backup_worker.mjs 4.3 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149
  1. import Queue from 'bull'
  2. import logger from '@overleaf/logger'
  3. import config from 'config'
  4. import metrics from '@overleaf/metrics'
  5. import {
  6. backupProject,
  7. initializeProjects,
  8. configureBackup,
  9. } from './backup.mjs'
  10. const CONCURRENCY = 15
  11. const WARN_THRESHOLD = 2 * 60 * 60 * 1000 // warn if projects are older than this
  12. const redisOptions = config.get('redis.queue')
  13. const JOB_TIME_BUCKETS = [10, 100, 500, 1000, 5000, 10000, 30000, 60000] // milliseconds
  14. const LAG_TIME_BUCKETS_HRS = [
  15. 0.5, 0.6, 0.7, 0.8, 0.9, 1.0, 1.1, 1.2, 1.3, 1.4, 1.5, 1.75, 2, 3, 4, 5, 6,
  16. ] // hours
  17. // Configure backup settings to match worker concurrency
  18. configureBackup({ concurrency: 50, useSecondary: true })
  19. // Create a Bull queue named 'backup'
  20. const backupQueue = new Queue('backup', {
  21. redis: redisOptions,
  22. settings: {
  23. lockDuration: 15 * 60 * 1000, // 15 minutes
  24. lockRenewTime: 60 * 1000, // 1 minute
  25. maxStalledCount: 0, // mark stalled jobs as failed
  26. },
  27. })
  28. // Log queue events
  29. backupQueue.on('active', job => {
  30. logger.debug({ job }, 'job is now active')
  31. })
  32. backupQueue.on('completed', (job, result) => {
  33. metrics.inc('backup_worker_job', 1, { status: 'completed' })
  34. logger.debug({ job, result }, 'job completed')
  35. })
  36. backupQueue.on('failed', (job, err) => {
  37. metrics.inc('backup_worker_job', 1, { status: 'failed' })
  38. logger.error({ job, err }, 'job failed')
  39. })
  40. backupQueue.on('waiting', jobId => {
  41. logger.debug({ jobId }, 'job is waiting')
  42. })
  43. backupQueue.on('error', error => {
  44. logger.error({ error }, 'queue error')
  45. })
  46. backupQueue.on('stalled', job => {
  47. logger.error({ job }, 'job has stalled')
  48. })
  49. backupQueue.on('lock-extension-failed', (job, err) => {
  50. logger.error({ job, err }, 'lock extension failed')
  51. })
  52. backupQueue.on('paused', () => {
  53. logger.info('queue paused')
  54. })
  55. backupQueue.on('resumed', () => {
  56. logger.info('queue resumed')
  57. })
  58. // Process jobs
  59. backupQueue.process(CONCURRENCY, async job => {
  60. const { projectId, startDate, endDate } = job.data
  61. if (projectId) {
  62. return await runBackup(projectId, job.data, job)
  63. } else if (startDate && endDate) {
  64. return await runInit(startDate, endDate)
  65. } else {
  66. throw new Error('invalid job data')
  67. }
  68. })
  69. async function runBackup(projectId, data, job) {
  70. const { pendingChangeAt } = data
  71. // record the time it takes to run the backup job
  72. const timer = new metrics.Timer(
  73. 'backup_worker_job_duration',
  74. 1,
  75. {},
  76. JOB_TIME_BUCKETS
  77. )
  78. const pendingAge = Date.now() - pendingChangeAt
  79. if (pendingAge > WARN_THRESHOLD) {
  80. logger.warn(
  81. { projectId, pendingAge, job },
  82. 'project has been pending for a long time'
  83. )
  84. }
  85. try {
  86. logger.debug({ projectId }, 'processing backup for project')
  87. await backupProject(projectId, {})
  88. metrics.inc('backup_worker_project', 1, {
  89. status: 'success',
  90. })
  91. timer.done()
  92. // record the replication lag (time from change to backup)
  93. if (pendingChangeAt) {
  94. metrics.histogram(
  95. 'backup_worker_replication_lag_in_hours',
  96. (Date.now() - pendingChangeAt) / (3600 * 1000),
  97. LAG_TIME_BUCKETS_HRS
  98. )
  99. }
  100. return `backup completed ${projectId}`
  101. } catch (err) {
  102. if (err.message === 'Project deleted') {
  103. metrics.inc('backup_worker_project', 1, { status: 'deleted' })
  104. logger.warn({ projectId, err }, 'skipping backup of deleted project')
  105. } else {
  106. metrics.inc('backup_worker_project', 1, { status: 'failed' })
  107. logger.error({ projectId, err }, 'backup failed')
  108. throw err // Re-throw to mark job as failed
  109. }
  110. }
  111. }
  112. async function runInit(startDate, endDate) {
  113. try {
  114. logger.info({ startDate, endDate }, 'initializing projects')
  115. await initializeProjects({ 'start-date': startDate, 'end-date': endDate })
  116. return `initialization completed ${startDate} - ${endDate}`
  117. } catch (err) {
  118. logger.error({ startDate, endDate, err }, 'initialization failed')
  119. throw err
  120. }
  121. }
  122. export async function drainQueue() {
  123. logger.info({ queue: backupQueue.name }, 'pausing queue')
  124. await backupQueue.pause(true) // pause this worker and wait for jobs to finish
  125. logger.info({ queue: backupQueue.name }, 'closing queue')
  126. await backupQueue.close()
  127. }
  128. export async function healthCheck() {
  129. const count = await backupQueue.count()
  130. metrics.gauge('backup_worker_queue_length', count)
  131. }