diff --git a/CHANGELOG.md b/CHANGELOG.md index 1b5793cc9df3..e609fa730092 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,17 @@ Work in this release was contributed by @kunal649. Thank you for your contributi `Sentry.cron.instrumentCron`, `instrumentNodeCron` and `instrumentNodeSchedule` read schedules the same way as `@SentryCron` and the cron integrations. Without a time zone, they send the server's time zone, where the scheduler runs the job, instead of letting Sentry assume UTC. For expressions Sentry would read differently than the scheduler, like per-second schedules, they send no monitor config, so existing monitors keep their schedule. They send names and nicknames like `MON` or `@daily` as numbers, and drop a fixed seconds field. If the seconds field isn't `0`, a check-in margin of 2 minutes is sent too, since the job checks in up to 59 seconds after the minute Sentry expects. This replaces a margin set in Sentry. Expressions with a day of month that none of their months have, like `0 9 31 2,4 *`, send no monitor config. `instrumentNodeSchedule` also sends `L` and `#`, where Sentry reads them the same way. +- **feat(node): Add `bullmqJobSchedulerIntegration` to monitor BullMQ job schedulers ([#25472](https://github.com/getsentry/sentry-javascript/pull/25472))** + + Add `Sentry.bullmqJobSchedulerIntegration()` to send check-ins for every job a BullMQ worker (5.16.0 to 6.x) runs from a job scheduler, with `-` as the monitor slug and the scheduler's `pattern` or `every` as the schedule. Each monitored scheduler creates a monitor in Sentry, and monitors are billed. Use `excludeJobSchedulers` to skip schedulers by id. A retried job keeps one check-in. + + ```js + Sentry.init({ + dsn: '__DSN__', + integrations: [Sentry.bullmqJobSchedulerIntegration({ excludeJobSchedulers: ['cache-warmup'] })], + }); + ``` + ## 11.12.0 ### Important Changes diff --git a/dev-packages/bun-integration-tests/node-suites/excludes.ts b/dev-packages/bun-integration-tests/node-suites/excludes.ts index 60d47967bd65..5b68f898fce9 100644 --- a/dev-packages/bun-integration-tests/node-suites/excludes.ts +++ b/dev-packages/bun-integration-tests/node-suites/excludes.ts @@ -4,13 +4,15 @@ // `supports({ bunMin })`. Neither is listed here. // Node-only features: ANR and native thread watchdogs, child processes, the AWS Lambda Node runtime, -// `node:sqlite`, which `flue` needs, and the Vercel keep-alive, which needs `http.server.response.finish`. +// `node:sqlite`, which `flue` needs, the Vercel keep-alive, which needs `http.server.response.finish`, and +// `bullmqJobSchedulerIntegration`, which `bun run` can't inject and the bundler plugins don't instrument. const NODE_ONLY = [ 'suites/anr/test.ts', 'suites/aws-lambda-web/**', 'suites/aws-serverless/**', 'suites/breadcrumbs/**', 'suites/child-process/test.ts', + 'suites/cron/bullmq/test.ts', 'suites/thread-blocked-native/test.ts', 'suites/tracing/flue/test.ts', 'suites/vercel/keep-alive/test.ts', diff --git a/dev-packages/e2e-tests/test-applications/node-exports-test-app/scripts/consistentExports.ts b/dev-packages/e2e-tests/test-applications/node-exports-test-app/scripts/consistentExports.ts index 3c880974fe0b..430ba9243afa 100644 --- a/dev-packages/e2e-tests/test-applications/node-exports-test-app/scripts/consistentExports.ts +++ b/dev-packages/e2e-tests/test-applications/node-exports-test-app/scripts/consistentExports.ts @@ -59,6 +59,7 @@ const DEPENDENTS: Dependent[] = [ 'childProcessIntegration', 'workerThreadsIntegration', 'pinoIntegration', + 'bullmqJobSchedulerIntegration', // Bun will get its own runtime metrics integration 'nodeRuntimeMetricsIntegration', 'NodeRuntimeMetricsOptions', diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/docker-compose.yml b/dev-packages/node-integration-tests/suites/cron/bullmq/docker-compose.yml new file mode 100644 index 000000000000..c54562dfc169 --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/docker-compose.yml @@ -0,0 +1,14 @@ +version: '3.9' + +services: + db: + image: redis:latest + restart: always + ports: + - '6385:6379' + healthcheck: + test: ['CMD-SHELL', 'redis-cli ping | grep -q PONG'] + interval: 2s + timeout: 3s + retries: 30 + start_period: 5s diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/instrument-tracing.mjs b/dev-packages/node-integration-tests/suites/cron/bullmq/instrument-tracing.mjs new file mode 100644 index 000000000000..ed997320d0b6 --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/instrument-tracing.mjs @@ -0,0 +1,10 @@ +import * as Sentry from '@sentry/node'; +import { loggingTransport } from '@sentry-internal/node-integration-tests'; + +Sentry.init({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + release: '1.0', + tracesSampleRate: 1.0, + transport: loggingTransport, + integrations: [Sentry.bullmqJobSchedulerIntegration()], +}); diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/instrument.mjs b/dev-packages/node-integration-tests/suites/cron/bullmq/instrument.mjs new file mode 100644 index 000000000000..686a33cb283b --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/instrument.mjs @@ -0,0 +1,9 @@ +import * as Sentry from '@sentry/node'; +import { loggingTransport } from '@sentry-internal/node-integration-tests'; + +Sentry.init({ + dsn: 'https://public@dsn.ingest.sentry.io/1337', + release: '1.0', + transport: loggingTransport, + integrations: [Sentry.bullmqJobSchedulerIntegration({ excludeJobSchedulers: ['excluded-scheduler'] })], +}); diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/processor.cjs b/dev-packages/node-integration-tests/suites/cron/bullmq/processor.cjs new file mode 100644 index 000000000000..81aff321c0e6 --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/processor.cjs @@ -0,0 +1 @@ +module.exports = async () => {}; diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/scenario-telemetry.mjs b/dev-packages/node-integration-tests/suites/cron/bullmq/scenario-telemetry.mjs new file mode 100644 index 000000000000..a0a93ad2ebe9 --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/scenario-telemetry.mjs @@ -0,0 +1,55 @@ +import * as Sentry from '@sentry/node'; +import { Queue, Worker } from 'bullmq'; + +const connection = { host: 'localhost', port: 6385 }; +const telemetry = new Sentry.BullMQTelemetry(); +const autorun = process.env.AUTORUN === 'true'; + +async function run() { + const queue = new Queue('crons-telemetry', { connection, telemetry }); + await queue.obliterate({ force: true }); + + await queue.upsertJobScheduler('ok-scheduler', { every: 300_000 }, { name: 'ok-job' }); + await queue.upsertJobScheduler( + 'failing-scheduler', + { pattern: '0 0 9 * * 1-5', tz: 'Europe/Vienna', immediately: true }, + { name: 'failing-job' }, + ); + + const worker = new Worker( + 'crons-telemetry', + async job => { + await Sentry.startSpan({ name: `work ${job.name}` }, async () => { + await new Promise(resolve => setTimeout(resolve, 50)); + }); + if (job.name === 'failing-job') { + throw new Error('Error in scheduled job'); + } + }, + { connection, telemetry, autorun }, + ); + + const finished = new Promise(resolve => { + let count = 0; + const done = () => { + if (++count === 2) { + resolve(); + } + }; + worker.on('completed', done); + worker.on('failed', done); + }); + + if (!autorun) { + void worker.run(); + } + + await finished; + await worker.close(); + await queue.obliterate({ force: true }); + await queue.close(); + await Sentry.flush(); + process.exit(); +} + +void run(); diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/scenario.mjs b/dev-packages/node-integration-tests/suites/cron/bullmq/scenario.mjs new file mode 100644 index 000000000000..ec61949740a9 --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/scenario.mjs @@ -0,0 +1,101 @@ +import { dirname, join } from 'node:path'; +import { Queue, Worker } from 'bullmq'; + +const connection = { host: 'localhost', port: 6385 }; + +async function run() { + const queue = new Queue('crons', { connection }); + const sandboxedQueue = new Queue('crons-sandboxed', { connection }); + await queue.obliterate({ force: true }); + await sandboxedQueue.obliterate({ force: true }); + + const worker = new Worker( + 'crons', + async job => { + if (job.name === 'failing' || (job.name === 'flaky' && job.attemptsMade === 0)) { + throw new Error('Error in scheduled job'); + } + }, + { connection }, + ); + const sandboxedWorker = new Worker('crons-sandboxed', join(dirname(process.argv[1]), 'processor.cjs'), { + connection, + }); + + // Waits for every job to finish, including the ones that send no check-ins. + const pending = new Map([ + ['plain', 1], + ['legacy', 1], + ['legacy-key', 1], + ['excluded', 1], + ['every', 2], + ['failing', 1], + ['flaky', 1], + ['sandboxed', 1], + ]); + const finished = new Promise(resolve => { + const done = job => { + const left = pending.get(job?.name); + if (left === undefined) { + return; + } + if (left > 1) { + pending.set(job.name, left - 1); + } else { + pending.delete(job.name); + } + if (!pending.size) { + resolve(); + } + }; + for (const w of [worker, sandboxedWorker]) { + w.on('completed', done); + w.on('failed', job => job?.finishedOn && done(job)); + } + }); + + // Runs delayed scheduler jobs now. The loop below and the `completed` listener can race to promote the same job. + const promote = job => job?.promote().catch(() => {}); + + // Runs the iteration the worker created after the first run, instead of waiting 5 minutes. + let promoted = false; + worker.on('completed', async job => { + if (job.name !== 'every' || promoted) { + return; + } + promoted = true; + const delayed = await queue.getDelayed(); + await promote(delayed.find(next => next.repeatJobKey === 'every-scheduler')); + }); + + await queue.add('plain', {}); + await queue.add('legacy', {}, { repeat: { every: 300_000, immediately: true } }); + await queue.add('legacy-key', {}, { repeat: { every: 300_000, key: 'custom-key', immediately: true } }); + await queue.upsertJobScheduler('excluded-scheduler', { every: 300_000 }, { name: 'excluded' }); + await queue.upsertJobScheduler('every-scheduler', { every: 300_000 }, { name: 'every' }); + await queue.upsertJobScheduler( + 'pattern-scheduler', + { pattern: '0 0 9 * * 1-5', tz: 'Europe/Vienna', immediately: true }, + { name: 'failing' }, + ); + await queue.upsertJobScheduler('retry-scheduler', { every: 600_000 }, { name: 'flaky', opts: { attempts: 2 } }); + await sandboxedQueue.upsertJobScheduler('sandboxed-scheduler', { every: 300_000 }, { name: 'sandboxed' }); + + // BullMQ 5.16 starts an `every` scheduler at its next full interval, so run the first jobs now. + for (const job of [...(await queue.getDelayed()), ...(await sandboxedQueue.getDelayed())]) { + if (job.opts.repeat?.count === 1) { + await promote(job); + } + } + + await finished; + await worker.close(); + await sandboxedWorker.close(); + await queue.obliterate({ force: true }); + await sandboxedQueue.obliterate({ force: true }); + await queue.close(); + await sandboxedQueue.close(); + process.exit(); +} + +void run(); diff --git a/dev-packages/node-integration-tests/suites/cron/bullmq/test.ts b/dev-packages/node-integration-tests/suites/cron/bullmq/test.ts new file mode 100644 index 000000000000..bdc1b101964c --- /dev/null +++ b/dev-packages/node-integration-tests/suites/cron/bullmq/test.ts @@ -0,0 +1,168 @@ +import type { Event, SerializedCheckIn } from '@sentry/core'; +import { afterAll, describe, expect } from 'vitest'; +import { cleanupChildProcesses, createEsmAndCjsTests, describeWithDockerCompose } from '../../../utils/runner'; + +describeWithDockerCompose('bullmq job scheduler check-ins', { workingDirectory: [__dirname] }, () => { + afterAll(() => { + cleanupChildProcesses(); + }); + + // The workspace has the latest BullMQ 5. Also run the oldest version with job schedulers and BullMQ 6. + describe.each([ + ['BullMQ 5', undefined], + ['BullMQ 5.16.0', { bullmq: '5.16.0' }], + ['BullMQ 6', { bullmq: '6.7.5' }], + ])('%s', (_, additionalDependencies) => { + createEsmAndCjsTests( + __dirname, + 'scenario.mjs', + 'instrument.mjs', + (createRunner, test) => { + test('sends check-ins with the job scheduler schedule', { timeout: 90_000 }, async () => { + const checkIns: SerializedCheckIn[] = []; + await createRunner() + .unordered() + .expectN(11, { check_in: checkIn => void checkIns.push(checkIn) }) + .start() + .completed(); + + const bySlug = (slug: string): SerializedCheckIn[] => + checkIns.filter(checkIn => checkIn.monitor_slug === slug); + const everyCheckIns = bySlug('crons-every-scheduler'); + const patternCheckIns = bySlug('crons-pattern-scheduler'); + const retryCheckIns = bySlug('crons-retry-scheduler'); + const sandboxedCheckIns = bySlug('crons-sandboxed-sandboxed-scheduler'); + const everyConfig = { schedule: { type: 'interval', value: 5, unit: 'minute' } }; + const patternConfig = { schedule: { type: 'crontab', value: '0 9 * * 1-5' }, timezone: 'Europe/Vienna' }; + const retryConfig = { schedule: { type: 'interval', value: 10, unit: 'minute' } }; + + expect(new Set(checkIns.map(checkIn => checkIn.monitor_slug))).toEqual( + new Set([ + 'crons-every-scheduler', + 'crons-pattern-scheduler', + 'crons-retry-scheduler', + 'crons-sandboxed-sandboxed-scheduler', + ]), + ); + // The second run is the iteration the worker created after the first. + expect(everyCheckIns).toEqual([ + expect.objectContaining({ status: 'in_progress', release: '1.0', monitor_config: everyConfig }), + expect.objectContaining({ + status: 'ok', + check_in_id: everyCheckIns[0]?.check_in_id, + duration: expect.any(Number), + monitor_config: everyConfig, + }), + expect.objectContaining({ status: 'in_progress', monitor_config: everyConfig }), + expect.objectContaining({ status: 'ok', check_in_id: everyCheckIns[2]?.check_in_id }), + ]); + expect(everyCheckIns[2]?.check_in_id).not.toBe(everyCheckIns[0]?.check_in_id); + expect(patternCheckIns).toEqual([ + expect.objectContaining({ status: 'in_progress', release: '1.0', monitor_config: patternConfig }), + expect.objectContaining({ + status: 'error', + check_in_id: patternCheckIns[0]?.check_in_id, + duration: expect.any(Number), + monitor_config: patternConfig, + }), + ]); + // The retry updates the first attempt's check-in, and Sentry measures its duration. + const retryCheckInId = retryCheckIns[0]?.check_in_id; + expect(retryCheckIns).toEqual([ + expect.objectContaining({ + status: 'in_progress', + check_in_id: retryCheckInId, + monitor_config: retryConfig, + }), + expect.objectContaining({ + status: 'in_progress', + check_in_id: retryCheckInId, + monitor_config: retryConfig, + }), + expect.objectContaining({ status: 'ok', check_in_id: retryCheckInId, monitor_config: retryConfig }), + ]); + expect(retryCheckIns[2]).not.toHaveProperty('duration'); + expect(sandboxedCheckIns).toEqual([ + expect.objectContaining({ status: 'in_progress', monitor_config: everyConfig }), + expect.objectContaining({ status: 'ok', check_in_id: sandboxedCheckIns[0]?.check_in_id }), + ]); + }); + }, + { additionalDependencies, copyPaths: ['processor.cjs'] }, + ); + }); + + createEsmAndCjsTests(__dirname, 'scenario-telemetry.mjs', 'instrument-tracing.mjs', (createRunner, test) => { + test.each([ + ['with autorun', 'true'], + ['with a later run()', 'false'], + ])( + 'sends one check-in pair per run in the job trace with BullMQTelemetry, %s', + { timeout: 60_000 }, + async (_, autorun) => { + const checkIns: SerializedCheckIn[] = []; + const errors: Event[] = []; + const runner = createRunner() + .withEnv({ AUTORUN: autorun }) + .unordered() + .expectN(4, { check_in: checkIn => void checkIns.push(checkIn) }) + .expect({ event: event => void errors.push(event) }); + const spansByJob = ['ok-job', 'failing-job'].map(jobName => + runner.collectStreamedSpans(spans => + spans.some( + span => + span.is_segment && + span.name === 'process crons-telemetry' && + span.attributes['messaging.bullmq.job.name']?.value === jobName, + ), + ), + ); + + await runner.start().completed(); + + const [okSpans, failingSpans] = await Promise.all(spansByJob); + const okSegment = okSpans!.find(span => span.is_segment)!; + const failingSegment = failingSpans!.find(span => span.is_segment)!; + + expect(okSegment.status).toBe('ok'); + expect(failingSegment.status).toBe('error'); + expect(okSpans!.some(span => span.name === 'work ok-job' && span.parent_span_id === okSegment.span_id)).toBe( + true, + ); + expect( + failingSpans!.some( + span => span.name === 'work failing-job' && span.parent_span_id === failingSegment.span_id, + ), + ).toBe(true); + + const summary = (slug: string): unknown => + checkIns + .filter(checkIn => checkIn.monitor_slug === slug) + .map(checkIn => ({ + status: checkIn.status, + check_in_id: checkIn.check_in_id, + trace_id: checkIn.contexts?.trace?.trace_id, + })); + const okCheckInId = checkIns.find( + checkIn => checkIn.monitor_slug === 'crons-telemetry-ok-scheduler', + )?.check_in_id; + const failingCheckInId = checkIns.find( + checkIn => checkIn.monitor_slug === 'crons-telemetry-failing-scheduler', + )?.check_in_id; + + expect(summary('crons-telemetry-ok-scheduler')).toEqual([ + { status: 'in_progress', check_in_id: okCheckInId, trace_id: okSegment.trace_id }, + { status: 'ok', check_in_id: okCheckInId, trace_id: okSegment.trace_id }, + ]); + expect(summary('crons-telemetry-failing-scheduler')).toEqual([ + { status: 'in_progress', check_in_id: failingCheckInId, trace_id: failingSegment.trace_id }, + { status: 'error', check_in_id: failingCheckInId, trace_id: failingSegment.trace_id }, + ]); + + expect(errors).toHaveLength(1); + expect(errors[0]?.exception?.values?.[0]?.value).toBe('Error in scheduled job'); + expect(errors[0]?.contexts?.trace?.trace_id).toBe(failingSegment.trace_id); + }, + ); + }); +}); diff --git a/packages/astro/src/index.server.ts b/packages/astro/src/index.server.ts index f407a5723a5b..bf7d28442a5a 100644 --- a/packages/astro/src/index.server.ts +++ b/packages/astro/src/index.server.ts @@ -49,6 +49,7 @@ export { fsIntegration, functionToStringIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration, diff --git a/packages/aws-serverless/src/index.ts b/packages/aws-serverless/src/index.ts index f7310775b554..f018b7ad0c62 100644 --- a/packages/aws-serverless/src/index.ts +++ b/packages/aws-serverless/src/index.ts @@ -119,6 +119,7 @@ export { firebaseIntegration, fsIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration, diff --git a/packages/deno/src/index.ts b/packages/deno/src/index.ts index 4cf53f81d690..f4a4144f7ada 100644 --- a/packages/deno/src/index.ts +++ b/packages/deno/src/index.ts @@ -195,6 +195,7 @@ export { postgresIntegration, postgresJsIntegration, neonIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration, diff --git a/packages/google-cloud-serverless/src/index.ts b/packages/google-cloud-serverless/src/index.ts index 107674b83b95..e7b011243467 100644 --- a/packages/google-cloud-serverless/src/index.ts +++ b/packages/google-cloud-serverless/src/index.ts @@ -119,6 +119,7 @@ export { fastifyIntegration, firebaseIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration, diff --git a/packages/node/src/index.ts b/packages/node/src/index.ts index 5297b54a8c25..e198d796e49c 100644 --- a/packages/node/src/index.ts +++ b/packages/node/src/index.ts @@ -13,6 +13,8 @@ export { type ExpressIntegrationOptions, firebaseIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, + type BullMQJobSchedulerIntegrationOptions, cronJobIntegration, type CronJobIntegrationOptions, nodeCronIntegration, diff --git a/packages/remix/src/server/index.ts b/packages/remix/src/server/index.ts index e034d9404d05..09b46d0a8da5 100644 --- a/packages/remix/src/server/index.ts +++ b/packages/remix/src/server/index.ts @@ -37,6 +37,7 @@ export { flush, functionToStringIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration, diff --git a/packages/server-utils/src/index.ts b/packages/server-utils/src/index.ts index 3ab5b322c212..a6b87b1403be 100644 --- a/packages/server-utils/src/index.ts +++ b/packages/server-utils/src/index.ts @@ -38,6 +38,8 @@ export { anthropicAIIntegration } from './integrations/anthropic'; export { awsIntegration } from './integrations/aws-sdk'; export { dataloaderIntegration } from './integrations/dataloader'; export { genericPoolIntegration } from './integrations/generic-pool'; +export { bullmqJobSchedulerIntegration } from './integrations/bullmq'; +export type { BullMQJobSchedulerIntegrationOptions } from './integrations/bullmq'; export { cronJobIntegration } from './integrations/cron'; export type { CronJobIntegrationOptions } from './integrations/cron'; export { isReadAlikeByNodeCron3, nodeCronIntegration } from './integrations/node-cron'; diff --git a/packages/server-utils/src/integrations/bullmq.ts b/packages/server-utils/src/integrations/bullmq.ts new file mode 100644 index 000000000000..e4d94f945465 --- /dev/null +++ b/packages/server-utils/src/integrations/bullmq.ts @@ -0,0 +1,315 @@ +import { createHash } from 'node:crypto'; +import type { InProgressCheckIn, IntegrationFn, MonitorConfig } from '@sentry/core'; +import { + captureCheckIn, + debug, + defineIntegration, + getClient, + stringMatchesSomePattern, + timestampInSeconds, +} from '@sentry/core'; +import { DEBUG_BUILD } from '../debug-build'; +import { CHANNELS } from '../orchestrion/channels'; +import { bullmqModuleNames } from '../orchestrion/config/bullmq'; +import { invokeOrchestrionInstrumentation } from '../orchestrion/instrumentation'; +import { cronExpressionToMonitorConfig } from '../utils/cronMonitoring'; +import * as diagnosticsChannel from '../utils/diagnosticsChannel'; + +const INTEGRATION_NAME = 'BullMQJobScheduler' as const; + +export interface BullMQJobSchedulerIntegrationOptions { + /** Job scheduler ids not to monitor. Strings must match the id exactly. */ + excludeJobSchedulers?: Array; +} + +const _bullmqJobSchedulerIntegration = ((options: BullMQJobSchedulerIntegrationOptions = {}) => { + return { + name: INTEGRATION_NAME, + setup(client) { + invokeOrchestrionInstrumentation(client, bullmqModuleNames, subscribe, [options], { + requiresTracingChannelBinding: false, + }); + }, + }; +}) satisfies IntegrationFn; + +/** + * Sends Crons check-ins for the jobs a BullMQ 5.16 to 6.x worker runs from job schedulers, with `-` + * as the monitor slug. Schedulers that end or whose schedule Crons can't express are not monitored. + */ +export const bullmqJobSchedulerIntegration = defineIntegration(_bullmqJobSchedulerIntegration); + +type BullMQMajor = 5 | 6; + +function subscribe(options: BullMQJobSchedulerIntegrationOptions): void { + const channels = [ + [CHANNELS.BULLMQ_WORKER_CONSTRUCTOR, 5], + [CHANNELS.BULLMQ_6_WORKER_CONSTRUCTOR, 6], + ] as const; + for (const [channel, major] of channels) { + diagnosticsChannel.tracingChannel(channel).end.subscribe(message => { + try { + instrumentWorker((message as { self?: unknown }).self, options, major); + } catch (e) { + DEBUG_BUILD && debug.error(`[${INTEGRATION_NAME}] Failed to set up the cron monitor:`, e); + } + }); + } +} + +interface BullMQRepeatOptions { + pattern?: unknown; + every?: unknown; + tz?: unknown; + utc?: unknown; + nthDayOfWeek?: unknown; + limit?: unknown; + endDate?: unknown; + key?: unknown; + jobId?: unknown; +} + +interface BullMQJob { + id?: unknown; + name?: unknown; + queueQualifiedName?: unknown; + timestamp?: unknown; + repeatJobKey?: unknown; + attemptsStarted?: unknown; + attemptsMade?: unknown; + finishedOn?: unknown; + opts?: { repeat?: BullMQRepeatOptions }; +} + +interface BullMQWorker { + name?: unknown; + processFn?: (job: BullMQJob, ...args: unknown[]) => unknown; + opts?: { settings?: { repeatStrategy?: unknown; repeatKeyHashAlgorithm?: unknown } }; + on?: (event: string, listener: (job?: BullMQJob) => void) => unknown; +} + +interface Monitor { + monitorSlug: string; + checkInId: string; + config: MonitorConfig; +} + +interface WorkerSettings { + major: BullMQMajor; + hasCustomRepeatStrategy: boolean; + repeatKeyHashAlgorithm: string; + exclude: Array | undefined; +} + +const instrumentedWorkers = new WeakSet(); +const loggedSchedulers = new Set(); +const MAX_LOGGED_SCHEDULERS = 100; + +// `captureCheckIn` keeps a given `checkInId` for `in_progress` check-ins too. +type InProgressCheckInWithId = InProgressCheckIn & { checkInId: string }; + +/** Sends check-ins for the jobs a new BullMQ worker runs from job schedulers. */ +export function instrumentWorker( + worker: unknown, + options: BullMQJobSchedulerIntegrationOptions, + major: BullMQMajor, +): void { + const target = worker as BullMQWorker | undefined; + const queueName = target?.name; + const processFn = target?.processFn; + if ( + !target || + instrumentedWorkers.has(target) || + typeof processFn !== 'function' || + typeof queueName !== 'string' || + typeof target.on !== 'function' + ) { + return; + } + instrumentedWorkers.add(target); + const settings = target.opts?.settings; + const workerSettings: WorkerSettings = { + major, + hasCustomRepeatStrategy: !!settings?.repeatStrategy, + repeatKeyHashAlgorithm: + typeof settings?.repeatKeyHashAlgorithm === 'string' ? settings.repeatKeyHashAlgorithm : 'md5', + exclude: options.excludeJobSchedulers, + }; + const monitorFor = (job: BullMQJob | undefined): Monitor | undefined => getMonitor(job, queueName, workerSettings); + + const startTimes = new WeakMap(); + + // Sentry keeps the trace of the `in_progress` check-in. BullMQ emits `active` before the job's trace starts, + // often inside the previous job's, so send it from the processor instead. + target.processFn = function (this: unknown, job: BullMQJob, ...args: unknown[]): unknown { + try { + const monitor = monitorFor(job); + if (job && monitor) { + const { monitorSlug, checkInId, config } = monitor; + // Retries and reruns of stalled jobs update the first attempt's check-in, which may be on another worker. + captureCheckIn({ monitorSlug, status: 'in_progress', checkInId } as InProgressCheckInWithId, config); + if (isFirstAttempt(job)) { + startTimes.set(job, timestampInSeconds()); + } + } + } catch (e) { + DEBUG_BUILD && debug.error(`[${INTEGRATION_NAME}] Failed to send check-in:`, e); + } + return processFn.call(this, job, ...args); + }; + + const finish = + (status: 'ok' | 'error') => + (job?: BullMQJob): void => { + try { + // BullMQ emits `failed` for every attempt, and only sets `finishedOn` once it stops retrying. + if (!job || (status === 'error' && !job.finishedOn)) { + return; + } + const monitor = monitorFor(job); + if (!monitor) { + return; + } + const { monitorSlug, checkInId, config } = monitor; + const start = startTimes.get(job); + // Without a start time, Sentry measures the duration from the first `in_progress` check-in. + const duration = start === undefined ? undefined : timestampInSeconds() - start; + // BullMQ fails some jobs, such as ones that started too often, without running the processor, so send the + // config in case the check-in doesn't exist yet. + captureCheckIn({ monitorSlug, status, checkInId, ...(duration !== undefined && { duration }) }, config); + } catch (e) { + DEBUG_BUILD && debug.error(`[${INTEGRATION_NAME}] Failed to send check-in:`, e); + } + }; + target.on('completed', finish('ok')); + target.on('failed', finish('error')); +} + +function getMonitor(job: BullMQJob | undefined, queueName: string, settings: WorkerSettings): Monitor | undefined { + const schedulerId = job?.repeatJobKey; + if ( + !job || + typeof schedulerId !== 'string' || + !schedulerId || + stringMatchesSomePattern(schedulerId, settings.exclude, true) + ) { + return undefined; + } + // Scheduler ids are only unique within a queue. + const monitorSlug = `${queueName}-${schedulerId}`; + const config = isLegacyRepeatableJob(job, schedulerId, settings.repeatKeyHashAlgorithm) + ? 'it is a repeatable job added with queue.add, not a job scheduler' + : getMonitorConfig(job.opts?.repeat, settings); + if (typeof config === 'string') { + if (DEBUG_BUILD && !loggedSchedulers.has(monitorSlug)) { + if (loggedSchedulers.size >= MAX_LOGGED_SCHEDULERS) { + loggedSchedulers.clear(); + } + loggedSchedulers.add(monitorSlug); + debug.log(`[${INTEGRATION_NAME}] Not monitoring ${monitorSlug}: ${config}.`); + } + return undefined; + } + return { monitorSlug, checkInId: getCheckInId(job), config }; +} + +// Check-in ids are global in Sentry, so mix in the DSN and environment, not just the job. +function getCheckInId(job: BullMQJob): string { + const options = getClient()?.getOptions(); + return createHash('sha256') + .update(JSON.stringify([options?.dsn, options?.environment, job.queueQualifiedName, job.id, job.timestamp])) + .digest('hex') + .slice(0, 32); +} + +function isFirstAttempt(job: BullMQJob): boolean { + return !job.attemptsMade && (typeof job.attemptsStarted !== 'number' || job.attemptsStarted <= 1); +} + +// The queue's `repeatKeyHashAlgorithm` isn't reachable from a worker, so also try the common ones. +const LEGACY_KEY_HASH_ALGORITHMS = ['md5', 'sha1', 'sha256', 'sha512']; + +// BullMQ 5 keys repeatable jobs from `queue.add` by `repeat.key`, or by their name and repeat options or a hash of them. +// Job schedulers don't take a `key`. +function isLegacyRepeatableJob(job: BullMQJob, id: string, hashAlgorithm: string): boolean { + const repeat = job.opts?.repeat; + if (!repeat) { + return false; + } + if (repeat.key != null) { + return true; + } + const endDate = repeat.endDate ? new Date(repeat.endDate as string).getTime() : ''; + const suffix = repeat.pattern || String(repeat.every); + const key = `${job.name}:${repeat.jobId || ''}:${endDate}:${repeat.tz || ''}:${suffix}`; + if (id === key) { + return true; + } + return ( + /^[\da-f]+$/.test(id) && + [hashAlgorithm, ...LEGACY_KEY_HASH_ALGORITHMS].some( + algorithm => createHash(algorithm).update(key).digest('hex') === id, + ) + ); +} + +/** The monitor config for a job scheduler's repeat options, or why it isn't monitored. */ +function getMonitorConfig(repeat: BullMQRepeatOptions | undefined, settings: WorkerSettings): MonitorConfig | string { + // A scheduler that stops would show up as missed. + if (repeat?.limit != null) { + return 'it sets a limit'; + } + if (repeat?.endDate != null) { + return 'it sets an endDate'; + } + + if (typeof repeat?.every === 'number') { + const minutes = repeat.every / 60_000; + if (!Number.isInteger(minutes) || minutes <= 0) { + return "Crons can't express its schedule"; + } + if (minutes % 1440 === 0) { + return { schedule: { type: 'interval', value: minutes / 1440, unit: 'day' } }; + } + if (minutes % 60 === 0) { + return { schedule: { type: 'interval', value: minutes / 60, unit: 'hour' } }; + } + return { schedule: { type: 'interval', value: minutes, unit: 'minute' } }; + } + + if (typeof repeat?.pattern !== 'string') { + return "Crons can't express its schedule"; + } + if (settings.hasCustomRepeatStrategy) { + return 'the worker has a custom repeatStrategy'; + } + // BullMQ 6's cron-parser ignores `utc` and `nthDayOfWeek`. + const pattern = settings.major === 6 ? repeat.pattern : withNthDayOfWeek(repeat.pattern, repeat.nthDayOfWeek); + if (!pattern) { + return "Crons can't express its nthDayOfWeek"; + } + const timezone = settings.major === 5 && repeat.utc ? 'UTC' : repeat.tz; + return cronExpressionToMonitorConfig(pattern, timezone, 'cron-parser') || "Crons can't express its schedule"; +} + +// cron-parser 4 reads `{ pattern: '0 9 * * 1', nthDayOfWeek: 2 }` like `0 9 * * 1#2`, and applies `nthDayOfWeek` to +// any other day of week too. +function withNthDayOfWeek(pattern: string, nthDayOfWeek: unknown): string | undefined { + if (!nthDayOfWeek) { + return pattern; + } + const fields = pattern.trim().split(/\s+/); + const dayOfWeek = fields[fields.length - 1] as string; + if ( + (fields.length !== 5 && fields.length !== 6) || + !/^(?:[0-7]|[a-z]+)$/i.test(dayOfWeek) || + typeof nthDayOfWeek !== 'number' || + !Number.isInteger(nthDayOfWeek) || + nthDayOfWeek < 1 || + nthDayOfWeek > 5 + ) { + return undefined; + } + fields[fields.length - 1] = `${dayOfWeek}#${nthDayOfWeek}`; + return fields.join(' '); +} diff --git a/packages/server-utils/src/orchestrion/channels.ts b/packages/server-utils/src/orchestrion/channels.ts index f593fefe0ebd..aed4a2b336e5 100644 --- a/packages/server-utils/src/orchestrion/channels.ts +++ b/packages/server-utils/src/orchestrion/channels.ts @@ -1,6 +1,7 @@ import { amqplibChannels } from './config/amqplib'; import { anthropicAiChannels } from './config/anthropic-ai'; import { awsSdkChannels } from './config/aws-sdk'; +import { bullmqChannels } from './config/bullmq'; import { cronChannels } from './config/cron'; import { dataloaderChannels } from './config/dataloader'; import { expressChannels } from './config/express'; @@ -61,6 +62,7 @@ export const CHANNELS = { ...amqplibChannels, ...anthropicAiChannels, ...awsSdkChannels, + ...bullmqChannels, ...cronChannels, ...dataloaderChannels, ...expressChannels, diff --git a/packages/server-utils/src/orchestrion/config/bullmq.ts b/packages/server-utils/src/orchestrion/config/bullmq.ts new file mode 100644 index 000000000000..82a74cfd9e46 --- /dev/null +++ b/packages/server-utils/src/orchestrion/config/bullmq.ts @@ -0,0 +1,22 @@ +import type { InstrumentationConfig } from '../apmTypes'; +import { getModuleNames } from './module-names'; + +// Job schedulers were added in 5.16.0. BullMQ 6 gets its own channel, since it reads `pattern` with cron-parser 5. +const workerConfigs = (channelName: string, versionRange: string): InstrumentationConfig[] => + ['dist/cjs/classes/worker.js', 'dist/esm/classes/worker.js'].map(filePath => ({ + channelName, + module: { name: 'bullmq', versionRange, filePath }, + functionQuery: { className: 'Worker' }, + })); + +export const bullmqConfig = [ + ...workerConfigs('workerConstructor', '>=5.16.0 <6'), + ...workerConfigs('worker6Constructor', '>=6.0.0 <7'), +]; + +export const bullmqModuleNames = getModuleNames(bullmqConfig); + +export const bullmqChannels = { + BULLMQ_WORKER_CONSTRUCTOR: 'orchestrion:bullmq:workerConstructor', + BULLMQ_6_WORKER_CONSTRUCTOR: 'orchestrion:bullmq:worker6Constructor', +} as const; diff --git a/packages/server-utils/src/orchestrion/config/index.ts b/packages/server-utils/src/orchestrion/config/index.ts index 7636fbef80fc..4144a38d017d 100644 --- a/packages/server-utils/src/orchestrion/config/index.ts +++ b/packages/server-utils/src/orchestrion/config/index.ts @@ -3,6 +3,7 @@ import type { InstrumentationConfig } from '../apmTypes'; import { uniq } from '@sentry/core'; import { awsSdkConfig } from './aws-sdk'; +import { bullmqConfig } from './bullmq'; import { amqplibConfig } from './amqplib'; import { anthropicAiConfig } from './anthropic-ai'; import { cronConfig } from './cron'; @@ -112,9 +113,9 @@ export const SENTRY_INSTRUMENTATIONS: InstrumentationConfig[] = [ ]; /** - * The subset of {@link SENTRY_INSTRUMENTATIONS} the RUNTIME loader - * (`@sentry/server-runtime-injection`'s `register`, reached via `--import` or - * `Sentry.init()`) can actually apply. + * The configs the RUNTIME loader (`@sentry/server-runtime-injection`'s + * `register`, reached via `--import` or `Sentry.init()`) applies: the ones in + * {@link SENTRY_INSTRUMENTATIONS} it can apply, plus the runtime-only ones. * * Registration-only configs (native-channel libraries such as `ai` v7, * `ioredis`, `@redis/client`, `mysql2`, `mongoose`) carry the custom @@ -139,9 +140,12 @@ export const SENTRY_INSTRUMENTATIONS: InstrumentationConfig[] = [ * instantiate its integration factory. `@sentry/node` registers its * integrations statically, so it does not need it. */ -export const SENTRY_RUNTIME_INSTRUMENTATIONS: InstrumentationConfig[] = SENTRY_INSTRUMENTATIONS.filter( - config => !config.transform, -); +export const SENTRY_RUNTIME_INSTRUMENTATIONS: InstrumentationConfig[] = [ + ...SENTRY_INSTRUMENTATIONS.filter(config => !config.transform), + // Not in `SENTRY_INSTRUMENTATIONS`, so bundler plugins don't force BullMQ into the bundle. Bundled, it can't find + // the files it starts sandboxed processors from. + ...bullmqConfig, +]; /** * The unique set of package names instrumented by `SENTRY_INSTRUMENTATIONS` @@ -178,7 +182,7 @@ export const INSTRUMENTED_MODULE_NAMES: string[] = instrumentedModuleNames(); * additions — those force a helper package to be *bundled*, the opposite of keeping it external. */ export function getInstrumentedModuleNames(): string[] { - return uniq(SENTRY_INSTRUMENTATIONS.map(instrumentation => instrumentation.module.name)); + return uniq([...SENTRY_INSTRUMENTATIONS, ...bullmqConfig].map(instrumentation => instrumentation.module.name)); } /** diff --git a/packages/server-utils/test/integrations/bullmq.test.ts b/packages/server-utils/test/integrations/bullmq.test.ts new file mode 100644 index 000000000000..ff9e2a4f580a --- /dev/null +++ b/packages/server-utils/test/integrations/bullmq.test.ts @@ -0,0 +1,388 @@ +import { createHash } from 'node:crypto'; +import { EventEmitter } from 'node:events'; +import * as SentryCore from '@sentry/core'; +import { afterEach, beforeEach, describe, expect, type MockInstance, test, vi } from 'vitest'; +import { instrumentWorker } from '../../src/integrations/bullmq'; + +function schedulerJob(id: string, repeat: Record, attempt: Record = {}): object { + return { + id: `repeat:${id}:1767225600000`, + queueQualifiedName: 'bull:reports', + timestamp: 1767225500000, + name: 'job', + repeatJobKey: id, + attemptsStarted: 1, + attemptsMade: 0, + opts: { repeat: { count: 1, ...repeat } }, + ...attempt, + }; +} + +// BullMQ sets `finishedOn` when a job fails for the last time. +function finalFailure(job: object): object { + return Object.assign(job, { finishedOn: Date.now() }); +} + +describe('bullmqJobSchedulerIntegration', () => { + let captureCheckInSpy: MockInstance; + + beforeEach(() => { + captureCheckInSpy = vi.spyOn(SentryCore, 'captureCheckIn').mockReturnValue('check-in-id'); + }); + + afterEach(() => { + vi.restoreAllMocks(); + }); + + function createWorker( + opts: object = {}, + ): EventEmitter & { processFn: (job: object, ...args: unknown[]) => unknown; opts: object } { + return Object.assign(new EventEmitter(), { + name: 'reports', + processFn: vi.fn((_job: object, ..._args: unknown[]) => 'result'), + opts, + }); + } + + function runJob( + job: object, + outcome: 'completed' | 'failed' = 'completed', + worker = createWorker(), + major: 5 | 6 = 5, + ): void { + instrumentWorker(worker, {}, major); + worker.processFn(job); + if (outcome === 'failed') { + worker.emit('failed', finalFailure(job), new Error('boom'), 'active'); + } else { + worker.emit('completed', job, 'result', 'active'); + } + } + + function sentConfig(repeat: Record, major: 5 | 6 = 5): unknown { + runJob(schedulerJob('my-scheduler', repeat), 'completed', createWorker(), major); + return captureCheckInSpy.mock.calls[0]?.[1]; + } + + function expectSkipped(repeat: Record, major: 5 | 6 = 5): void { + runJob(schedulerJob('my-scheduler', repeat), 'failed', createWorker(), major); + const worker = createWorker(); + instrumentWorker(worker, {}, major); + worker.emit('failed', finalFailure(schedulerJob('my-scheduler', repeat)), new Error('stalled'), 'active'); + expect(captureCheckInSpy).not.toHaveBeenCalled(); + } + + test('sends in_progress and ok check-ins with the scheduler id as slug', () => { + runJob(schedulerJob('daily-report', { pattern: '0 9 * * 1-5', tz: 'Europe/Vienna' })); + + const config = { schedule: { type: 'crontab', value: '0 9 * * 1-5' }, timezone: 'Europe/Vienna' }; + expect(captureCheckInSpy).toHaveBeenNthCalledWith( + 1, + { monitorSlug: 'reports-daily-report', status: 'in_progress', checkInId: expect.stringMatching(/^[\da-f]{32}$/) }, + config, + ); + const checkInId = captureCheckInSpy.mock.calls[0]?.[0].checkInId; + expect(captureCheckInSpy).toHaveBeenNthCalledWith( + 2, + { monitorSlug: 'reports-daily-report', status: 'ok', checkInId, duration: expect.any(Number) }, + config, + ); + }); + + test('sends an error check-in when the job fails', () => { + runJob(schedulerJob('daily-report', { every: 60_000 }), 'failed'); + + expect(captureCheckInSpy).toHaveBeenLastCalledWith(expect.objectContaining({ status: 'error' }), expect.anything()); + }); + + test.each([ + ['0 0 9 * * *', '0 9 * * *'], + ['*/15 9-17 * * mon-fri', '*/15 9-17 * * 1-5'], + ['0 0 1 JAN *', '0 0 1 1 *'], + ['0 0 L * *', '0 0 L * *'], + ['0 0 * * 5L', '0 0 * * 5L'], + ['0 0 * * 1#2', '0 0 * * 1#2'], + ['0 0 1 * 1', '0 0 1 * 1'], + ['0 0 1 * 0-6', '0 0 1 * 0-6'], + ['@daily', '0 0 * * *'], + ])('converts pattern %j to crontab %j', (pattern, crontab) => { + expect(sentConfig({ pattern, tz: 'UTC' })).toEqual({ + schedule: { type: 'crontab', value: crontab }, + timezone: 'UTC', + }); + }); + + test.each([ + '*/10 * * * * *', + '0 0 ? * 1', + '0 0 15W * *', + '0 0 */2 * 1', + '0 0 1 * */2', + '0 0 1-31 * 1', + '0 0 * * * * 2026', + ])('skips pattern %j', pattern => { + expectSkipped({ pattern, tz: 'UTC' }); + }); + + test('uses the local time zone without tz', () => { + const timezone = Intl.DateTimeFormat().resolvedOptions().timeZone; + expect(sentConfig({ pattern: '0 * * * *' })).toEqual({ + schedule: { type: 'crontab', value: '0 * * * *' }, + timezone, + }); + }); + + test.each([true, 1])('uses UTC with utc: %j', utc => { + expect(sentConfig({ pattern: '0 * * * *', tz: 'Europe/Vienna', utc })).toEqual({ + schedule: { type: 'crontab', value: '0 * * * *' }, + timezone: 'UTC', + }); + }); + + test('ignores utc on BullMQ 6', () => { + expect(sentConfig({ pattern: '0 * * * *', tz: 'Europe/Vienna', utc: true }, 6)).toEqual({ + schedule: { type: 'crontab', value: '0 * * * *' }, + timezone: 'Europe/Vienna', + }); + }); + + test.each([ + ['0 9 * * 1', '0 9 * * 1#2'], + ['0 0 9 * * mon', '0 9 * * 1#2'], + ])('reads nthDayOfWeek with %j as %j', (pattern, crontab) => { + expect(sentConfig({ pattern, nthDayOfWeek: 2, tz: 'UTC' })).toEqual({ + schedule: { type: 'crontab', value: crontab }, + timezone: 'UTC', + }); + }); + + test.each([ + ['0 9 * * *', 2], + ['0 9 * * 1-5', 2], + ['0 9 * * 1,3', 2], + ['0 9 * * 5L', 2], + ['0 9 * * 1#3', 2], + ['0 9 1 * 1', 2], + ['0 9 * * 1', 6], + ['0 9 * * 1', '2'], + ])('skips %j with nthDayOfWeek %j', (pattern, nthDayOfWeek) => { + expectSkipped({ pattern, nthDayOfWeek, tz: 'UTC' }); + }); + + test('ignores nthDayOfWeek on BullMQ 6', () => { + expect(sentConfig({ pattern: '0 9 * * 1', nthDayOfWeek: 2, tz: 'UTC' }, 6)).toEqual({ + schedule: { type: 'crontab', value: '0 9 * * 1' }, + timezone: 'UTC', + }); + }); + + test('logs why a scheduler is not monitored once', () => { + const logSpy = vi.spyOn(SentryCore.debug, 'log').mockImplementation(() => undefined); + const worker = createWorker(); + instrumentWorker(worker, {}, 5); + for (let run = 0; run < 2; run++) { + const job = schedulerJob('limited', { every: 60_000, limit: 3 }); + worker.processFn(job); + worker.emit('completed', job, 'result', 'active'); + } + + expect(logSpy).toHaveBeenCalledTimes(1); + expect(logSpy).toHaveBeenCalledWith('[BullMQJobScheduler] Not monitoring reports-limited: it sets a limit.'); + }); + + test('remembers only the last 100 schedulers it logged', () => { + const logSpy = vi.spyOn(SentryCore.debug, 'log').mockImplementation(() => undefined); + const worker = createWorker(); + instrumentWorker(worker, {}, 5); + for (const id of ['first', ...Array.from({ length: 100 }, (_, i) => `other-${i}`), 'first']) { + worker.emit('completed', schedulerJob(id, { every: 60_000, limit: 3 }), 'result', 'active'); + } + + expect(logSpy.mock.calls.filter(([message]) => String(message).includes('reports-first:'))).toHaveLength(2); + }); + + test('skips a fixed UTC offset', () => { + expectSkipped({ pattern: '0 * * * *', tz: 'UTC+5' }); + }); + + test.each([ + [300_000, { type: 'interval', value: 5, unit: 'minute' }], + [7_200_000, { type: 'interval', value: 2, unit: 'hour' }], + [86_400_000, { type: 'interval', value: 1, unit: 'day' }], + ])('converts every %j ms to an interval', (every, schedule) => { + expect(sentConfig({ every })).toEqual({ schedule }); + }); + + test.each([30_000, 90_000])('skips every %j ms', every => { + expectSkipped({ every }); + }); + + test.each([{ limit: 3 }, { endDate: Date.now() + 60_000 }])('skips a scheduler that ends: %j', end => { + expectSkipped({ every: 60_000, ...end }); + }); + + test.each([ + ['a job that is not from a scheduler', { name: 'job', opts: {} }], + [ + 'a legacy repeatable job', + schedulerJob(createHash('md5').update('job::::60000').digest('hex'), { every: 60_000, offset: 1000 }), + ], + [ + 'a legacy repeatable job with a jobId and tz', + schedulerJob(createHash('md5').update('job:my-id::UTC:0 * * * *').digest('hex'), { + pattern: '0 * * * *', + tz: 'UTC', + jobId: 'my-id', + }), + ], + [ + 'a legacy repeatable job from a queue that hashes keys with sha1', + schedulerJob(createHash('sha1').update('job::::60000').digest('hex'), { every: 60_000 }), + ], + ['a legacy repeatable job with an unhashed key', schedulerJob('job::::60000', { every: 60_000 })], + ['a legacy repeatable job with a custom key', schedulerJob('custom-key', { every: 60_000, key: 'custom-key' })], + ['an excluded scheduler', schedulerJob('cache-warmup', { every: 60_000 })], + ['a scheduler matching an excluded pattern', schedulerJob('tmp-cleanup', { every: 60_000 })], + ])('ignores %s', (_, job) => { + const worker = createWorker(); + instrumentWorker(worker, { excludeJobSchedulers: ['cache-warmup', /^tmp-/] }, 5); + worker.processFn(job); + worker.emit('failed', finalFailure(job)); + + expect(captureCheckInSpy).not.toHaveBeenCalled(); + }); + + test("ignores a legacy repeatable job hashed with the worker's repeatKeyHashAlgorithm", () => { + const worker = createWorker({ settings: { repeatKeyHashAlgorithm: 'sha384' } }); + const job = schedulerJob(createHash('sha384').update('job::::60000').digest('hex'), { every: 60_000 }); + runJob(job, 'completed', worker); + + expect(captureCheckInSpy).not.toHaveBeenCalled(); + }); + + test('logs that a legacy repeatable job with an endDate is not monitored once', () => { + const logSpy = vi.spyOn(SentryCore.debug, 'log').mockImplementation(() => undefined); + const endDate = Date.UTC(2030, 0, 1); + const id = createHash('md5').update(`job::${endDate}::60000`).digest('hex'); + const worker = createWorker(); + instrumentWorker(worker, {}, 5); + for (let run = 0; run < 2; run++) { + const job = schedulerJob(id, { every: 60_000, endDate: new Date(endDate).toISOString() }); + worker.processFn(job); + worker.emit('completed', job, 'result', 'active'); + } + + expect(captureCheckInSpy).not.toHaveBeenCalled(); + expect(logSpy).toHaveBeenCalledTimes(1); + expect(logSpy).toHaveBeenCalledWith( + `[BullMQJobScheduler] Not monitoring reports-${id}: it is a repeatable job added with queue.add, not a job scheduler.`, + ); + }); + + test.each(['0123456789abcdef0123456789abcdef', 'a:b:c:d:e'])('monitors a scheduler with the id %j', id => { + runJob(schedulerJob(id, { every: 60_000 })); + + expect(captureCheckInSpy).toHaveBeenCalledWith( + expect.objectContaining({ monitorSlug: `reports-${id}`, status: 'ok' }), + expect.anything(), + ); + }); + + test('calls the processor with the worker and its arguments', () => { + const worker = createWorker(); + const processor = worker.processFn; + instrumentWorker(worker, {}, 5); + const job = schedulerJob('my-scheduler', { every: 60_000 }); + + expect(worker.processFn.call(worker, job, 'token')).toBe('result'); + expect(processor).toHaveBeenCalledWith(job, 'token'); + expect(vi.mocked(processor).mock.contexts[0]).toBe(worker); + }); + + test('sends an error check-in for a job that fails without running the processor', () => { + const worker = createWorker(); + instrumentWorker(worker, {}, 5); + const job = finalFailure(schedulerJob('my-scheduler', { every: 60_000 }, { attemptsStarted: 3 })); + worker.emit('failed', job, new Error('job started more than allowable limit'), 'active'); + + expect(captureCheckInSpy).toHaveBeenCalledTimes(1); + expect(captureCheckInSpy).toHaveBeenCalledWith( + { monitorSlug: 'reports-my-scheduler', status: 'error', checkInId: expect.any(String) }, + { schedule: { type: 'interval', value: 1, unit: 'minute' } }, + ); + }); + + test('keeps one check-in open across retries, on any worker', () => { + const repeat = { every: 60_000 }; + const firstWorker = createWorker(); + instrumentWorker(firstWorker, {}, 5); + const firstAttempt = schedulerJob('my-scheduler', repeat); + firstWorker.processFn(firstAttempt); + firstWorker.emit('failed', Object.assign(firstAttempt, { attemptsMade: 1 }), new Error('boom'), 'active'); + + const secondWorker = createWorker(); + instrumentWorker(secondWorker, {}, 5); + const retry = schedulerJob('my-scheduler', repeat, { attemptsStarted: 2, attemptsMade: 1 }); + secondWorker.processFn(retry); + secondWorker.emit('completed', retry, 'result', 'active'); + + const checkIns = captureCheckInSpy.mock.calls.map(([checkIn]) => checkIn); + const checkInId = checkIns[0].checkInId; + // Without a duration, Sentry measures from the first attempt's `in_progress` check-in. + expect(checkIns).toEqual([ + { monitorSlug: 'reports-my-scheduler', status: 'in_progress', checkInId }, + { monitorSlug: 'reports-my-scheduler', status: 'in_progress', checkInId }, + { monitorSlug: 'reports-my-scheduler', status: 'ok', checkInId }, + ]); + }); + + test('uses a different check-in id for each run', () => { + runJob(schedulerJob('my-scheduler', { every: 60_000 })); + runJob(schedulerJob('my-scheduler', { every: 60_000 }, { id: 'repeat:my-scheduler:1767225660000' })); + + const [first, , second] = captureCheckInSpy.mock.calls.map(([checkIn]) => checkIn.checkInId); + expect(first).not.toBe(second); + }); + + test('sends an ok check-in for a job that completes without running the processor', () => { + const worker = createWorker(); + instrumentWorker(worker, {}, 5); + worker.emit('completed', schedulerJob('my-scheduler', { every: 60_000 }), 'result', 'active'); + + expect(captureCheckInSpy).toHaveBeenCalledWith( + { monitorSlug: 'reports-my-scheduler', status: 'ok', checkInId: expect.any(String) }, + { schedule: { type: 'interval', value: 1, unit: 'minute' } }, + ); + }); + + test('skips patterns with a custom repeat strategy', () => { + const worker = createWorker({ settings: { repeatStrategy: () => Date.now() } }); + instrumentWorker(worker, {}, 5); + for (const repeat of [{ pattern: '0 * * * *', tz: 'UTC' }, { every: 60_000 }]) { + const job = schedulerJob('my-scheduler', repeat); + worker.processFn(job); + worker.emit('completed', job, 'result', 'active'); + } + + expect(captureCheckInSpy.mock.calls.map(([, config]) => config)).toEqual([ + { schedule: { type: 'interval', value: 1, unit: 'minute' } }, + { schedule: { type: 'interval', value: 1, unit: 'minute' } }, + ]); + }); + + test('instruments a worker only once', () => { + const worker = createWorker(); + instrumentWorker(worker, {}, 5); + runJob(schedulerJob('my-scheduler', { every: 60_000 }), 'completed', worker); + + expect(captureCheckInSpy).toHaveBeenCalledTimes(2); + }); + + test('does not throw into the worker when sending a check-in fails', () => { + captureCheckInSpy.mockImplementation(() => { + throw new Error('sentry failed'); + }); + + expect(() => runJob(schedulerJob('my-scheduler', { every: 60_000 }))).not.toThrow(); + }); +}); diff --git a/packages/server-utils/test/orchestrion/config.test.ts b/packages/server-utils/test/orchestrion/config.test.ts index 0385405c1573..fd02b838c2d3 100644 --- a/packages/server-utils/test/orchestrion/config.test.ts +++ b/packages/server-utils/test/orchestrion/config.test.ts @@ -8,6 +8,7 @@ import { SENTRY_RUNTIME_INSTRUMENTATIONS, withoutInstrumentedExternals, } from '../../src/orchestrion/config'; +import { bullmqConfig } from '../../src/orchestrion/config/bullmq'; import { CHANNEL_INTEGRATION_DEFINITIONS } from '../../src/orchestrion/config/channel-integration-definitions'; import { MODULE_REGISTRATION_TRANSFORM } from '../../src/orchestrion/config/registration-only'; @@ -45,7 +46,7 @@ describe('getInstrumentedModuleNames', () => { expect(getInstrumentedModuleNames()).not.toContain('@remix-run/node'); expect(INSTRUMENTED_MODULE_NAMES).toContain('@remix-run/node'); expect(new Set(getInstrumentedModuleNames())).toEqual( - new Set(SENTRY_INSTRUMENTATIONS.map(instrumentation => instrumentation.module.name)), + new Set([...SENTRY_INSTRUMENTATIONS.map(instrumentation => instrumentation.module.name), 'bullmq']), ); }); }); @@ -79,6 +80,22 @@ describe('orchestrion config — Flue', () => { }); }); +describe('orchestrion config — BullMQ', () => { + it('transforms bullmq at runtime', () => { + expect(SENTRY_RUNTIME_INSTRUMENTATIONS.map(i => i.module.name)).toContain('bullmq'); + }); + + // Bundled, BullMQ can't find the files it starts sandboxed processors from. + it('is not force-bundled', () => { + expect(SENTRY_INSTRUMENTATIONS.map(i => i.module.name)).not.toContain('bullmq'); + expect(INSTRUMENTED_MODULE_NAMES).not.toContain('bullmq'); + }); + + it('is kept external, so the runtime loader can transform it', () => { + expect(getInstrumentedModuleNames()).toContain('bullmq'); + }); +}); + describe('orchestrion config — custom instrumentations', () => { const customInstrumentation = { module: { name: 'my-lib' } } as InstrumentationConfig; @@ -118,11 +135,13 @@ describe('orchestrion config — SENTRY_RUNTIME_INSTRUMENTATIONS', () => { it('keeps every transform-less config, dropping only the ones with a custom transform', () => { // Nothing the runtime can apply is lost: each transform-less config from the full - // set survives (by reference), and the runtime set adds nothing extra. + // set survives (by reference), and the runtime set only adds the runtime-only BullMQ configs. for (const config of SENTRY_INSTRUMENTATIONS.filter(c => !c.transform)) { expect(SENTRY_RUNTIME_INSTRUMENTATIONS).toContain(config); } - expect(SENTRY_RUNTIME_INSTRUMENTATIONS).toHaveLength(SENTRY_INSTRUMENTATIONS.filter(c => !c.transform).length); + expect(SENTRY_RUNTIME_INSTRUMENTATIONS).toHaveLength( + SENTRY_INSTRUMENTATIONS.filter(c => !c.transform).length + bullmqConfig.length, + ); }); it('excludes only the native-channel modules, and only via their registration-only config', () => { diff --git a/packages/solidstart/src/server/index.ts b/packages/solidstart/src/server/index.ts index 39c5b31b1d38..3a37be1816e2 100644 --- a/packages/solidstart/src/server/index.ts +++ b/packages/solidstart/src/server/index.ts @@ -40,6 +40,7 @@ export { flush, functionToStringIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration, diff --git a/packages/sveltekit/src/server/index.ts b/packages/sveltekit/src/server/index.ts index 711a9b4ae3bf..2bc7fc8446e6 100644 --- a/packages/sveltekit/src/server/index.ts +++ b/packages/sveltekit/src/server/index.ts @@ -38,6 +38,7 @@ export { flush, functionToStringIntegration, genericPoolIntegration, + bullmqJobSchedulerIntegration, cronJobIntegration, nodeCronIntegration, nodeScheduleIntegration,