From f8bd75c20abb469593304fec7580228b1ca33359 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 08:26:09 +0000 Subject: [PATCH 01/15] feat(worker): stop polling idle workers on Redis and PostgreSQL An idle worker polled its queues every idleDelay (2s by default): on PostgreSQL, several transactions per queue on every poll, and up to idleDelay of latency before a new job ran. Adapters may now implement subscribe(queues, onWake, signal). onWake receives the time at which work becomes due: now for a new job, later for a delayed job, a retry, or a schedule run. A subscribed worker sleeps until a signal for now, the next due time it was told about, or the next stalled check, which is also the poll that finds lost signals. The worker polls until its subscription is ready, and aborts it when it stops first. Adapters announce now, the next delayed job of each queue, and the next schedule that can run when they subscribe and after each reconnection. A pop that promotes delayed jobs announces the next delayed job of its queue. - Redis publishes from the Lua scripts that write the job or schedule, so the signal goes with the write in one round trip, and listens on a duplicated connection. - Knex on PostgreSQL sends pg_notify on the connection of the write: a job dispatched in an application transaction is signaled on commit, and not at all on rollback. A connection outside the pool runs LISTEN; the adapter owns its client before it connects, so it can end it in its handshake, and calls a connection provider again once its settings expire. MySQL, SQLite, and Kysely keep polling. The knex() factory now accepts options as its second argument, including notifications: false for poolers without LISTEN support such as PgBouncer in transaction mode. A table name string still works. --- README.md | 24 +- src/contracts/adapter.ts | 35 +++ src/drivers/knex_adapter.ts | 301 ++++++++++++++++++++- src/drivers/redis_adapter.ts | 134 ++++++++- src/drivers/redis_scripts.ts | 56 ++++ src/drivers/wake_messages.ts | 44 +++ src/worker_session.ts | 76 +++++- src/worker_wakeup.ts | 81 ++++++ tests/_utils/register_wake_signal_suite.ts | 285 +++++++++++++++++++ tests/adapter.spec.ts | 265 +++++++++++++++++- tests/worker_session.spec.ts | 151 +++++++++++ 11 files changed, 1424 insertions(+), 28 deletions(-) create mode 100644 src/drivers/wake_messages.ts create mode 100644 src/worker_wakeup.ts create mode 100644 tests/_utils/register_wake_signal_suite.ts diff --git a/README.md b/README.md index 6bc6462..d8b6187 100644 --- a/README.md +++ b/README.md @@ -411,8 +411,15 @@ import Knex from 'knex' const connection = Knex({ client: 'pg', connection: '...' }) const adapter = knex(connection) -// Custom table name +// Custom table names const adapter = knex(config, 'custom_jobs_table') +const adapter = knex(config, { + tableName: 'custom_jobs_table', + schedulesTableName: 'custom_schedules_table', +}) + +// Behind PgBouncer in transaction mode, which does not support LISTEN: poll instead +const adapter = knex(config, { notifications: false }) ``` @@ -932,7 +939,7 @@ const config = { worker: { adapter: 'redis', // Registered Adapter listened to by this Worker concurrency: 5, // Parallel jobs - idleDelay: '2s', // Poll interval when idle + idleDelay: '2s', // Poll interval when idle (adapters without wake signals) timeout: '1m', // Default job timeout stalledThreshold: '30s', // When to consider job stalled stalledInterval: '30s', // How often to check @@ -943,6 +950,19 @@ const config = { } ``` +On Redis and PostgreSQL (Knex), an idle Worker does not poll: the Adapter signals new jobs through +Redis pub/sub or `LISTEN`/`NOTIFY`, and the Worker also wakes when a delayed job, a retry, or a +schedule becomes due. A job dispatched in a PostgreSQL transaction is signaled when it commits. A +signal can be lost, so the Worker still checks its queues every `stalledInterval`. Behind a pooler +that does not support `LISTEN`, such as PgBouncer in transaction mode, pass `notifications: false` +to `knex()`. MySQL, SQLite, and Kysely poll every `idleDelay`. + +The process that dispatches a job sends its signal. A job dispatched by an older version of the +package, or written to the storage without the Adapter, sends none: the Worker finds it at its next +stalled check. Upgrade the processes that dispatch jobs with, or before, the Workers. Each Worker +holds one more connection for its subscription: a Redis connection, or a PostgreSQL connection +outside of the Knex pool. + Run one Worker per process. A Worker listens on one Adapter, so to process the queues of several Adapters, start one process per Adapter. Starting a second Worker while another one runs in the same process throws `E_WORKER_ALREADY_RUNNING`: initializing it would destroy the Adapters of the diff --git a/src/contracts/adapter.ts b/src/contracts/adapter.ts index 64dc591..0936343 100644 --- a/src/contracts/adapter.ts +++ b/src/contracts/adapter.ts @@ -55,6 +55,17 @@ export interface StalledJobsRecovery { exceeded: AcquiredJob[] } +/** + * Receives the time (epoch ms) at which work may become due: now for a job + * ready to run, later for a delayed job, a retry, or a schedule. + */ +export type WakeListener = (at: number) => void + +/** + * Ends a subscription opened by `Adapter.subscribe`. + */ +export type Unsubscribe = () => Promise + /** * Adapter interface for queue storage backends. * @@ -100,6 +111,30 @@ export interface Adapter { */ popFrom(queue: string): Promise + /** + * Optional. Notify a worker when work may become due on `queues`, so it can + * sleep instead of polling. Without it, the worker polls every `idleDelay`. + * + * Signals are hints. A signal may be lost (reconnection, a broker without + * delivery guarantees), so the worker still polls once per stalled interval. + * To make up for signals sent before subscribing or while disconnected, the + * adapter calls `onWake` with now and with the next known due times once + * subscribed and after each reconnection. + * + * The worker polls until `subscribe` resolves, and aborts `signal` when it + * stops first: the adapter then releases what it opened and rejects. + * + * @param queues - The queues the worker processes + * @param onWake - Called with the time at which work may become due + * @param signal - Aborted when the worker stops before the subscription is ready + * @returns Ends the subscription + */ + subscribe?( + queues: readonly string[], + onWake: WakeListener, + signal?: AbortSignal + ): Promise + /** * Recover stalled jobs that have been active for too long. * A stalled job is one where the worker stopped responding (e.g., crash). diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 8d1d87d..80024bd 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -7,6 +7,8 @@ import type { JobLease, PushResult, StalledJobsRecovery, + Unsubscribe, + WakeListener, } from '../contracts/adapter.js' import type { AdapterFactoryContext, @@ -35,6 +37,7 @@ import { import { KnexQueueSchemaService } from '../services/knex_queue_schema.js' import { scheduleDatesMigrationRequiredMessage } from '../services/schedule_dates.js' import { SCHEDULE_TIMING_COLUMNS } from '../services/schedule_timing.js' +import { dispatchWakeMessage, encodeWakeMessage, type WakeMessage } from './wake_messages.js' export { KnexQueueSchemaService } from '../services/knex_queue_schema.js' export type { ScheduleDatesMigrationOptions } from '../services/schedule_dates.js' @@ -47,6 +50,38 @@ export interface KnexAdapterOptions { ownsConnection?: boolean /** Receives the retention prunings that fail. Defaults to the console. */ logger?: Logger + /** + * PostgreSQL only. Wake workers through LISTEN/NOTIFY instead of polling. + * Disable it behind a pooler that does not support LISTEN, such as + * PgBouncer in transaction mode. Defaults to true. + */ + notifications?: boolean +} + +/** + * The part of a node-postgres client the LISTEN connection uses. + */ +interface PgListenClient { + connect(): Promise + end(): Promise + query(sql: string): Promise + on( + event: 'notification', + listener: (message: { channel: string; payload?: string }) => void + ): void + on(event: 'error' | 'end', listener: (error?: Error) => void): void + removeAllListeners(): void +} + +const LISTEN_RECONNECT_DELAY = 1000 +const LISTEN_MAX_RECONNECT_DELAY = 30_000 + +/** + * A subscriber and the next schedule run it was told about. + */ +interface ScheduleWatcher { + onWake: WakeListener + at: number | null } /** @@ -73,6 +108,14 @@ interface ScheduleRow extends DbRow { created_at: number | string | null } +/** + * Options of the `knex()` factory. + */ +export type KnexFactoryOptions = Pick< + KnexAdapterOptions, + 'tableName' | 'schedulesTableName' | 'notifications' +> + /** * Create a new Knex adapter factory. * Accepts either a Knex instance or a Knex configuration object. @@ -82,14 +125,22 @@ interface ScheduleRow extends DbRow { * * When passing a Knex instance, the caller is responsible for * managing the connection lifecycle. + * + * ```ts + * knex(config) + * knex(config, 'custom_jobs_table') + * knex(config, { tableName: 'custom_jobs_table', notifications: false }) + * ``` */ -export function knex(config: KnexConfig, tableName?: string) { +export function knex(config: KnexConfig, options?: string | KnexFactoryOptions) { + const resolved = typeof options === 'string' ? { tableName: options } : options + return (context?: AdapterFactoryContext) => { const isKnexInstance = typeof config === 'function' const connection = isKnexInstance ? config : KnexPkg(config) return new KnexAdapter({ + ...resolved, connection, - tableName, ownsConnection: !isKnexInstance, logger: context?.logger, }) @@ -106,15 +157,213 @@ export class KnexAdapter implements Adapter { readonly #schedulesTable: string readonly #ownsConnection: boolean readonly #logger: Logger + /** Set on PostgreSQL with notifications enabled: the jobs table names the channel. */ + readonly #wakeChannel?: string + /** Subscribers of this adapter: see claimDueSchedule. */ + readonly #scheduleWatchers = new Set() #workerId: string = '' #scheduleDatesCheck: Promise | undefined + /** Defined on PostgreSQL with notifications enabled. See `Adapter.subscribe`. */ + readonly subscribe?: ( + queues: readonly string[], + onWake: WakeListener, + signal?: AbortSignal + ) => Promise + constructor(config: KnexAdapterOptions) { this.#connection = config.connection this.#jobsTable = config.tableName ?? 'queue_jobs' this.#schedulesTable = config.schedulesTableName ?? 'queue_schedules' this.#ownsConnection = config.ownsConnection ?? false this.#logger = config.logger ?? consoleLogger + + if (this.#connection.client.dialect === 'postgresql' && config.notifications !== false) { + this.#wakeChannel = this.#jobsTable + this.subscribe = (queues, onWake, signal) => this.#listen(queues, onWake, signal) + } + } + + /** + * NOTIFY the workers. On a transaction, PostgreSQL delivers the + * notification on commit, and drops it on rollback. + */ + async #notify(connection: Knex, message: WakeMessage): Promise { + if (!this.#wakeChannel) return + + const query = connection.raw('select pg_notify(?, ?)', [ + this.#wakeChannel, + encodeWakeMessage(message), + ]) + + // A failed statement aborts the transaction: let the application see it. + if (connection.isTransaction) { + await query + return + } + + // The job is stored: a lost signal only delays it until the next poll. + try { + await query + } catch (error) { + debug('failed to notify workers: %O', error) + } + } + + /** + * LISTEN on a connection outside of the pool, held for the whole + * subscription. A lost connection is replaced with a growing delay. + * + * The client is created from the driver of Knex rather than with + * acquireRawConnection, which only returns it once connected: ending the + * subscription must be able to abort a connection still in its handshake. + */ + async #listen( + queues: readonly string[], + onWake: WakeListener, + signal?: AbortSignal + ): Promise { + const channel = this.#wakeChannel! + const knexClient = this.#connection.client + const watcher: ScheduleWatcher = { onWake, at: null } + let client: PgListenClient | undefined + let closed = false + let reconnectTimer: NodeJS.Timeout | undefined + let reconnectDelay = LISTEN_RECONNECT_DELAY + // A client ended in its handshake never settles connect(): closing does. + const closing = Promise.withResolvers() + closing.promise.catch(() => {}) + + const release = async () => { + const current = client + client = undefined + if (!current) return + current.removeAllListeners() + await current.end().catch(() => {}) + } + + // A connection config provider is called again once its settings expire, + // as the pool of Knex does, for rotated credentials for instance. + let providedSettings: object | undefined + let settingsExpired: (() => boolean) | null = null + const createClient = async (): Promise => { + const provider = knexClient.connectionConfigProvider + if (!provider) return new knexClient.driver.Client(knexClient.connectionSettings) + + if (!providedSettings || settingsExpired?.()) { + const { expirationChecker, ...settings } = await provider() + providedSettings = settings + settingsExpired = expirationChecker ?? null + } + return new knexClient.driver.Client(providedSettings) + } + + // Signals sent before listening, or while disconnected, are lost. + const announce = async () => { + onWake(Date.now()) + // One per queue: promoting a job only announces the next one of its queue. + const rows: Array<{ at: number | string | null }> = await this.#connection(this.#jobsTable) + .whereIn('queue', [...queues]) + .where('status', 'delayed') + .groupBy('queue') + .min('execute_at as at') + for (const row of rows) { + if (row.at !== null) onWake(Number(row.at)) + } + await this.#announceNextSchedule(watcher) + } + + const onLost = (error?: Error) => { + if (closed || reconnectTimer) return + this.#logger.error({ err: error }, 'Lost the LISTEN connection, reconnecting') + void release() + reconnectTimer = setTimeout(() => { + reconnectTimer = undefined + if (closed) return + connect().then( + () => (reconnectDelay = LISTEN_RECONNECT_DELAY), + (connectError) => { + reconnectDelay = Math.min(reconnectDelay * 2, LISTEN_MAX_RECONNECT_DELAY) + onLost(connectError) + } + ) + }, reconnectDelay) + } + + const connect = async () => { + const connection = await createClient() + client = connection + connection.on('error', onLost) + connection.on('end', () => onLost()) + connection.on('notification', (message) => { + if (message.channel !== channel || !message.payload) return + dispatchWakeMessage(message.payload, queues, onWake, async () => { + watcher.at = await this.#nextScheduleAt() + return watcher.at + }).catch((error) => this.#logger.error({ err: error }, 'Failed to handle a wake signal')) + }) + await Promise.race([connection.connect(), closing.promise]) + await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) + if (closed) return release() + await announce() + } + + signal?.throwIfAborted() + this.#scheduleWatchers.add(watcher) + const close = async () => { + closed = true + closing.reject(new Error('The LISTEN subscription is closed')) + clearTimeout(reconnectTimer) + signal?.removeEventListener('abort', abort) + this.#scheduleWatchers.delete(watcher) + await release() + } + // Ends the first connection, even in its handshake. + const abort = () => void close() + signal?.addEventListener('abort', abort, { once: true }) + + try { + await connect() + signal?.throwIfAborted() + } catch (error) { + // The connection may have failed with an error event: no reconnection. + await close() + throw error + } + + return close + } + + async #announceNextSchedule(watcher: ScheduleWatcher, onlyFuture = false): Promise { + watcher.at = await this.#nextScheduleAt() + if (watcher.at === null) return + if (onlyFuture && watcher.at <= Date.now()) return + watcher.onWake(watcher.at) + } + + /** + * Next run of a schedule that claimDueSchedule can claim: a schedule past + * its run limit or end date stays active but never runs again. + */ + async #nextScheduleAt(): Promise { + const row = await this.#connection(this.#schedulesTable) + .where('status', 'active') + .whereNotNull('next_run_at') + .where((builder) => { + builder.whereNull('run_limit').orWhereRaw('run_count < run_limit') + }) + .where((builder) => { + builder + .whereNull('to_date') + .orWhere((range) => + range + .where('to_date', '>=', Date.now()) + .whereRaw('?? >= ??', ['to_date', 'next_run_at']) + ) + }) + .min('next_run_at as at') + .first() + return row?.at === null || row?.at === undefined ? null : Number(row.at) } setWorkerId(workerId: string): void { @@ -321,6 +570,20 @@ export class KnexAdapter implements Adapter { execute_at: null, }) } + + // Workers only know the next delayed job: announce the one after it. + // Due rows left are being promoted by concurrent transactions. + if (this.#wakeChannel) { + const next = await trx(this.#jobsTable) + .where('queue', queue) + .where('status', 'delayed') + .where('execute_at', '>', now) + .min('execute_at as at') + .first() + if (next?.at !== null && next?.at !== undefined) { + await this.#notify(trx, { queue, at: Number(next.at) }) + } + } }) } @@ -518,6 +781,7 @@ export class KnexAdapter implements Adapter { score: null, execute_at: retryAt.getTime(), }) + if (updated > 0) await this.#notify(this.#connection, { queue, at: retryAt.getTime() }) return updated > 0 } @@ -533,6 +797,7 @@ export class KnexAdapter implements Adapter { score, execute_at: null, }) + if (updated > 0) await this.#notify(this.#connection, { queue, at: now }) return updated > 0 } @@ -546,13 +811,15 @@ export class KnexAdapter implements Adapter { const score = calculateScore(priority, timestamp) if (jobData.dedup) { - return this.#pushWithDedup(queue, jobData, { + const result = await this.#pushWithDedup(queue, jobData, { id: jobData.id, queue, status: 'pending', data: JSON.stringify(jobData), score, }) + await this.#notify(this.#connection, { queue, at: timestamp }) + return result } await this.#connection(this.#jobsTable).insert({ @@ -562,6 +829,7 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), score, }) + await this.#notify(this.#connection, { queue, at: timestamp }) } async pushLater(jobData: JobData, delay: number): Promise { @@ -572,13 +840,15 @@ export class KnexAdapter implements Adapter { const executeAt = Date.now() + delay if (jobData.dedup) { - return this.#pushWithDedup(queue, jobData, { + const result = await this.#pushWithDedup(queue, jobData, { id: jobData.id, queue, status: 'delayed', data: JSON.stringify(jobData), execute_at: executeAt, }) + await this.#notify(this.#connection, { queue, at: executeAt }) + return result } await this.#connection(this.#jobsTable).insert({ @@ -588,6 +858,7 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), execute_at: executeAt, }) + await this.#notify(this.#connection, { queue, at: executeAt }) } async #pushWithDedup( @@ -773,6 +1044,7 @@ export class KnexAdapter implements Adapter { for (let start = 0; start < rows.length; start += SQL_INSERT_CHUNK_SIZE) { await connection(this.#jobsTable).insert(rows.slice(start, start + SQL_INSERT_CHUNK_SIZE)) } + await this.#notify(connection, { queue, at: now }) } if (this.#connection.isTransaction) { @@ -860,6 +1132,7 @@ export class KnexAdapter implements Adapter { } } + if (recovered > 0) await this.#notify(trx, { queue, at: now }) return { recovered, exceeded } }) } @@ -941,6 +1214,7 @@ export class KnexAdapter implements Adapter { ]), ...definition, }) + await this.#notify(this.#connection, { schedules: true }) return id } @@ -991,6 +1265,7 @@ export class KnexAdapter implements Adapter { if (Object.keys(data).length > 0) { await this.#connection(this.#schedulesTable).where('id', id).update(data) + await this.#notify(this.#connection, { schedules: true }) } } @@ -998,6 +1273,7 @@ export class KnexAdapter implements Adapter { await this.#assertScheduleDatesMigrated() await this.#connection(this.#schedulesTable).where('id', id).delete() + await this.#notify(this.#connection, { schedules: true }) } async claimDueSchedule(): Promise { @@ -1005,7 +1281,7 @@ export class KnexAdapter implements Adapter { const now = Date.now() - return this.#claimTransaction(this.#schedulesTable, async (trx) => { + const claimed = await this.#claimTransaction(this.#schedulesTable, async (trx) => { // Find one due schedule with row locking let query = trx(this.#schedulesTable) .where('status', 'active') @@ -1059,10 +1335,25 @@ export class KnexAdapter implements Adapter { last_run_at: now, run_count: newRunCount, }) + await this.#notify(trx, { schedules: true }) // Return schedule data (before update state for payload) return this.#rowToScheduleData(row) }) + + // A watcher woken for a schedule that expired meanwhile, past its end + // date or run limit, waits for nothing: tell it the next claimable one. + // A due one is locked by a concurrent claim, which notifies on commit: + // waking for it again would only spin. + if (!claimed) { + for (const watcher of this.#scheduleWatchers) { + if (watcher.at !== null && watcher.at <= now) { + await this.#announceNextSchedule(watcher, true) + } + } + } + + return claimed } #rowToScheduleData(row: ScheduleRow): ScheduleData { diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index a8eb730..a003c46 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -8,8 +8,11 @@ import type { JobLease, PushResult, StalledJobsRecovery, + Unsubscribe, + WakeListener, } from '../contracts/adapter.js' -import { consoleLogger } from '../logger.js' +import { consoleLogger, type Logger } from '../logger.js' +import { dispatchWakeMessage, encodeWakeMessage, type WakeMessage } from './wake_messages.js' import type { AdapterFactoryContext, DedupOutcome } from '../types/main.js' import type { JobData, @@ -45,6 +48,8 @@ const schedulesDueKey = 'schedules::due' // Schedule hashes live one level below the index keys so no schedule id can collide with them. const scheduleDataPrefix = 'schedules::data::' const legacyScheduleDataPrefix = 'schedules::' +// ioredis does not prefix pub/sub channels: the adapter adds the key prefix itself. +const wakeChannelSuffix = 'jobs::wake' /** * An ioredis connection, or the options to create one. @@ -69,7 +74,7 @@ function isRedisConnection(config?: RedisConfig): config is Redis { export function redis(config?: RedisConfig) { return ({ logger }: AdapterFactoryContext = { logger: consoleLogger }) => { if (isRedisConnection(config)) { - return new RedisAdapter(config, false) + return new RedisAdapter(config, false, logger) } const options: RedisOptions = { @@ -86,17 +91,102 @@ export function redis(config?: RedisConfig) { logger.error({ err: error }, 'Redis connection error') }) - return new RedisAdapter(connection, true) + return new RedisAdapter(connection, true, logger) } } export class RedisAdapter implements Adapter { readonly #connection: Redis readonly #ownsConnection: boolean + readonly #logger: Logger #workerId: string = '' - constructor(connection: Redis, ownsConnection: boolean = false) { + constructor(connection: Redis, ownsConnection: boolean = false, logger: Logger = consoleLogger) { this.#connection = connection this.#ownsConnection = ownsConnection + this.#logger = logger + } + + get #wakeChannel(): string { + return `${this.#connection.options?.keyPrefix ?? ''}${wakeChannelSuffix}` + } + + /** + * The channel and message of a wake signal, passed as the last two ARGV of + * the script that announces it (see PUBLISH_WAKE_LUA). + */ + #wake(message: WakeMessage): [string, string] { + return [this.#wakeChannel, encodeWakeMessage(message)] + } + + /** + * Listen on the wake channel through a dedicated connection: a connection + * in subscriber mode cannot run other commands. + */ + async subscribe( + queues: readonly string[], + onWake: WakeListener, + signal?: AbortSignal + ): Promise { + signal?.throwIfAborted() + const subscriber = this.#connection.duplicate() + let subscribed = false + + const logError = (error: unknown, message: string) => { + this.#logger.error({ err: error as Error }, message) + } + + // Signals sent before subscribing, or while disconnected, are lost. + const announce = async () => { + onWake(Date.now()) + for (const queue of queues) { + const [, score] = await this.#connection.zrange( + this.#getKeys(queue).delayed, + '0', + '0', + 'WITHSCORES' + ) + if (score !== undefined) onWake(Number(score)) + } + const nextSchedule = await this.#nextScheduleAt() + if (nextSchedule !== null) onWake(nextSchedule) + } + + subscriber.on('error', (error) => logError(error, 'Redis wake subscriber error')) + subscriber.on('message', (channel: string, raw: string) => { + if (channel !== this.#wakeChannel) return + dispatchWakeMessage(raw, queues, onWake, () => this.#nextScheduleAt()).catch((error) => + logError(error, 'Failed to handle a wake signal') + ) + }) + // ioredis subscribes again on reconnection. + subscriber.on('ready', () => { + if (subscribed) announce().catch((error) => logError(error, 'Failed to announce due work')) + }) + + const abort = () => subscriber.disconnect() + signal?.addEventListener('abort', abort, { once: true }) + + try { + await subscriber.subscribe(this.#wakeChannel) + subscribed = true + await announce() + signal?.throwIfAborted() + } catch (error) { + subscriber.disconnect() + throw error + } finally { + signal?.removeEventListener('abort', abort) + } + + return async () => { + subscribed = false + subscriber.disconnect() + } + } + + async #nextScheduleAt(): Promise { + const [, score] = await this.#connection.zrange(schedulesDueKey, '0', '0', 'WITHSCORES') + return score === undefined ? null : Number(score) } #getKeys(queue: string) { @@ -154,7 +244,9 @@ export class RedisAdapter implements Adapter { keys.overlay, this.#workerId, now.toString(), - leaseToken + leaseToken, + this.#wakeChannel, + queue ) if (!result) { @@ -270,7 +362,8 @@ export class RedisAdapter implements Adapter { job.id, retryAt ? retryAt.getTime().toString() : '0', now.toString(), - job.leaseToken + job.leaseToken, + ...this.#wake({ queue, at: Math.max(retryAt?.getTime() ?? now, now) }) ) return retried === 1 } @@ -333,7 +426,8 @@ export class RedisAdapter implements Adapter { jobData.dedup.extend ? '1' : '0', jobData.dedup.replace ? '1' : '0', payloadData, - payloadIsUndefined + payloadIsUndefined, + ...this.#wake({ queue, at: executeAt }) )) as [string, string] return { outcome: result[0] as DedupOutcome, jobId: result[1] } } @@ -346,7 +440,8 @@ export class RedisAdapter implements Adapter { keys.overlay, jobData.id, JSON.stringify(jobData), - executeAt.toString() + executeAt.toString(), + ...this.#wake({ queue, at: executeAt }) ) } @@ -374,7 +469,8 @@ export class RedisAdapter implements Adapter { jobData.dedup.extend ? '1' : '0', jobData.dedup.replace ? '1' : '0', payloadData, - payloadIsUndefined + payloadIsUndefined, + ...this.#wake({ queue, at: timestamp }) )) as [string, string] return { outcome: result[0] as DedupOutcome, jobId: result[1] } } @@ -387,7 +483,8 @@ export class RedisAdapter implements Adapter { keys.overlay, jobData.id, JSON.stringify(jobData), - score.toString() + score.toString(), + ...this.#wake({ queue, at: timestamp }) ) } @@ -414,6 +511,7 @@ export class RedisAdapter implements Adapter { multi.zadd(keys.pending, score, job.id) } + multi.publish(...this.#wake({ queue, at: now })) await multi.exec() } @@ -449,7 +547,8 @@ export class RedisAdapter implements Adapter { maxStalledCount.toString(), this.#workerId, maxExceeded.toString(), - leaseTokenPrefix + leaseTokenPrefix, + ...this.#wake({ queue, at: now }) )) as [number, ...string[]] return { @@ -514,7 +613,8 @@ export class RedisAdapter implements Adapter { id, now.toString(), JSON.stringify(scheduleData), - config.nextRunAt?.getTime().toString() ?? '' + config.nextRunAt?.getTime().toString() ?? '', + ...this.#wake({ schedules: true }) )) as [string, string, string] | null // Finalize it as its worker would have, from the time of the claim. The @@ -615,7 +715,8 @@ export class RedisAdapter implements Adapter { scheduleKey, schedulesDueKey, id, - JSON.stringify(data) + JSON.stringify(data), + ...this.#wake({ schedules: true }) ) } @@ -626,6 +727,7 @@ export class RedisAdapter implements Adapter { .del(scheduleKey) .srem(schedulesIndexKey, id) .zrem(schedulesDueKey, id) + .publish(...this.#wake({ schedules: true })) .exec() } @@ -651,7 +753,8 @@ export class RedisAdapter implements Adapter { schedulesDueKey, scheduleDataPrefix, now.toString(), - claimToken + claimToken, + ...this.#wake({ schedules: true }) )) as ['claimed' | 'unfinalized', string] | null if (!result) { @@ -723,7 +826,8 @@ export class RedisAdapter implements Adapter { claim.cronExpression, claim.configRevision, claim.claimToken, - nextRunAt.toString() + nextRunAt.toString(), + ...this.#wake({ schedules: true }) ) } diff --git a/src/drivers/redis_scripts.ts b/src/drivers/redis_scripts.ts index 9efe584..60de887 100644 --- a/src/drivers/redis_scripts.ts +++ b/src/drivers/redis_scripts.ts @@ -1,5 +1,16 @@ import { REDIS_DEDUP_LUA, REDIS_JOB_STORAGE_LUA } from './redis_job_storage.js' +/** + * Publishes the wake signal of a script, given as its last two ARGV: the + * channel and the message. Publishing from the script keeps one round trip + * and sends the signal with the write it announces. + */ +const PUBLISH_WAKE_LUA = ` + local function publish_wake() + redis.call('PUBLISH', ARGV[#ARGV - 1], ARGV[#ARGV]) + end +` + /** * Lua script for pushing a job to the queue. * Stores job data in the central hash and adds jobId to pending ZSET. @@ -14,8 +25,11 @@ export const PUSH_JOB_SCRIPT = ` ${REDIS_JOB_STORAGE_LUA} +${PUBLISH_WAKE_LUA} + store_job_data(data_key, overlay_key, job_id, job_data) redis.call('ZADD', pending_key, score, job_id) + publish_wake() return 1 ` @@ -57,6 +71,10 @@ export const PUSH_DEDUP_JOB_SCRIPT = ` ${REDIS_JOB_STORAGE_LUA} ${REDIS_DEDUP_LUA} +${PUBLISH_WAKE_LUA} + + -- The job may be skipped: a spurious signal only costs a poll. + publish_wake() local existing_result = resolve_dedup_existing_job( data_key, @@ -96,8 +114,11 @@ export const PUSH_DELAYED_JOB_SCRIPT = ` ${REDIS_JOB_STORAGE_LUA} +${PUBLISH_WAKE_LUA} + store_job_data(data_key, overlay_key, job_id, job_data) redis.call('ZADD', delayed_key, execute_at, job_id) + publish_wake() return 1 ` @@ -118,6 +139,8 @@ export const ACQUIRE_JOB_SCRIPT = ` local worker_id = ARGV[1] local now = tonumber(ARGV[2]) local lease_token = ARGV[3] + local wake_channel = ARGV[4] + local queue = ARGV[5] ${REDIS_JOB_STORAGE_LUA} @@ -134,6 +157,13 @@ ${REDIS_JOB_STORAGE_LUA} redis.call('ZREM', delayed_key, job_id) end end + + -- Workers only know the next delayed job: announce the one after it. + local next_delayed = redis.call('ZRANGE', delayed_key, 0, 0, 'WITHSCORES') + if #next_delayed > 0 then + redis.call('PUBLISH', wake_channel, + cjson.encode({ queue = queue, at = tonumber(next_delayed[2]) })) + end end -- Pop highest priority job (lowest score) @@ -318,6 +348,7 @@ export const RETRY_JOB_SCRIPT = ` ${REDIS_JOB_STORAGE_LUA} ${REDIS_LEASE_LUA} +${PUBLISH_WAKE_LUA} -- Verify the caller still holds the job if not holds_lease(active_key, job_id, lease_token) then @@ -353,6 +384,7 @@ ${REDIS_LEASE_LUA} redis.call('ZADD', pending_key, score, job_id) end + publish_wake() return 1 ` @@ -378,6 +410,7 @@ export const RECOVER_STALLED_JOBS_SCRIPT = ` local lease_token_prefix = ARGV[6] ${REDIS_JOB_STORAGE_LUA} +${PUBLISH_WAKE_LUA} local recovered = 0 -- The first element is replaced by the recovered count before returning. @@ -433,6 +466,9 @@ ${REDIS_JOB_STORAGE_LUA} end result[1] = recovered + if recovered > 0 then + publish_wake() + end return result ` @@ -590,6 +626,9 @@ export const UPSERT_SCHEDULE_SCRIPT = ` local next_run_at = ARGV[4] ${SCHEDULE_DUE_INDEX_LUA} +${PUBLISH_WAKE_LUA} + + publish_wake() -- The same test as migrate(): an indexed id with a 0.7 hash at its old key. if redis.call('SISMEMBER', schedules_index_key, id) == 1 @@ -668,6 +707,9 @@ export const UPDATE_SCHEDULE_SCRIPT = ` local updates = cjson.decode(ARGV[2]) ${SCHEDULE_DUE_INDEX_LUA} +${PUBLISH_WAKE_LUA} + + publish_wake() if redis.call('EXISTS', schedule_key) == 0 then redis.call('ZREM', due_key, id) @@ -703,6 +745,9 @@ export const FINALIZE_CRON_SCHEDULE_SCRIPT = ` local next_run_at = ARGV[5] ${SCHEDULE_DUE_INDEX_LUA} +${PUBLISH_WAKE_LUA} + + publish_wake() if redis.call('EXISTS', schedule_key) == 0 then redis.call('ZREM', due_key, id) @@ -852,6 +897,7 @@ ${SCHEDULE_DUE_INDEX_LUA} * KEYS[2] = schedule key prefix (e.g. "schedules::data::") * ARGV[1] = now (epoch milliseconds) * ARGV[2] = claim token, kept by the schedule when it is a cron + * ARGV[3], ARGV[4] = wake channel and message, published when the due index changes * * Returns nil, or `{ 'claimed' | 'unfinalized', }`. */ @@ -862,14 +908,23 @@ export const CLAIM_SCHEDULE_SCRIPT = ` local claim_token = ARGV[2] ${SCHEDULE_DUE_INDEX_LUA} +${PUBLISH_WAKE_LUA} + + local skipped = false while true do local candidates = redis.call('ZRANGEBYSCORE', due_key, '-inf', tostring(now), 'LIMIT', 0, 1) if #candidates == 0 then + -- Subscribers may wait for a skipped entry: let them read the next one. + if skipped then + publish_wake() + end return nil end + skipped = true + local id = candidates[1] local schedule_key = prefix .. id @@ -952,6 +1007,7 @@ ${SCHEDULE_DUE_INDEX_LUA} 'claimed_at', new_claimed_at) sync_schedule_due_index(schedule_key, due_key, id) + publish_wake() -- Return the schedule data (before update) as JSON return { 'claimed', cjson.encode(schedule) } diff --git a/src/drivers/wake_messages.ts b/src/drivers/wake_messages.ts new file mode 100644 index 0000000..2e11650 --- /dev/null +++ b/src/drivers/wake_messages.ts @@ -0,0 +1,44 @@ +import type { WakeListener } from '../contracts/adapter.js' + +/** + * Message adapters publish on their wake channel. + * + * - `{ queue, at }`: a job of `queue` becomes due at `at` (epoch ms). + * - `{ schedules: true }`: schedules changed. A schedule is not tied to a + * queue and its next run is not always known by the writer, so subscribers + * read the next due schedule from storage. + */ +export type WakeMessage = { queue: string; at: number } | { schedules: true } + +export function encodeWakeMessage(message: WakeMessage): string { + return JSON.stringify(message) +} + +/** + * Route a raw message of the wake channel to `onWake`. Messages for other + * queues are ignored; schedule changes call `readNextSchedule`. + */ +export async function dispatchWakeMessage( + raw: string, + queues: readonly string[], + onWake: WakeListener, + readNextSchedule: () => Promise +): Promise { + let message: Partial<{ queue: unknown; at: unknown; schedules: unknown }> + + try { + message = JSON.parse(raw) + } catch { + return + } + + if (message.schedules === true) { + const at = await readNextSchedule() + if (at !== null) onWake(at) + return + } + + if (typeof message.queue === 'string' && typeof message.at === 'number') { + if (queues.includes(message.queue)) onWake(message.at) + } +} diff --git a/src/worker_session.ts b/src/worker_session.ts index ba08baf..e71e5bb 100644 --- a/src/worker_session.ts +++ b/src/worker_session.ts @@ -5,8 +5,9 @@ import { parse, retryOnDeadlock } from './utils.js' import { JobPool, type PoolEntry } from './job_pool.js' import { WorkerHeartbeat, type HeartbeatOperationWrapper } from './worker_heartbeat.js' import { Locator } from './locator.js' +import { WorkerWakeup } from './worker_wakeup.js' import type { SingleJobDispatchRequest } from './job_dispatch_runtime.js' -import type { Adapter, AcquiredJob } from './contracts/adapter.js' +import type { Adapter, AcquiredJob, Unsubscribe } from './contracts/adapter.js' import type { JobExecutionOutcome, JobExecutionRuntime } from './job_runtime.js' import type { Logger, WorkerCycle } from './types/main.js' import { DEFAULT_ERROR_RETRY_DELAY, UNKNOWN_JOB_RETRY_DELAY } from './constants.js' @@ -80,6 +81,8 @@ export class WorkerSession { #completionDelayController?: AbortController #lastStalledCheck = 0 #delayController?: AbortController + /** Set while `start()` holds a subscription: idle waits sleep until a signal. */ + #wakeup?: WorkerWakeup constructor(options: WorkerSessionOptions) { this.#workerId = options.workerId @@ -122,6 +125,10 @@ export class WorkerSession { const completion = Promise.withResolvers() this.#startCompletion = completion.promise + // Polls until the subscription is ready: a slow handshake delays no job. + const subscribeAbort = new AbortController() + const subscription = this.#subscribe(subscribeAbort.signal) + try { debug('starting worker %s on queues: %O', this.#workerId, this.#queues) @@ -141,9 +148,15 @@ export class WorkerSession { debug('worker %s is idle, waiting for %dms', this.#workerId, delay) } - await this.#waitBeforeNextCycle(delay) + await this.#waitBeforeNextCycle(cycle.type === 'idle' && this.#wakeup ? null : delay) } } finally { + this.#wakeup = undefined + subscribeAbort.abort() + const unsubscribe = await subscription + await unsubscribe?.().catch((error) => { + this.#logger.error({ err: error, workerId: this.#workerId }, 'Failed to unsubscribe') + }) completion.resolve() if (this.#startCompletion === completion.promise) { this.#startCompletion = undefined @@ -270,14 +283,62 @@ export class WorkerSession { } } - async #waitBeforeNextCycle(delay: number): Promise { + /** + * Subscribe to the wake signals of the adapter, when it supports them. A + * failure is logged and the worker keeps polling. `signal` aborts a + * subscription that is not ready when the session stops. + */ + async #subscribe(signal: AbortSignal): Promise { + if (!this.#adapter.subscribe) return + + const wakeup = new WorkerWakeup() + + try { + const unsubscribe = await this.#adapter.subscribe( + this.#queues, + (at) => wakeup.notify(at), + signal + ) + if (!signal.aborted) { + this.#wakeup = wakeup + debug('worker %s subscribed to wake signals', this.#workerId) + // The current wait polls: end it, so the next one sleeps until a signal. + this.#delayController?.abort() + this.#completionDelayController?.abort() + } + return unsubscribe + } catch (error) { + if (signal.aborted) return + this.#logger.error( + { err: error as Error, workerId: this.#workerId }, + 'Failed to subscribe to wake signals, polling instead' + ) + } + } + + /** + * Time left before the next stalled check. A subscribed worker sleeps at + * most this long: the check doubles as the poll that catches lost signals. + */ + #untilStalledCheck(): number { + return Math.max(this.#lastStalledCheck + this.#settings.stalledInterval - Date.now(), 0) + } + + /** + * Sleep for `delay`, or until a wake signal when `delay` is null. + */ + async #waitBeforeNextCycle(delay: number | null): Promise { if (!this.#running) return const controller = new AbortController() this.#delayController = controller try { - await setTimeout(delay, undefined, { signal: controller.signal }) + if (delay === null) { + await this.#wakeup?.wait(this.#untilStalledCheck(), controller.signal) + } else { + await setTimeout(delay, undefined, { signal: controller.signal }) + } } catch (error) { if (!controller.signal.aborted) { throw error @@ -295,6 +356,7 @@ export class WorkerSession { try { while (this.#running) { try { + this.#wakeup?.reset() await this.#checkStalledJobs() if (!this.#running) break @@ -365,7 +427,11 @@ export class WorkerSession { this.#completionDelayController = controller try { - await setTimeout(this.#settings.idleDelay, undefined, { signal: controller.signal }) + if (this.#wakeup) { + await this.#wakeup.wait(this.#untilStalledCheck(), controller.signal) + } else { + await setTimeout(this.#settings.idleDelay, undefined, { signal: controller.signal }) + } } catch (error) { if (!controller.signal.aborted) { throw error diff --git a/src/worker_wakeup.ts b/src/worker_wakeup.ts new file mode 100644 index 0000000..dab81c9 --- /dev/null +++ b/src/worker_wakeup.ts @@ -0,0 +1,81 @@ +/** + * Lets an idle worker sleep until an adapter signals that work may be due. + * + * Signals for now wake the current wait, or the next one when they arrive + * while the worker is looking for work. Signals for later are kept as timers, + * so a delayed job, a retry, or a schedule wakes the worker when it is due. + * + * ``` + * cycle: reset() ─► stalled check, schedules, pop ─► wait(maxDelay) + * ▲ notify(now) here sets `#requested`: the wait returns at once + * ``` + */ +export class WorkerWakeup { + /** Bounds the timers kept: past it, the latest are dropped and found by polling. */ + static readonly MAX_TIMERS = 1024 + + #requested = false + /** Future due times, sorted ascending, without duplicates. */ + #timers: number[] = [] + /** Re-evaluates the current wait. */ + #interrupt?: () => void + + notify(at: number): void { + if (at <= Date.now()) { + this.#requested = true + } else if (!this.#insert(at)) { + return + } + + this.#interrupt?.() + } + + /** + * Call before looking for work: the signals received until then are + * covered by this look, those received from now on wake the next wait. + */ + reset(): void { + this.#requested = false + const now = Date.now() + const due = this.#timers.findIndex((at) => at > now) + this.#timers.splice(0, due === -1 ? this.#timers.length : due) + } + + /** + * Resolve on a signal for now, when the next timer is due, after + * `maxDelay`, or when `signal` aborts. + */ + async wait(maxDelay: number, signal: AbortSignal): Promise { + const deadline = Date.now() + maxDelay + + while (!signal.aborted && !this.#requested) { + const now = Date.now() + const until = Math.min(deadline, this.#timers[0] ?? Infinity) + if (until <= now) return + + await new Promise((resolve) => { + const done = () => { + clearTimeout(timer) + signal.removeEventListener('abort', done) + this.#interrupt = undefined + resolve() + } + const timer = setTimeout(done, until - now) + signal.addEventListener('abort', done, { once: true }) + this.#interrupt = done + }) + } + } + + /** Returns false when `at` was already known or past the bound. */ + #insert(at: number): boolean { + let index = this.#timers.findIndex((timer) => timer >= at) + if (index === -1) index = this.#timers.length + if (this.#timers[index] === at) return false + if (index >= WorkerWakeup.MAX_TIMERS) return false + + this.#timers.splice(index, 0, at) + if (this.#timers.length > WorkerWakeup.MAX_TIMERS) this.#timers.pop() + return true + } +} diff --git a/tests/_utils/register_wake_signal_suite.ts b/tests/_utils/register_wake_signal_suite.ts new file mode 100644 index 0000000..67fc3dc --- /dev/null +++ b/tests/_utils/register_wake_signal_suite.ts @@ -0,0 +1,285 @@ +import { setTimeout } from 'node:timers/promises' +import { test as JapaTest } from '@japa/runner' +import type { Adapter } from '../../src/contracts/adapter.js' + +interface WakeSignalSuiteOptions { + test: typeof JapaTest + /** Creates an adapter that implements `subscribe`. */ + createAdapter: () => Adapter + /** See `inTransaction` of the driver test suite. */ + inTransaction?: (operation: (adapter: Adapter) => Promise) => Promise +} + +const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) + +/** Subscribe and record the signals received after the initial announcement. */ +async function listen(adapter: Adapter, queues = ['default']) { + const wakes: number[] = [] + const unsubscribe = await adapter.subscribe!(queues, (at) => wakes.push(at)) + + return { + wakes, + unsubscribe, + clear: () => wakes.splice(0), + async next(timeout = 2000): Promise { + const start = Date.now() + while (wakes.length === 0) { + if (Date.now() - start > timeout) throw new Error('No wake signal received') + await setTimeout(5) + } + return wakes.shift()! + }, + } +} + +/** + * Wake signals of adapters that implement `subscribe`. The subscriber and the + * writer use separate adapters, as a worker and a dispatcher would. + */ +export function registerWakeSignalSuite({ + test, + createAdapter, + inTransaction, +}: WakeSignalSuiteOptions) { + test('signals a push to the subscribers of its queue only', async ({ assert, cleanup }) => { + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + listener.clear() + const writer = createAdapter() + + await writer.pushOn('other', job('other-queue')) + await setTimeout(100) + assert.deepEqual(listener.wakes, []) + + const before = Date.now() + await writer.pushOn('default', job('default-queue')) + const at = await listener.next() + assert.isAtLeast(at, before) + assert.isAtMost(at, Date.now()) + }) + + test('signals when a delayed job and a retry become due', async ({ assert, cleanup }) => { + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + listener.clear() + const writer = createAdapter() + + const before = Date.now() + await writer.pushLaterOn('default', job('delayed'), 60_000) + const delayedAt = await listener.next() + assert.isAtLeast(delayedAt, before + 60_000) + assert.isAtMost(delayedAt, Date.now() + 60_000) + + await writer.pushOn('default', job('retried')) + await listener.next() + const acquired = await writer.popFrom('default') + const retryAt = new Date(Date.now() + 30_000) + await writer.retryJob(acquired!, 'default', retryAt) + assert.equal(await listener.next(), retryAt.getTime()) + }) + + test('signals the next run of a schedule when it changes or runs', async ({ + assert, + cleanup, + }) => { + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + listener.clear() + const writer = createAdapter() + + const firstRun = Date.now() - 1000 + await writer.upsertSchedule({ + id: 'wake-schedule', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(firstRun), + }) + assert.equal(await listener.next(), firstRun) + + const before = Date.now() + await writer.claimDueSchedule() + const nextRun = await listener.next() + assert.isAtLeast(nextRun, before + 60_000) + assert.isAtMost(nextRun, Date.now() + 60_000) + }) + + test('announces work stored before subscribing', async ({ assert, cleanup }) => { + const writer = createAdapter() + const delayedBefore = Date.now() + await writer.pushLaterOn('default', job('stored-delayed'), 60_000) + const delayedAfter = Date.now() + const scheduleRun = Date.now() + 30_000 + await writer.upsertSchedule({ + id: 'stored-schedule', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(scheduleRun), + }) + + const before = Date.now() + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + const [now, delayedAt, ...rest] = listener.wakes + + assert.isAtLeast(now, before) + assert.isAtLeast(delayedAt, delayedBefore + 60_000) + assert.isAtMost(delayedAt, delayedAfter + 60_000) + assert.deepEqual(rest, [scheduleRun]) + }) + + test('announces the next delayed job once the previous one is promoted', async ({ + assert, + cleanup, + }) => { + const writer = createAdapter() + await writer.pushLaterOn('default', job('first-delayed'), 50) + const before = Date.now() + await writer.pushLaterOn('default', job('second-delayed'), 60_000) + const after = Date.now() + + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + listener.clear() + + await setTimeout(100) + await writer.popFrom('default') + const at = await listener.next() + assert.isAtLeast(at, before + 60_000) + assert.isAtMost(at, after + 60_000) + }) + + test('announces the next delayed job of each queue', async ({ assert, cleanup }) => { + const writer = createAdapter() + await writer.pushLaterOn('first', job('first-queue'), 30_000) + const before = Date.now() + await writer.pushLaterOn('second', job('second-queue'), 60_000) + const after = Date.now() + + const listener = await listen(createAdapter(), ['first', 'second']) + cleanup(listener.unsubscribe) + + assert.isTrue( + listener.wakes.some((at) => at >= before + 60_000 && at <= after + 60_000), + 'the second queue is announced' + ) + }) + + test('announces the next schedule past an expired one', async ({ assert, cleanup }) => { + const writer = createAdapter() + const now = Date.now() + await writer.upsertSchedule({ + id: 'expired', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + to: new Date(now - 500), + nextRunAt: new Date(now - 1000), + }) + const nextRun = now + 60_000 + await writer.upsertSchedule({ + id: 'next', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(nextRun), + }) + + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + + // A worker woken for the expired schedule claims nothing. + assert.isNull(await writer.claimDueSchedule()) + await setTimeout(100) + assert.include(listener.wakes, nextRun) + }) + + test('announces the next schedule when the announced one expires before running', async ({ + assert, + cleanup, + }) => { + const writer = createAdapter() + const now = Date.now() + await writer.upsertSchedule({ + id: 'expiring', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + to: new Date(now + 150), + nextRunAt: new Date(now + 100), + }) + const nextRun = now + 60_000 + await writer.upsertSchedule({ + id: 'next', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(nextRun), + }) + + // The worker adapter is told about the expiring schedule only. + const worker = createAdapter() + const listener = await listen(worker) + cleanup(listener.unsubscribe) + assert.include(listener.wakes, now + 100) + listener.clear() + + // It wakes once the schedule has also passed its end date. + await setTimeout(200) + assert.isNull(await worker.claimDueSchedule()) + await setTimeout(100) + assert.include(listener.wakes, nextRun) + }) + + test('announces the next schedule when one is deleted', async ({ assert, cleanup }) => { + const writer = createAdapter() + const schedule = (id: string, nextRunAt: number) => + writer.upsertSchedule({ + id, + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(nextRunAt), + }) + const secondRun = Date.now() + 60_000 + await schedule('first', Date.now() + 30_000) + await schedule('second', secondRun) + + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + listener.clear() + + await writer.deleteSchedule('first') + assert.equal(await listener.next(), secondRun) + }) + + if (inTransaction) { + test('signals a push in a transaction once it commits', async ({ assert, cleanup }) => { + const listener = await listen(createAdapter()) + cleanup(listener.unsubscribe) + listener.clear() + + await inTransaction(async (adapter) => { + await adapter.pushOn('default', job('committed')) + await setTimeout(100) + assert.deepEqual(listener.wakes, [], 'no signal before the commit') + }) + await listener.next() + + await inTransaction(async (adapter) => { + await adapter.pushOn('default', job('rolled-back')) + throw new Error('rollback') + }).catch(() => {}) + await setTimeout(100) + assert.deepEqual(listener.wakes, [], 'no signal after a rollback') + }) + } +} diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 7903838..02ca112 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -9,9 +9,10 @@ import { Redis } from 'ioredis' import { CronExpressionParser } from 'cron-parser' import { MemoryAdapter } from './_mocks/memory_adapter.js' import { redis, RedisAdapter } from '../src/drivers/redis_adapter.js' -import { KnexAdapter } from '../src/drivers/knex_adapter.js' +import { knex, KnexAdapter } from '../src/drivers/knex_adapter.js' import { KnexQueueSchemaService } from '../src/services/knex_queue_schema.js' import { registerDriverTestSuite } from './_utils/register_driver_test_suite.js' +import { registerWakeSignalSuite } from './_utils/register_wake_signal_suite.js' import { withRedisWriteSpy } from './_utils/with_redis_write_spy.js' import { withKnexQuerySpy } from './_utils/with_knex_query_spy.js' import { pauseKnexDeletes } from './_utils/pause_deletes.js' @@ -115,6 +116,11 @@ test.group('Adapter | Redis', (group) => { createAdapter: () => new RedisAdapter(connection), }) + registerWakeSignalSuite({ + test, + createAdapter: () => new RedisAdapter(connection), + }) + test('listSchedules should use bounded network round-trips as schedule count grows', async ({ assert, }) => { @@ -2354,6 +2360,263 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { }, }) + registerWakeSignalSuite({ + test, + inTransaction: (operation) => + connection.transaction((trx) => + operation(new KnexAdapter({ connection: trx, tableName, schedulesTableName })) + ), + createAdapter: () => new KnexAdapter({ connection, tableName, schedulesTableName }), + }) + + test('announces a future delayed job past rows another transaction promotes', async ({ + assert, + cleanup, + }) => { + const row = (id: string, executeAt: number) => ({ + id, + queue: 'default', + status: 'delayed', + data: JSON.stringify({ id, name: 'TestJob', payload: {}, attempts: 0 }), + execute_at: executeAt, + }) + const now = Date.now() + const nextAt = now + 60_000 + await connection(tableName).insert([ + row('locked', now - 2000), + row('own', now - 1000), + row('next', nextAt), + ]) + + const wakes: number[] = [] + const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) + const unsubscribe = await subscriber.subscribe!(['default'], (at) => wakes.push(at)) + cleanup(unsubscribe) + wakes.splice(0) + + // Another worker holds the oldest due row while it promotes it. + const trx = await connection.transaction() + cleanup(async () => { + await trx.rollback() + }) + await trx(tableName).where('id', 'locked').forUpdate().first() + + await new KnexAdapter({ connection, tableName, schedulesTableName }).popFrom('default') + await new Promise((resolve) => setTimeout(resolve, 100)) + assert.deepEqual(wakes, [nextAt]) + }) + + /** + * Replace the node-postgres client the adapter creates for LISTEN. Each + * fake gets the behavior `behave` returns for its 1-based creation number. + */ + function fakeListenClients( + cleanup: (callback: () => void) => void, + behave: (index: number) => { connect?: () => Promise; query?: () => Promise } + ) { + const client = connection.client as KnexTypes.Client & { driver: { Client: unknown } } + const driver = client.driver + client.driver = { ...driver } + cleanup(() => { + client.driver = driver + }) + + const created: Array<{ ended: boolean; emit: (event: string, error?: Error) => void }> = [] + client.driver.Client = class { + #listeners = new Map void>() + #behavior = behave(created.length + 1) + state = { + ended: false, + emit: (event: string, error?: Error) => this.#listeners.get(event)?.(error), + } + + constructor() { + created.push(this.state) + } + on(event: string, listener: (error?: Error) => void) { + this.#listeners.set(event, listener) + } + removeAllListeners() { + this.#listeners.clear() + } + // As node-postgres: connect() never settles once ended in its handshake. + async connect() { + await this.#behavior.connect?.() + } + async query() { + await this.#behavior.query?.() + } + async end() { + this.state.ended = true + } + } + return created + } + + test('aborts a first LISTEN connection still in its handshake', async ({ assert, cleanup }) => { + const created = fakeListenClients(cleanup, () => ({ connect: () => new Promise(() => {}) })) + const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) + const controller = new AbortController() + + const subscription = subscriber.subscribe!(['default'], () => {}, controller.signal) + while (created.length < 1) await new Promise((resolve) => setTimeout(resolve, 5)) + controller.abort() + + await assert.rejects(() => subscription) + assert.isTrue(created[0].ended) + }) + + test('does not wake again for a due schedule a concurrent claim holds', async ({ + assert, + cleanup, + }) => { + await connection(schedulesTableName).insert({ + id: 'locked', + name: 'TestJob', + payload: '{}', + every_ms: 60_000, + timezone: 'UTC', + next_run_at: Date.now() + 100, + run_count: 0, + status: 'active', + created_at: Date.now(), + }) + const worker = new KnexAdapter({ connection, tableName, schedulesTableName }) + const wakes: number[] = [] + const unsubscribe = await worker.subscribe!(['default'], (at) => wakes.push(at)) + cleanup(unsubscribe) + wakes.splice(0) + + // Another worker is claiming the schedule when it becomes due. + const trx = await connection.transaction() + cleanup(async () => { + await trx.rollback() + }) + await trx(schedulesTableName).where('id', 'locked').forUpdate().first() + await new Promise((resolve) => setTimeout(resolve, 150)) + + assert.isNull(await worker.claimDueSchedule()) + await new Promise((resolve) => setTimeout(resolve, 50)) + assert.deepEqual(wakes, [], 'the commit of the other claim notifies') + }) + + test('calls the connection provider again when its settings expire', async ({ + assert, + cleanup, + }) => { + let provided = 0 + let expired = false + const provider = Knex({ + client: 'pg', + connection: async () => { + provided++ + expired = false + return { + host: process.env.PG_HOST || 'localhost', + port: Number.parseInt(process.env.PG_PORT || '5432', 10), + user: process.env.PG_USER || 'postgres', + password: process.env.PG_PASSWORD || 'postgres', + database: process.env.PG_DATABASE || 'queue_test', + application_name: `listen-${provided}`, + expirationChecker: () => expired, + } + }, + }) + cleanup(() => provider.destroy()) + const listenerName = async () => { + const result = await connection.raw( + `select application_name from pg_stat_activity where query like 'LISTEN%' and application_name like 'listen-%'` + ) + return result.rows.map((row: { application_name: string }) => row.application_name) + } + + const subscriber = new KnexAdapter({ + connection: provider, + tableName, + schedulesTableName, + logger: new MemoryLogger(), + }) + const unsubscribe = await subscriber.subscribe!(['default'], () => {}) + cleanup(unsubscribe) + const [first] = await listenerName() + + // Rotated credentials: the provider marks its settings expired. + expired = true + await connection.raw( + `select pg_terminate_backend(pid) from pg_stat_activity where application_name = ?`, + [first] + ) + await new Promise((resolve) => setTimeout(resolve, 1500)) + + const [second] = await listenerName() + assert.isDefined(second) + assert.notEqual(second, first) + }) + + test('does not reconnect a LISTEN connection that failed to subscribe', async ({ + assert, + cleanup, + }) => { + const created = fakeListenClients(cleanup, () => ({ + async query() { + const error = new Error('Connection terminated') + created[0].emit('error', error) + throw error + }, + })) + + const subscriber = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + logger: new MemoryLogger(), + }) + await assert.rejects( + () => subscriber.subscribe!(['default'], () => {}), + 'Connection terminated' + ) + + // Past the reconnection delay + await new Promise((resolve) => setTimeout(resolve, 1200)) + assert.lengthOf(created, 1) + }) + + test('aborts a LISTEN reconnection still in its handshake when unsubscribing', async ({ + assert, + cleanup, + }) => { + // The second connection never completes its handshake. + const created = fakeListenClients(cleanup, (index) => ({ + connect: index === 1 ? async () => {} : () => new Promise(() => {}), + })) + + const subscriber = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + logger: new MemoryLogger(), + }) + const unsubscribe = await subscriber.subscribe!(['default'], () => {}) + created[0].emit('error', new Error('Connection terminated')) + + while (created.length < 2) await new Promise((resolve) => setTimeout(resolve, 20)) + await unsubscribe() + assert.isTrue(created[1].ended) + }) + + test('knex() factory accepts a table name or options', async ({ assert }) => { + const job = { id: 'factory-job', name: 'TestJob', payload: {}, attempts: 0 } + + await knex(connection, tableName)().pushOn('default', job) + + const polling = knex(connection, { tableName, schedulesTableName, notifications: false })() + assert.isUndefined(polling.subscribe) + assert.isNotNull(await polling.getJob(job.id, 'default'), 'the string sets the jobs table') + + const listening = knex(connection, { tableName, schedulesTableName })() + assert.isFunction(listening.subscribe) + }) + registerPruneFailureSuite({ test, createAdapter: (logger) => { diff --git a/tests/worker_session.spec.ts b/tests/worker_session.spec.ts index 256172d..bb328d8 100644 --- a/tests/worker_session.spec.ts +++ b/tests/worker_session.spec.ts @@ -11,6 +11,7 @@ import { import { ControllableAdapter } from './_mocks/controllable_adapter.js' import { trackPromise } from './_utils/track_promise.js' import { MemoryLogger } from './_mocks/memory_logger.js' +import type { Unsubscribe, WakeListener } from '../src/contracts/adapter.js' type SessionOverrides = Partial> & { jobExecutionRuntime?: Partial @@ -869,3 +870,153 @@ test.group('WorkerSession', () => { assert.equal(errorCycle?.type, 'error') }) }) + +/** Hands the wake listener of `subscribe` to the test. */ +class SubscribableAdapter extends ControllableAdapter { + onWake?: WakeListener + subscribeError?: Error + + async subscribe( + _queues: readonly string[], + onWake: WakeListener, + _signal?: AbortSignal + ): Promise { + if (this.subscribeError) throw this.subscribeError + this.onWake = onWake + return async () => { + this.onWake = undefined + } + } +} + +const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) + +test.group('WorkerSession | wake signals', () => { + test('sleeps until a wake signal instead of polling every idleDelay', async ({ + assert, + cleanup, + }) => { + const adapter = new SubscribableAdapter() + const executed = Promise.withResolvers() + const session = createSession({ + adapter, + settings: { idleDelay: 10 }, + jobExecutionRuntime: { + async execute() { + executed.resolve() + return { type: 'completed' } + }, + }, + }) + cleanup(() => session.stop()) + + const start = session.start() + await adapter.acquisitions.waitForSettled(1) + await setTimeout(100) + assert.equal(adapter.acquisitions.calls, 1) + + await adapter.pushOn('default', job('woken')) + adapter.onWake!(Date.now()) + await executed.promise + + await session.stop() + await start + assert.isUndefined(adapter.onWake, 'stopping ends the subscription') + }) + + test('wakes when a signalled due time is reached', async ({ assert, cleanup }) => { + const adapter = new SubscribableAdapter() + const session = createSession({ adapter }) + cleanup(() => session.stop()) + + void session.start() + await adapter.acquisitions.waitForSettled(1) + adapter.onWake!(Date.now() + 150) + + await setTimeout(75) + assert.equal(adapter.acquisitions.calls, 1) + await setTimeout(150) + assert.equal(adapter.acquisitions.calls, 2) + }) + + test('keeps a signal received while looking for work', async ({ cleanup }) => { + const adapter = new SubscribableAdapter() + adapter.acquisitions.block(1) + const session = createSession({ adapter }) + cleanup(async () => { + adapter.acquisitions.releaseAll() + await session.stop() + }) + + void session.start() + await adapter.acquisitions.waitForStarted(1) + adapter.onWake!(Date.now()) + adapter.acquisitions.release(1) + + // Lost, the signal would leave the session asleep until the stalled check. + await adapter.acquisitions.waitForStarted(2) + }) + + test('polls and stops while the subscription is not ready', async ({ assert }) => { + const adapter = new SubscribableAdapter() + let aborted = false + adapter.subscribe = (_queues, _onWake, signal) => + new Promise((_resolve, reject) => { + signal?.addEventListener('abort', () => { + aborted = true + reject(signal.reason) + }) + }) + const logger = new MemoryLogger() + const session = createSession({ adapter, logger, settings: { idleDelay: 10 } }) + + const start = session.start() + await adapter.acquisitions.waitForStarted(3) + await session.stop() + await start + + assert.isTrue(aborted, 'stopping aborts the pending subscription') + assert.deepEqual(logger.logs, [], 'an aborted subscription is not an error') + }) + + test('follows the signals of a subscription that gets ready while polling', async ({ + assert, + cleanup, + }) => { + const adapter = new SubscribableAdapter() + const ready = Promise.withResolvers() + const subscribe = adapter.subscribe.bind(adapter) + adapter.subscribe = async (queues, onWake, signal) => { + await ready.promise + return subscribe(queues, onWake, signal) + } + const session = createSession({ adapter, settings: { idleDelay: 60_000 } }) + cleanup(() => session.stop()) + + void session.start() + await adapter.acquisitions.waitForSettled(1) + await setTimeout(20) // the session now sleeps for idleDelay + ready.resolve() + while (!adapter.onWake) await setTimeout(1) + adapter.onWake(Date.now() + 100) + + // Without it, the first poll would wait for idleDelay. + await setTimeout(200) + assert.isAtLeast(adapter.acquisitions.calls, 2) + }) + + test('polls every idleDelay when subscribing fails', async ({ assert, cleanup }) => { + const adapter = new SubscribableAdapter() + adapter.subscribeError = new Error('LISTEN is not supported') + const logger = new MemoryLogger() + const session = createSession({ adapter, logger, settings: { idleDelay: 10 } }) + cleanup(() => session.stop()) + + void session.start() + await adapter.acquisitions.waitForStarted(3) + + const errors = logger.logs.filter((entry) => entry.level === 'error') + assert.equal(errors[0].message, 'Failed to subscribe to wake signals, polling instead') + assert.strictEqual(errors[0].obj?.err, adapter.subscribeError) + }) +}) From bd53eb6095f31c858d20d7483497dfaa700e56a6 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 09:48:32 +0000 Subject: [PATCH 02/15] fix(worker): make wake signals safe in real deployments Tests against PgBouncer, Redis ACLs and multiple hosts found cases where wake signals broke writes, slowed workers or went unnoticed: - Redis: a user without channel permissions failed every push after its writes, because PUBLISH raised inside the scripts. Scripts now use redis.pcall, so the write succeeds and the worker polls. The channel also includes the database, since pub/sub ignores it. - PostgreSQL behind PgBouncer in transaction mode: LISTEN succeeded but never received anything, so jobs waited for the stalled check. The subscriber now sends a probe notification and falls back to polling with a clear message when it does not arrive. - A table name over 63 bytes failed pg_notify. The channel name is hashed in that case. - "Now" signals carried the producer clock: a producer ahead of the worker delayed jobs until the stalled check. They no longer carry a timestamp, so the worker uses its own clock. - Sequential pushes lost about a third of their throughput, as PostgreSQL serializes NOTIFY commits. Signals for ready jobs are now coalesced per queue, and a delayed job is inserted and signalled in one statement. --- src/drivers/knex_adapter.ts | 139 ++++++++++++++++++++++++++++---- src/drivers/redis_adapter.ts | 18 +++-- src/drivers/redis_scripts.ts | 8 +- src/drivers/wake_messages.ts | 10 ++- tests/adapter.spec.ts | 149 ++++++++++++++++++++++++++++++++--- 5 files changed, 287 insertions(+), 37 deletions(-) diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 80024bd..cc7b383 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -1,4 +1,4 @@ -import { randomUUID } from 'node:crypto' +import { createHash, randomUUID } from 'node:crypto' import KnexPkg from 'knex' import type { Knex } from 'knex' import type { @@ -73,7 +73,17 @@ interface PgListenClient { removeAllListeners(): void } +/** + * The channel of a jobs table. PostgreSQL rejects a channel name over 63 + * bytes in pg_notify: a longer table name is hashed. + */ +function wakeChannelName(table: string): string { + if (Buffer.byteLength(table) <= 63) return table + return `queue_jobs_${createHash('sha256').update(table).digest('hex').slice(0, 40)}` +} + const LISTEN_RECONNECT_DELAY = 1000 +const LISTEN_PROBE_TIMEOUT = 2000 const LISTEN_MAX_RECONNECT_DELAY = 30_000 /** @@ -159,6 +169,8 @@ export class KnexAdapter implements Adapter { readonly #logger: Logger /** Set on PostgreSQL with notifications enabled: the jobs table names the channel. */ readonly #wakeChannel?: string + /** Queues with a NOTIFY of ready jobs in flight: see #pushReady. */ + readonly #readySignals = new Map }>() /** Subscribers of this adapter: see claimDueSchedule. */ readonly #scheduleWatchers = new Set() #workerId: string = '' @@ -179,7 +191,7 @@ export class KnexAdapter implements Adapter { this.#logger = config.logger ?? consoleLogger if (this.#connection.client.dialect === 'postgresql' && config.notifications !== false) { - this.#wakeChannel = this.#jobsTable + this.#wakeChannel = wakeChannelName(this.#jobsTable) this.subscribe = (queues, onWake, signal) => this.#listen(queues, onWake, signal) } } @@ -210,6 +222,62 @@ export class KnexAdapter implements Adapter { } } + /** + * Insert a job ready now and signal it. + * + * PostgreSQL serializes the commits that NOTIFY, so a NOTIFY per push + * would halve the throughput of concurrent dispatches. Outside of a + * transaction, the push returns once the job is stored and a queue has + * at most one NOTIFY in flight per adapter: a push that commits meanwhile + * asks for one more, sent once it completes, so after that commit. + * `destroy()` waits for them. + */ + async #pushReady(queue: string, row: Record): Promise { + if (!this.#wakeChannel || this.#connection.isTransaction) { + return this.#insertJob(row, { queue }) + } + + await this.#connection(this.#jobsTable).insert(row) + this.#signalReady(queue) + } + + /** Signal a ready job of `queue` that is already committed. */ + #signalReady(queue: string): void { + const inFlight = this.#readySignals.get(queue) + if (inFlight) { + inFlight.pending = true + return + } + + const state = { pending: true, sent: Promise.resolve() } + this.#readySignals.set(queue, state) + state.sent = (async () => { + while (state.pending) { + state.pending = false + await this.#notify(this.#connection, { queue }) + } + this.#readySignals.delete(queue) + })() + } + + /** + * Insert a job row and NOTIFY the workers in one statement, so the signal + * costs no round trip to dispatch. + */ + async #insertJob(row: Record, message: WakeMessage): Promise { + const insert = this.#connection(this.#jobsTable).insert(row) + if (!this.#wakeChannel) { + await insert + return + } + + await this.#connection.raw('with inserted as (?) select pg_notify(?, ?)', [ + insert, + this.#wakeChannel, + encodeWakeMessage(message), + ]) + } + /** * LISTEN on a connection outside of the pool, held for the whole * subscription. A lost connection is replaced with a growing delay. @@ -290,6 +358,37 @@ export class KnexAdapter implements Adapter { }, reconnectDelay) } + // A pooler in transaction mode, such as PgBouncer, accepts LISTEN but + // never delivers: check that a NOTIFY sent through the pool arrives. + let probe: { payload: string; received: PromiseWithResolvers } | undefined + const verify = async () => { + probe = { + payload: encodeWakeMessage({ probe: randomUUID() }), + received: Promise.withResolvers(), + } + const { received } = probe + let timer: NodeJS.Timeout | undefined + const timeout = new Promise((_resolve, reject) => { + timer = setTimeout( + () => + reject( + new Error( + 'LISTEN received no notification within 2s. Behind a pooler in transaction ' + + 'mode, such as PgBouncer, pass { notifications: false } to knex()' + ) + ), + LISTEN_PROBE_TIMEOUT + ) + }) + try { + await this.#connection.raw('select pg_notify(?, ?)', [channel, probe.payload]) + await Promise.race([received.promise, timeout, closing.promise]) + } finally { + clearTimeout(timer) + probe = undefined + } + } + const connect = async () => { const connection = await createClient() client = connection @@ -297,6 +396,7 @@ export class KnexAdapter implements Adapter { connection.on('end', () => onLost()) connection.on('notification', (message) => { if (message.channel !== channel || !message.payload) return + if (message.payload === probe?.payload) return probe.received.resolve() dispatchWakeMessage(message.payload, queues, onWake, async () => { watcher.at = await this.#nextScheduleAt() return watcher.at @@ -305,6 +405,7 @@ export class KnexAdapter implements Adapter { await Promise.race([connection.connect(), closing.promise]) await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) if (closed) return release() + await verify() await announce() } @@ -371,6 +472,7 @@ export class KnexAdapter implements Adapter { } async destroy(): Promise { + await Promise.all([...this.#readySignals.values()].map((state) => state.sent)) if (this.#ownsConnection) { await this.#connection.destroy() } @@ -797,7 +899,7 @@ export class KnexAdapter implements Adapter { score, execute_at: null, }) - if (updated > 0) await this.#notify(this.#connection, { queue, at: now }) + if (updated > 0) await this.#notify(this.#connection, { queue }) return updated > 0 } @@ -818,18 +920,21 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), score, }) - await this.#notify(this.#connection, { queue, at: timestamp }) + if (this.#connection.isTransaction) { + await this.#notify(this.#connection, { queue }) + } else if (this.#wakeChannel) { + this.#signalReady(queue) + } return result } - await this.#connection(this.#jobsTable).insert({ + await this.#pushReady(queue, { id: jobData.id, queue, status: 'pending', data: JSON.stringify(jobData), score, }) - await this.#notify(this.#connection, { queue, at: timestamp }) } async pushLater(jobData: JobData, delay: number): Promise { @@ -851,14 +956,16 @@ export class KnexAdapter implements Adapter { return result } - await this.#connection(this.#jobsTable).insert({ - id: jobData.id, - queue, - status: 'delayed', - data: JSON.stringify(jobData), - execute_at: executeAt, - }) - await this.#notify(this.#connection, { queue, at: executeAt }) + await this.#insertJob( + { + id: jobData.id, + queue, + status: 'delayed', + data: JSON.stringify(jobData), + execute_at: executeAt, + }, + { queue, at: executeAt } + ) } async #pushWithDedup( @@ -1044,7 +1151,7 @@ export class KnexAdapter implements Adapter { for (let start = 0; start < rows.length; start += SQL_INSERT_CHUNK_SIZE) { await connection(this.#jobsTable).insert(rows.slice(start, start + SQL_INSERT_CHUNK_SIZE)) } - await this.#notify(connection, { queue, at: now }) + await this.#notify(connection, { queue }) } if (this.#connection.isTransaction) { @@ -1132,7 +1239,7 @@ export class KnexAdapter implements Adapter { } } - if (recovered > 0) await this.#notify(trx, { queue, at: now }) + if (recovered > 0) await this.#notify(trx, { queue }) return { recovered, exceeded } }) } diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index a003c46..d3e9138 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -48,7 +48,8 @@ const schedulesDueKey = 'schedules::due' // Schedule hashes live one level below the index keys so no schedule id can collide with them. const scheduleDataPrefix = 'schedules::data::' const legacyScheduleDataPrefix = 'schedules::' -// ioredis does not prefix pub/sub channels: the adapter adds the key prefix itself. +// Pub/sub channels belong to no database and ioredis does not prefix them: +// the adapter adds the key prefix and the database itself. const wakeChannelSuffix = 'jobs::wake' /** @@ -107,7 +108,8 @@ export class RedisAdapter implements Adapter { } get #wakeChannel(): string { - return `${this.#connection.options?.keyPrefix ?? ''}${wakeChannelSuffix}` + const options = this.#connection.options + return `${options?.keyPrefix ?? ''}${wakeChannelSuffix}::${options?.db ?? 0}` } /** @@ -363,7 +365,9 @@ export class RedisAdapter implements Adapter { retryAt ? retryAt.getTime().toString() : '0', now.toString(), job.leaseToken, - ...this.#wake({ queue, at: Math.max(retryAt?.getTime() ?? now, now) }) + ...this.#wake( + retryAt && retryAt.getTime() > now ? { queue, at: retryAt.getTime() } : { queue } + ) ) return retried === 1 } @@ -470,7 +474,7 @@ export class RedisAdapter implements Adapter { jobData.dedup.replace ? '1' : '0', payloadData, payloadIsUndefined, - ...this.#wake({ queue, at: timestamp }) + ...this.#wake({ queue }) )) as [string, string] return { outcome: result[0] as DedupOutcome, jobId: result[1] } } @@ -484,7 +488,7 @@ export class RedisAdapter implements Adapter { jobData.id, JSON.stringify(jobData), score.toString(), - ...this.#wake({ queue, at: timestamp }) + ...this.#wake({ queue }) ) } @@ -511,7 +515,7 @@ export class RedisAdapter implements Adapter { multi.zadd(keys.pending, score, job.id) } - multi.publish(...this.#wake({ queue, at: now })) + multi.publish(...this.#wake({ queue })) await multi.exec() } @@ -548,7 +552,7 @@ export class RedisAdapter implements Adapter { this.#workerId, maxExceeded.toString(), leaseTokenPrefix, - ...this.#wake({ queue, at: now }) + ...this.#wake({ queue }) )) as [number, ...string[]] return { diff --git a/src/drivers/redis_scripts.ts b/src/drivers/redis_scripts.ts index 60de887..aea992f 100644 --- a/src/drivers/redis_scripts.ts +++ b/src/drivers/redis_scripts.ts @@ -4,10 +4,14 @@ import { REDIS_DEDUP_LUA, REDIS_JOB_STORAGE_LUA } from './redis_job_storage.js' * Publishes the wake signal of a script, given as its last two ARGV: the * channel and the message. Publishing from the script keeps one round trip * and sends the signal with the write it announces. + * + * The signal is a hint: pcall keeps a refused PUBLISH, such as for an ACL + * user without channel permissions (the Redis 7 default), from failing a + * script whose writes Redis does not roll back. Workers then poll. */ const PUBLISH_WAKE_LUA = ` local function publish_wake() - redis.call('PUBLISH', ARGV[#ARGV - 1], ARGV[#ARGV]) + redis.pcall('PUBLISH', ARGV[#ARGV - 1], ARGV[#ARGV]) end ` @@ -161,7 +165,7 @@ ${REDIS_JOB_STORAGE_LUA} -- Workers only know the next delayed job: announce the one after it. local next_delayed = redis.call('ZRANGE', delayed_key, 0, 0, 'WITHSCORES') if #next_delayed > 0 then - redis.call('PUBLISH', wake_channel, + redis.pcall('PUBLISH', wake_channel, cjson.encode({ queue = queue, at = tonumber(next_delayed[2]) })) end end diff --git a/src/drivers/wake_messages.ts b/src/drivers/wake_messages.ts index 2e11650..835596f 100644 --- a/src/drivers/wake_messages.ts +++ b/src/drivers/wake_messages.ts @@ -4,11 +4,15 @@ import type { WakeListener } from '../contracts/adapter.js' * Message adapters publish on their wake channel. * * - `{ queue, at }`: a job of `queue` becomes due at `at` (epoch ms). + * - `{ queue }`: a job of `queue` is ready now. Without a timestamp, a + * writer whose clock runs ahead cannot delay the subscriber. * - `{ schedules: true }`: schedules changed. A schedule is not tied to a * queue and its next run is not always known by the writer, so subscribers * read the next due schedule from storage. + * - `{ probe }`: sent by a subscriber to check that its connection receives + * notifications. Other subscribers ignore it. */ -export type WakeMessage = { queue: string; at: number } | { schedules: true } +export type WakeMessage = { queue: string; at?: number } | { schedules: true } | { probe: string } export function encodeWakeMessage(message: WakeMessage): string { return JSON.stringify(message) @@ -38,7 +42,7 @@ export async function dispatchWakeMessage( return } - if (typeof message.queue === 'string' && typeof message.at === 'number') { - if (queues.includes(message.queue)) onWake(message.at) + if (typeof message.queue === 'string' && queues.includes(message.queue)) { + onWake(typeof message.at === 'number' ? message.at : Date.now()) } } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 02ca112..788ad3c 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -121,6 +121,73 @@ test.group('Adapter | Redis', (group) => { createAdapter: () => new RedisAdapter(connection), }) + test('dispatches for an ACL user without channel permissions', async ({ assert, cleanup }) => { + // New ACL users get no channel permission by default since Redis 7. + await connection.call( + 'ACL', + 'SETUSER', + 'queue-no-channels', + 'on', + '>pw', + '~*', + '+@all', + 'resetchannels' + ) + const restricted = new Redis({ + host: process.env.REDIS_HOST || 'localhost', + port: Number.parseInt(process.env.REDIS_PORT || '6379', 10), + keyPrefix: KEY_PREFIX, + db: 15, + username: 'queue-no-channels', + password: 'pw', + }) + cleanup(async () => { + restricted.disconnect() + await connection.call('ACL', 'DELUSER', 'queue-no-channels') + }) + const adapter = new RedisAdapter(restricted) + + await adapter.pushOn('default', { id: 'acl-job', name: 'TestJob', payload: {}, attempts: 0 }) + await adapter.pushLaterOn( + 'default', + { id: 'acl-delayed', name: 'TestJob', payload: {}, attempts: 0 }, + 0 + ) + const acquired = await adapter.popFrom('default') + assert.equal(acquired?.id, 'acl-job') + assert.isTrue(await adapter.retryJob(acquired!, 'default')) + + // The worker cannot subscribe: it polls instead. + await assert.rejects(() => adapter.subscribe(['default'], () => {}), /NOPERM/) + }) + + test('does not wake subscribers of another database', async ({ assert, cleanup }) => { + const other = new Redis({ + host: process.env.REDIS_HOST || 'localhost', + port: Number.parseInt(process.env.REDIS_PORT || '6379', 10), + keyPrefix: KEY_PREFIX, + db: 14, + }) + cleanup(async () => { + await other.quit() + }) + const wakes: number[] = [] + const unsubscribe = await new RedisAdapter(connection).subscribe(['default'], (at) => + wakes.push(at) + ) + cleanup(unsubscribe) + wakes.splice(0) + + await new RedisAdapter(other).pushOn('default', { + id: 'other-db', + name: 'TestJob', + payload: {}, + attempts: 0, + }) + await new Promise((resolve) => setTimeout(resolve, 100)) + assert.deepEqual(wakes, []) + }) + test('listSchedules should use bounded network round-trips as schedule count grows', async ({ assert, }) => { @@ -2408,29 +2475,39 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { /** * Replace the node-postgres client the adapter creates for LISTEN. Each - * fake gets the behavior `behave` returns for its 1-based creation number. + * client gets the behavior `behave` returns for its 1-based creation + * number: 'real' for a working connection, or a fake one. */ function fakeListenClients( cleanup: (callback: () => void) => void, - behave: (index: number) => { connect?: () => Promise; query?: () => Promise } + behave: ( + index: number + ) => 'real' | { connect?: () => Promise; query?: () => Promise } ) { - const client = connection.client as KnexTypes.Client & { driver: { Client: unknown } } + type PgClient = new (settings: unknown) => { + end(): Promise + on(event: string, listener: (error?: Error) => void): unknown + emit(event: string, error?: Error): unknown + } + const client = connection.client as KnexTypes.Client & { driver: { Client: PgClient } } const driver = client.driver + const RealClient = driver.Client client.driver = { ...driver } cleanup(() => { client.driver = driver }) const created: Array<{ ended: boolean; emit: (event: string, error?: Error) => void }> = [] - client.driver.Client = class { + const FakeClient = class { #listeners = new Map void>() - #behavior = behave(created.length + 1) + #behavior: { connect?: () => Promise; query?: () => Promise } state = { ended: false, emit: (event: string, error?: Error) => this.#listeners.get(event)?.(error), } - constructor() { + constructor(behavior: { connect?: () => Promise; query?: () => Promise }) { + this.#behavior = behavior created.push(this.state) } on(event: string, listener: (error?: Error) => void) { @@ -2450,9 +2527,37 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { this.state.ended = true } } + client.driver.Client = function (settings: unknown) { + const behavior = behave(created.length + 1) + if (behavior !== 'real') return new FakeClient(behavior) + + const real = new RealClient(settings) + const state = { + ended: false, + emit: (event: string, error?: Error) => real.emit(event, error), + } + created.push(state) + const end = real.end.bind(real) + real.end = () => { + state.ended = true + return end() + } + return real + } as unknown as PgClient return created } + test('rejects a LISTEN connection that receives no notification', async ({ assert, cleanup }) => { + // As behind PgBouncer in transaction mode: LISTEN succeeds, nothing arrives. + fakeListenClients(cleanup, () => ({})) + const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) + + await assert.rejects( + () => subscriber.subscribe!(['default'], () => {}), + /pass \{ notifications: false \} to knex\(\)/ + ) + }).timeout(5000) + test('aborts a first LISTEN connection still in its handshake', async ({ assert, cleanup }) => { const created = fakeListenClients(cleanup, () => ({ connect: () => new Promise(() => {}) })) const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) @@ -2586,9 +2691,9 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { cleanup, }) => { // The second connection never completes its handshake. - const created = fakeListenClients(cleanup, (index) => ({ - connect: index === 1 ? async () => {} : () => new Promise(() => {}), - })) + const created = fakeListenClients(cleanup, (index) => + index === 1 ? 'real' : { connect: () => new Promise(() => {}) } + ) const subscriber = new KnexAdapter({ connection, @@ -2604,6 +2709,32 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.isTrue(created[1].ended) }) + test('signals jobs of a table whose name is too long for a channel', async ({ + assert, + cleanup, + }) => { + // A schema and a table name of 63 bytes each, the PostgreSQL maximum. + const schema = `tenant_${'x'.repeat(56)}` + const longTableName = `${schema}.queue_jobs_test` + await connection.raw('create schema if not exists ??', [schema]) + cleanup(() => connection.raw('drop schema ?? cascade', [schema])) + await connection.raw('create table ?? (like ?? including all)', [longTableName, tableName]) + const options = { tableName: longTableName, schedulesTableName } + + const wakes: number[] = [] + const subscriber = new KnexAdapter({ connection, ...options }) + const unsubscribe = await subscriber.subscribe!(['default'], (at) => wakes.push(at)) + cleanup(unsubscribe) + wakes.splice(0) + + const job = { id: 'long-table-job', name: 'TestJob', payload: {}, attempts: 0 } + await connection.transaction((trx) => + new KnexAdapter({ connection: trx, ...options }).pushOn('default', job) + ) + while (wakes.length === 0) await new Promise((resolve) => setTimeout(resolve, 10)) + assert.isNotNull(await subscriber.getJob(job.id, 'default')) + }) + test('knex() factory accepts a table name or options', async ({ assert }) => { const job = { id: 'factory-job', name: 'TestJob', payload: {}, attempts: 0 } From 73a699907d6c0f344222921e3f01055000c01079 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 10:40:36 +0000 Subject: [PATCH 03/15] fix(worker): reconnect a subscription that stops answering A subscription connection can stop delivering without closing, behind a stuck proxy or a half-open TCP connection. The worker then ran jobs only at its stalled check, 30 s by default, until it restarted. The subscriber now sends PING on Redis, or SELECT 1 on the LISTEN connection, every 10 s, and reconnects when it gets no answer within 5 s. The reconnection announces due work, as after any reconnection. --- README.md | 3 +- src/drivers/knex_adapter.ts | 15 +++++- src/drivers/redis_adapter.ts | 16 ++++++- src/drivers/wake_messages.ts | 44 ++++++++++++++++++ tests/_utils/silent_proxy.ts | 48 +++++++++++++++++++ tests/adapter.spec.ts | 90 ++++++++++++++++++++++++++++++++++++ 6 files changed, 213 insertions(+), 3 deletions(-) create mode 100644 tests/_utils/silent_proxy.ts diff --git a/README.md b/README.md index d8b6187..a4b52ca 100644 --- a/README.md +++ b/README.md @@ -961,7 +961,8 @@ The process that dispatches a job sends its signal. A job dispatched by an older package, or written to the storage without the Adapter, sends none: the Worker finds it at its next stalled check. Upgrade the processes that dispatch jobs with, or before, the Workers. Each Worker holds one more connection for its subscription: a Redis connection, or a PostgreSQL connection -outside of the Knex pool. +outside of the Knex pool. The Worker pings it every 10 seconds and reconnects when it gets no answer +within 5 seconds. Run one Worker per process. A Worker listens on one Adapter, so to process the queues of several Adapters, start one process per Adapter. Starting a second Worker while another one runs in the diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index cc7b383..1900a4c 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -37,7 +37,12 @@ import { import { KnexQueueSchemaService } from '../services/knex_queue_schema.js' import { scheduleDatesMigrationRequiredMessage } from '../services/schedule_dates.js' import { SCHEDULE_TIMING_COLUMNS } from '../services/schedule_timing.js' -import { dispatchWakeMessage, encodeWakeMessage, type WakeMessage } from './wake_messages.js' +import { + dispatchWakeMessage, + encodeWakeMessage, + startHeartbeat, + type WakeMessage, +} from './wake_messages.js' export { KnexQueueSchemaService } from '../services/knex_queue_schema.js' export type { ScheduleDatesMigrationOptions } from '../services/schedule_dates.js' @@ -298,6 +303,7 @@ export class KnexAdapter implements Adapter { let closed = false let reconnectTimer: NodeJS.Timeout | undefined let reconnectDelay = LISTEN_RECONNECT_DELAY + let listening = false // A client ended in its handshake never settles connect(): closing does. const closing = Promise.withResolvers() closing.promise.catch(() => {}) @@ -342,6 +348,7 @@ export class KnexAdapter implements Adapter { } const onLost = (error?: Error) => { + listening = false if (closed || reconnectTimer) return this.#logger.error({ err: error }, 'Lost the LISTEN connection, reconnecting') void release() @@ -406,14 +413,20 @@ export class KnexAdapter implements Adapter { await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) if (closed) return release() await verify() + listening = true await announce() } + const stopHeartbeat = startHeartbeat( + () => (listening ? client?.query('select 1') : undefined), + () => onLost(new Error('The LISTEN connection did not answer a ping')) + ) signal?.throwIfAborted() this.#scheduleWatchers.add(watcher) const close = async () => { closed = true closing.reject(new Error('The LISTEN subscription is closed')) + stopHeartbeat() clearTimeout(reconnectTimer) signal?.removeEventListener('abort', abort) this.#scheduleWatchers.delete(watcher) diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index d3e9138..bd2c27f 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -12,7 +12,12 @@ import type { WakeListener, } from '../contracts/adapter.js' import { consoleLogger, type Logger } from '../logger.js' -import { dispatchWakeMessage, encodeWakeMessage, type WakeMessage } from './wake_messages.js' +import { + dispatchWakeMessage, + encodeWakeMessage, + startHeartbeat, + type WakeMessage, +} from './wake_messages.js' import type { AdapterFactoryContext, DedupOutcome } from '../types/main.js' import type { JobData, @@ -180,8 +185,17 @@ export class RedisAdapter implements Adapter { signal?.removeEventListener('abort', abort) } + const stopHeartbeat = startHeartbeat( + () => (subscriber.status === 'ready' ? subscriber.ping() : undefined), + () => { + logError(new Error('No answer to PING'), 'Redis wake subscriber is silent, reconnecting') + subscriber.disconnect(true) + } + ) + return async () => { subscribed = false + stopHeartbeat() subscriber.disconnect() } } diff --git a/src/drivers/wake_messages.ts b/src/drivers/wake_messages.ts index 835596f..ac74ed3 100644 --- a/src/drivers/wake_messages.ts +++ b/src/drivers/wake_messages.ts @@ -46,3 +46,47 @@ export async function dispatchWakeMessage( onWake(typeof message.at === 'number' ? message.at : Date.now()) } } + +/** + * How often a subscription connection is pinged, and how long it has to + * answer. Tests shorten them. + */ +export const subscriptionHeartbeat = { interval: 10_000, timeout: 5_000 } + +/** + * Ping a subscription connection on an interval. A connection can stop + * delivering without closing, behind a stuck proxy or a half-open TCP + * connection: `onSilent` is called when a ping gets no answer in time, to + * reconnect. `ping` returns undefined to skip a beat, while reconnecting. + * + * Returns a function that stops the heartbeat. + */ +export function startHeartbeat( + ping: () => Promise | undefined, + onSilent: () => void +): () => void { + let timeout: NodeJS.Timeout | undefined + + const interval = setInterval(() => { + if (timeout) return + const answer = ping() + if (!answer) return + + const timer = setTimeout(() => { + timeout = undefined + onSilent() + }, subscriptionHeartbeat.timeout) + timeout = timer + const answered = () => { + clearTimeout(timer) + if (timeout === timer) timeout = undefined + } + answer.then(answered, answered) + }, subscriptionHeartbeat.interval) + interval.unref() + + return () => { + clearInterval(interval) + clearTimeout(timeout) + } +} diff --git a/tests/_utils/silent_proxy.ts b/tests/_utils/silent_proxy.ts new file mode 100644 index 0000000..2d5de1e --- /dev/null +++ b/tests/_utils/silent_proxy.ts @@ -0,0 +1,48 @@ +import { createServer, connect, type Socket } from 'node:net' + +/** + * TCP proxy to a server. `silence()` stops forwarding on open connections + * without closing them, as a stuck network path would: all of them, or the + * one from the client port `clientPort`. Later connections are forwarded. + */ +export async function startSilentProxy(target: { host: string; port: number }) { + const connections = new Map() + + const server = createServer((client) => { + const upstream = connect(target) + const entry = { client, upstream, silent: false } + const clientPort = client.remotePort! + connections.set(clientPort, entry) + + for (const [from, to] of [ + [client, upstream], + [upstream, client], + ]) { + from.on('data', (chunk) => { + if (!entry.silent) to.write(chunk) + }) + from.on('error', () => to.destroy()) + from.on('close', () => { + connections.delete(clientPort) + to.destroy() + }) + } + }) + await new Promise((resolve) => server.listen(0, '127.0.0.1', resolve)) + + return { + port: (server.address() as { port: number }).port, + silence(clientPort?: number) { + for (const [port, entry] of connections) { + if (clientPort === undefined || port === clientPort) entry.silent = true + } + }, + async close() { + for (const { client, upstream } of connections.values()) { + client.destroy() + upstream.destroy() + } + await new Promise((resolve) => server.close(resolve)) + }, + } +} diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 788ad3c..8706623 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -18,6 +18,8 @@ import { withKnexQuerySpy } from './_utils/with_knex_query_spy.js' import { pauseKnexDeletes } from './_utils/pause_deletes.js' import { registerRetentionRaceSuite } from './_utils/register_retention_race_suite.js' import { MemoryLogger } from './_mocks/memory_logger.js' +import { startSilentProxy } from './_utils/silent_proxy.js' +import { subscriptionHeartbeat } from '../src/drivers/wake_messages.js' import { pgDeleteFailureSql, registerPruneFailureSuite, @@ -188,6 +190,36 @@ test.group('Adapter | Redis', (group) => { assert.deepEqual(wakes, []) }) + test('reconnects a subscription that stops answering', async ({ cleanup }) => { + shortenHeartbeat(cleanup) + const target = { + host: process.env.REDIS_HOST || 'localhost', + port: Number.parseInt(process.env.REDIS_PORT || '6379', 10), + } + const proxy = await startSilentProxy(target) + cleanup(() => proxy.close()) + // Only the subscriber connection goes through the proxy. + const direct = new Redis({ ...target, keyPrefix: KEY_PREFIX, db: 15 }) + direct.duplicate = () => + new Redis({ host: '127.0.0.1', port: proxy.port, keyPrefix: KEY_PREFIX, db: 15 }) + cleanup(() => direct.disconnect()) + + const wakes: number[] = [] + const subscriber = new RedisAdapter(direct, false, new MemoryLogger()) + const unsubscribe = await subscriber.subscribe(['default'], (at) => wakes.push(at)) + cleanup(unsubscribe) + proxy.silence() + wakes.splice(0) + + await new RedisAdapter(connection).pushOn('default', { + id: 'after-silence', + name: 'TestJob', + payload: {}, + attempts: 0, + }) + await waitFor(() => wakes.length > 0) + }) + test('listSchedules should use bounded network round-trips as schedule count grows', async ({ assert, }) => { @@ -2196,6 +2228,21 @@ test.group('Adapter | Redis', (group) => { * A jobs table as the previous versions left it: no unique index, and expired * owners that still hold their dedup id. */ +/** Ping subscription connections every 50 ms, with 100 ms to answer. */ +function shortenHeartbeat(cleanup: (callback: () => void) => void) { + const defaults = { ...subscriptionHeartbeat } + Object.assign(subscriptionHeartbeat, { interval: 50, timeout: 100 }) + cleanup(() => Object.assign(subscriptionHeartbeat, defaults)) +} + +async function waitFor(condition: () => boolean, timeout = 2000) { + const start = Date.now() + while (!condition()) { + if (Date.now() - start > timeout) throw new Error('Condition not met in time') + await new Promise((resolve) => setTimeout(resolve, 10)) + } +} + async function assertDedupMigration( assert: Assert, connection: ReturnType, @@ -2735,6 +2782,49 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.isNotNull(await subscriber.getJob(job.id, 'default')) }) + test('reconnects a LISTEN connection that stops answering', async ({ cleanup }) => { + shortenHeartbeat(cleanup) + const proxy = await startSilentProxy({ + host: process.env.PG_HOST || 'localhost', + port: Number.parseInt(process.env.PG_PORT || '5432', 10), + }) + cleanup(() => proxy.close()) + // The LISTEN connection goes through the proxy. + const knexClient = connection.client as KnexTypes.Client & { + connectionConfigProvider?: () => Promise + } + knexClient.connectionConfigProvider = async () => ({ + host: '127.0.0.1', + port: proxy.port, + user: process.env.PG_USER || 'postgres', + password: process.env.PG_PASSWORD || 'postgres', + database: process.env.PG_DATABASE || 'queue_test', + }) + cleanup(() => { + knexClient.connectionConfigProvider = undefined + }) + + const wakes: number[] = [] + const subscriber = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + logger: new MemoryLogger(), + }) + const unsubscribe = await subscriber.subscribe!(['default'], (at) => wakes.push(at)) + cleanup(unsubscribe) + proxy.silence() + wakes.splice(0) + + await new KnexAdapter({ connection, tableName, schedulesTableName }).pushOn('default', { + id: 'after-silence', + name: 'TestJob', + payload: {}, + attempts: 0, + }) + await waitFor(() => wakes.length > 0) + }) + test('knex() factory accepts a table name or options', async ({ assert }) => { const job = { id: 'factory-job', name: 'TestJob', payload: {}, attempts: 0 } From 0adea5ef39531f7edbe8c7d05cfa8ec5370f3e0e Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 13:48:10 +0000 Subject: [PATCH 04/15] feat(worker): wake one Redis worker per job and bound PostgreSQL wakes A load test showed the wake signals did not scale. Every push woke every idle worker, and each ran a full cycle: on PostgreSQL with 100 workers at 1000 jobs/s, throughput fell from 635 to 234 jobs/s. Every NOTIFY also reached every LISTEN connection, an idle PostgreSQL worker held 3 connections instead of 1, and every schedule claim made every worker read the next schedule. Adapters now implement watch(), which returns a watcher the worker waits on, instead of subscribe(), which pushed signals to it. Redis waits on markers with BZPOPMIN, as BullMQ does. A push adds a marker to its queue; BZPOPMIN hands it to one waiting worker, and a worker that pops a job adds it again while jobs remain. Delayed jobs and schedules keep their next due time in a marker that one worker holds, and puts back when it stops waiting first. Markers outlive a reconnection, so the pub/sub channel and its announcements are gone. PostgreSQL keeps LISTEN/NOTIFY, which wakes every worker, and bounds what it costs: - A worker woken for nothing waits idleDelay before it wakes again, so idle workers query no more often than when polling. - Outside of a transaction, a queue gets at most one NOTIFY per 50 ms per adapter. - Schedule changes carry the next run, read once by the writer. - The LISTEN connection reads what it announces, and the probe uses a short-lived connection, so the pool does not grow. --- README.md | 33 +- src/contracts/adapter.ts | 59 ++-- src/drivers/knex_adapter.ts | 208 ++++++++----- src/drivers/redis_adapter.ts | 187 ++++------- src/drivers/redis_scripts.ts | 170 +++++++--- src/drivers/redis_work_watcher.ts | 201 ++++++++++++ src/drivers/wake_messages.ts | 48 +-- src/{ => drivers}/worker_wakeup.ts | 24 +- src/worker_session.ts | 84 ++--- tests/_utils/register_wake_signal_suite.ts | 285 ----------------- tests/_utils/register_work_watcher_suite.ts | 261 ++++++++++++++++ tests/adapter.spec.ts | 328 +++++++++++++------- tests/worker_session.spec.ts | 113 ++++--- 13 files changed, 1200 insertions(+), 801 deletions(-) create mode 100644 src/drivers/redis_work_watcher.ts rename src/{ => drivers}/worker_wakeup.ts (76%) delete mode 100644 tests/_utils/register_wake_signal_suite.ts create mode 100644 tests/_utils/register_work_watcher_suite.ts diff --git a/README.md b/README.md index a4b52ca..e634ce2 100644 --- a/README.md +++ b/README.md @@ -939,7 +939,7 @@ const config = { worker: { adapter: 'redis', // Registered Adapter listened to by this Worker concurrency: 5, // Parallel jobs - idleDelay: '2s', // Poll interval when idle (adapters without wake signals) + idleDelay: '2s', // Poll interval when idle. PostgreSQL: wait after a wake that found nothing timeout: '1m', // Default job timeout stalledThreshold: '30s', // When to consider job stalled stalledInterval: '30s', // How often to check @@ -950,19 +950,26 @@ const config = { } ``` -On Redis and PostgreSQL (Knex), an idle Worker does not poll: the Adapter signals new jobs through -Redis pub/sub or `LISTEN`/`NOTIFY`, and the Worker also wakes when a delayed job, a retry, or a -schedule becomes due. A job dispatched in a PostgreSQL transaction is signaled when it commits. A -signal can be lost, so the Worker still checks its queues every `stalledInterval`. Behind a pooler -that does not support `LISTEN`, such as PgBouncer in transaction mode, pass `notifications: false` -to `knex()`. MySQL, SQLite, and Kysely poll every `idleDelay`. - -The process that dispatches a job sends its signal. A job dispatched by an older version of the -package, or written to the storage without the Adapter, sends none: the Worker finds it at its next +On Redis and PostgreSQL (Knex), an idle Worker does not poll: it waits until a job is dispatched, or +a delayed job, a retry, or a schedule becomes due. The Worker still checks its queues every +`stalledInterval`, in case a wake was lost. + +- Redis: Workers wait on a marker with `BZPOPMIN`, as in BullMQ. A dispatched job wakes one idle + Worker, which wakes the next one while jobs remain. +- PostgreSQL: Workers `LISTEN` for a `NOTIFY` that wakes all of them. A Worker woken for a job + another Worker took waits `idleDelay` before it looks again, so idle Workers never query more + often than when polling. A job dispatched in a transaction wakes Workers when it commits. Behind + a pooler that does not support `LISTEN`, such as PgBouncer in transaction mode, pass + `notifications: false` to `knex()`. +- MySQL, SQLite, and Kysely poll every `idleDelay`. + +The process that dispatches a job wakes the Workers. A job dispatched by an older version of the +package, or written to the storage without the Adapter, wakes none: the Worker finds it at its next stalled check. Upgrade the processes that dispatch jobs with, or before, the Workers. Each Worker -holds one more connection for its subscription: a Redis connection, or a PostgreSQL connection -outside of the Knex pool. The Worker pings it every 10 seconds and reconnects when it gets no answer -within 5 seconds. +holds one more connection to wait for work, checked every 10 seconds. + +Prefer fewer Workers with a higher `concurrency` to many Workers with a `concurrency` of 1: each +Worker holds connections, and on PostgreSQL every `NOTIFY` reaches every Worker. Run one Worker per process. A Worker listens on one Adapter, so to process the queues of several Adapters, start one process per Adapter. Starting a second Worker while another one runs in the diff --git a/src/contracts/adapter.ts b/src/contracts/adapter.ts index 0936343..4f12e75 100644 --- a/src/contracts/adapter.ts +++ b/src/contracts/adapter.ts @@ -56,15 +56,33 @@ export interface StalledJobsRecovery { } /** - * Receives the time (epoch ms) at which work may become due: now for a job - * ready to run, later for a delayed job, a retry, or a schedule. + * Lets an idle worker wait for work instead of polling. See `Adapter.watch`. + * + * ``` + * cycle: reset() ─► stalled check, schedules, pop ─► wait() ─► cycle + * ``` */ -export type WakeListener = (at: number) => void +export interface WorkWatcher { + /** + * Called before the worker looks for work: work signaled until then is + * covered by that look. + */ + reset(): void -/** - * Ends a subscription opened by `Adapter.subscribe`. - */ -export type Unsubscribe = () => Promise + /** + * Resolve true when work may be due on the watched queues or schedules, + * false after `maxDelay` or when `signal` aborts. + * + * `cooldown` is non-zero when the previous wake found no work, as when + * another worker took the job first. An adapter that wakes every worker for + * the same work must not wake this one again before it elapses: idle workers + * then look for work at most once per `cooldown`, as when polling. + */ + wait(maxDelay: number, signal: AbortSignal, cooldown: number): Promise + + /** Releases what the watcher opened. */ + close(): Promise +} /** * Adapter interface for queue storage backends. @@ -112,28 +130,19 @@ export interface Adapter { popFrom(queue: string): Promise /** - * Optional. Notify a worker when work may become due on `queues`, so it can - * sleep instead of polling. Without it, the worker polls every `idleDelay`. - * - * Signals are hints. A signal may be lost (reconnection, a broker without - * delivery guarantees), so the worker still polls once per stalled interval. - * To make up for signals sent before subscribing or while disconnected, the - * adapter calls `onWake` with now and with the next known due times once - * subscribed and after each reconnection. + * Optional. Lets an idle worker wait until work may be due on `queues` or + * the schedules, instead of polling. Without it, the worker polls every + * `idleDelay`. * - * The worker polls until `subscribe` resolves, and aborts `signal` when it - * stops first: the adapter then releases what it opened and rejects. + * A wake is a hint and may be lost, so the worker still polls once per + * stalled interval. The worker polls until `watch` resolves, and aborts + * `signal` when it stops first: the adapter then releases what it opened + * and rejects. * * @param queues - The queues the worker processes - * @param onWake - Called with the time at which work may become due - * @param signal - Aborted when the worker stops before the subscription is ready - * @returns Ends the subscription + * @param signal - Aborted when the worker stops before the watcher is ready */ - subscribe?( - queues: readonly string[], - onWake: WakeListener, - signal?: AbortSignal - ): Promise + watch?(queues: readonly string[], signal?: AbortSignal): Promise /** * Recover stalled jobs that have been active for too long. diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 1900a4c..904e1db 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -1,4 +1,5 @@ import { createHash, randomUUID } from 'node:crypto' +import { setTimeout as sleep } from 'node:timers/promises' import KnexPkg from 'knex' import type { Knex } from 'knex' import type { @@ -7,8 +8,7 @@ import type { JobLease, PushResult, StalledJobsRecovery, - Unsubscribe, - WakeListener, + WorkWatcher, } from '../contracts/adapter.js' import type { AdapterFactoryContext, @@ -41,8 +41,10 @@ import { dispatchWakeMessage, encodeWakeMessage, startHeartbeat, + type WakeListener, type WakeMessage, } from './wake_messages.js' +import { WorkerWakeup } from './worker_wakeup.js' export { KnexQueueSchemaService } from '../services/knex_queue_schema.js' export type { ScheduleDatesMigrationOptions } from '../services/schedule_dates.js' @@ -69,7 +71,7 @@ export interface KnexAdapterOptions { interface PgListenClient { connect(): Promise end(): Promise - query(sql: string): Promise + query(sql: string, values?: unknown[]): Promise<{ rows: DbRow[] }> on( event: 'notification', listener: (message: { channel: string; payload?: string }) => void @@ -90,15 +92,27 @@ function wakeChannelName(table: string): string { const LISTEN_RECONNECT_DELAY = 1000 const LISTEN_PROBE_TIMEOUT = 2000 const LISTEN_MAX_RECONNECT_DELAY = 30_000 +/** + * Every NOTIFY reaches every LISTEN connection of the database: outside of + * transactions, a queue gets at most one signal per interval per adapter. + */ +const SIGNAL_INTERVAL = 50 /** - * A subscriber and the next schedule run it was told about. + * A watcher and the next schedule run it was told about. */ interface ScheduleWatcher { onWake: WakeListener at: number | null } +/** Signals of a queue that wait for the next interval. */ +interface QueueSignal { + ready: boolean + at: number | null + sent: Promise +} + /** * A Knex instance, or the config to create one. */ @@ -174,19 +188,15 @@ export class KnexAdapter implements Adapter { readonly #logger: Logger /** Set on PostgreSQL with notifications enabled: the jobs table names the channel. */ readonly #wakeChannel?: string - /** Queues with a NOTIFY of ready jobs in flight: see #pushReady. */ - readonly #readySignals = new Map }>() - /** Subscribers of this adapter: see claimDueSchedule. */ + /** Queues with a signal in flight: see #signal. */ + readonly #signals = new Map() + /** Watchers of this adapter: see claimDueSchedule. */ readonly #scheduleWatchers = new Set() #workerId: string = '' #scheduleDatesCheck: Promise | undefined - /** Defined on PostgreSQL with notifications enabled. See `Adapter.subscribe`. */ - readonly subscribe?: ( - queues: readonly string[], - onWake: WakeListener, - signal?: AbortSignal - ) => Promise + /** Defined on PostgreSQL with notifications enabled. See `Adapter.watch`. */ + readonly watch?: (queues: readonly string[], signal?: AbortSignal) => Promise constructor(config: KnexAdapterOptions) { this.#connection = config.connection @@ -197,7 +207,15 @@ export class KnexAdapter implements Adapter { if (this.#connection.client.dialect === 'postgresql' && config.notifications !== false) { this.#wakeChannel = wakeChannelName(this.#jobsTable) - this.subscribe = (queues, onWake, signal) => this.#listen(queues, onWake, signal) + this.watch = async (queues, signal) => { + const wakeup = new WorkerWakeup() + const close = await this.#listen(queues, (at) => wakeup.notify(at), signal) + return { + reset: () => wakeup.reset(), + wait: (maxDelay, abort, cooldown) => wakeup.wait(maxDelay, abort, cooldown), + close, + } + } } } @@ -228,54 +246,58 @@ export class KnexAdapter implements Adapter { } /** - * Insert a job ready now and signal it. + * Signal work of `queue`: ready now, or due at `at`. * - * PostgreSQL serializes the commits that NOTIFY, so a NOTIFY per push - * would halve the throughput of concurrent dispatches. Outside of a - * transaction, the push returns once the job is stored and a queue has - * at most one NOTIFY in flight per adapter: a push that commits meanwhile - * asks for one more, sent once it completes, so after that commit. - * `destroy()` waits for them. + * In a transaction, the NOTIFY joins it. Otherwise, the work is stored and + * the signal is sent in the background: PostgreSQL serializes the commits + * that NOTIFY, and delivers each NOTIFY to every LISTEN connection. A queue + * gets at most one signal per SIGNAL_INTERVAL per adapter; the signals + * asked for meanwhile join the next one, with the earliest due time. That + * is enough: promoting a delayed job announces the next one. `destroy()` + * waits for them. */ - async #pushReady(queue: string, row: Record): Promise { - if (!this.#wakeChannel || this.#connection.isTransaction) { - return this.#insertJob(row, { queue }) + async #signal(queue: string, at?: number): Promise { + if (!this.#wakeChannel) return + if (this.#connection.isTransaction) { + return this.#notify(this.#connection, at === undefined ? { queue } : { queue, at }) } - await this.#connection(this.#jobsTable).insert(row) - this.#signalReady(queue) - } - - /** Signal a ready job of `queue` that is already committed. */ - #signalReady(queue: string): void { - const inFlight = this.#readySignals.get(queue) - if (inFlight) { - inFlight.pending = true - return + const pending = this.#signals.get(queue) + const state = pending ?? { ready: false, at: null, sent: Promise.resolve() } + if (at === undefined || at <= Date.now()) { + state.ready = true + } else { + state.at = Math.min(state.at ?? Infinity, at) } + if (pending) return - const state = { pending: true, sent: Promise.resolve() } - this.#readySignals.set(queue, state) + this.#signals.set(queue, state) state.sent = (async () => { - while (state.pending) { - state.pending = false - await this.#notify(this.#connection, { queue }) + while (state.ready || state.at !== null) { + const { ready, at: dueAt } = state + state.ready = false + state.at = null + if (ready) await this.#notify(this.#connection, { queue }) + if (dueAt !== null) await this.#notify(this.#connection, { queue, at: dueAt }) + await sleep(SIGNAL_INTERVAL) } - this.#readySignals.delete(queue) + this.#signals.delete(queue) })() } /** - * Insert a job row and NOTIFY the workers in one statement, so the signal - * costs no round trip to dispatch. + * Insert a job row and signal it. In a transaction, the insert and the + * NOTIFY run in one statement, so the signal costs no round trip. */ - async #insertJob(row: Record, message: WakeMessage): Promise { + async #insertJob(row: Record, queue: string, at?: number): Promise { const insert = this.#connection(this.#jobsTable).insert(row) - if (!this.#wakeChannel) { + if (!this.#wakeChannel || !this.#connection.isTransaction) { await insert + await this.#signal(queue, at) return } + const message: WakeMessage = at === undefined ? { queue } : { queue, at } await this.#connection.raw('with inserted as (?) select pg_notify(?, ?)', [ insert, this.#wakeChannel, @@ -283,6 +305,13 @@ export class KnexAdapter implements Adapter { ]) } + /** Tell watchers the next schedule run, read in the same transaction. */ + async #notifySchedules(connection: Knex): Promise { + if (!this.#wakeChannel) return + const at = await this.#nextScheduleAt(connection) + if (at !== null) await this.#notify(connection, { schedule: at }) + } + /** * LISTEN on a connection outside of the pool, held for the whole * subscription. A lost connection is replaced with a growing delay. @@ -295,7 +324,7 @@ export class KnexAdapter implements Adapter { queues: readonly string[], onWake: WakeListener, signal?: AbortSignal - ): Promise { + ): Promise<() => Promise> { const channel = this.#wakeChannel! const knexClient = this.#connection.client const watcher: ScheduleWatcher = { onWake, at: null } @@ -332,19 +361,28 @@ export class KnexAdapter implements Adapter { return new knexClient.driver.Client(providedSettings) } - // Signals sent before listening, or while disconnected, are lost. - const announce = async () => { + // Signals sent before listening, or while disconnected, are lost. The + // LISTEN connection reads them: the pool keeps a connection it adds. + const announce = async (connection: PgListenClient) => { + const read = async (query: Knex.QueryBuilder) => { + const { sql, bindings } = query.toSQL().toNative() + return (await connection.query(sql, [...bindings])).rows + } onWake(Date.now()) // One per queue: promoting a job only announces the next one of its queue. - const rows: Array<{ at: number | string | null }> = await this.#connection(this.#jobsTable) - .whereIn('queue', [...queues]) - .where('status', 'delayed') - .groupBy('queue') - .min('execute_at as at') + const rows = await read( + this.#connection(this.#jobsTable) + .whereIn('queue', [...queues]) + .where('status', 'delayed') + .groupBy('queue') + .min('execute_at as at') + ) for (const row of rows) { if (row.at !== null) onWake(Number(row.at)) } - await this.#announceNextSchedule(watcher) + const [next] = await read(this.#nextScheduleQuery(this.#connection)) + watcher.at = next?.at === null || next?.at === undefined ? null : Number(next.at) + if (watcher.at !== null) onWake(watcher.at) } const onLost = (error?: Error) => { @@ -366,7 +404,8 @@ export class KnexAdapter implements Adapter { } // A pooler in transaction mode, such as PgBouncer, accepts LISTEN but - // never delivers: check that a NOTIFY sent through the pool arrives. + // never delivers: check that a NOTIFY sent by another connection, outside + // of the pool, arrives. let probe: { payload: string; received: PromiseWithResolvers } | undefined const verify = async () => { probe = { @@ -387,12 +426,15 @@ export class KnexAdapter implements Adapter { LISTEN_PROBE_TIMEOUT ) }) + const sender = await createClient() try { - await this.#connection.raw('select pg_notify(?, ?)', [channel, probe.payload]) + await Promise.race([sender.connect(), closing.promise]) + await sender.query('select pg_notify($1, $2)', [channel, probe.payload]) await Promise.race([received.promise, timeout, closing.promise]) } finally { clearTimeout(timer) probe = undefined + void sender.end().catch(() => {}) } } @@ -404,17 +446,17 @@ export class KnexAdapter implements Adapter { connection.on('notification', (message) => { if (message.channel !== channel || !message.payload) return if (message.payload === probe?.payload) return probe.received.resolve() - dispatchWakeMessage(message.payload, queues, onWake, async () => { - watcher.at = await this.#nextScheduleAt() - return watcher.at - }).catch((error) => this.#logger.error({ err: error }, 'Failed to handle a wake signal')) + dispatchWakeMessage(message.payload, queues, onWake, (at) => { + watcher.at = at + onWake(at) + }) }) await Promise.race([connection.connect(), closing.promise]) await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) if (closed) return release() await verify() listening = true - await announce() + await announce(connection) } const stopHeartbeat = startHeartbeat( () => (listening ? client?.query('select 1') : undefined), @@ -459,8 +501,13 @@ export class KnexAdapter implements Adapter { * Next run of a schedule that claimDueSchedule can claim: a schedule past * its run limit or end date stays active but never runs again. */ - async #nextScheduleAt(): Promise { - const row = await this.#connection(this.#schedulesTable) + async #nextScheduleAt(connection: Knex = this.#connection): Promise { + const row = await this.#nextScheduleQuery(connection) + return row?.at === null || row?.at === undefined ? null : Number(row.at) + } + + #nextScheduleQuery(connection: Knex) { + return connection(this.#schedulesTable) .where('status', 'active') .whereNotNull('next_run_at') .where((builder) => { @@ -477,7 +524,6 @@ export class KnexAdapter implements Adapter { }) .min('next_run_at as at') .first() - return row?.at === null || row?.at === undefined ? null : Number(row.at) } setWorkerId(workerId: string): void { @@ -485,7 +531,7 @@ export class KnexAdapter implements Adapter { } async destroy(): Promise { - await Promise.all([...this.#readySignals.values()].map((state) => state.sent)) + await Promise.all([...this.#signals.values()].map((state) => state.sent)) if (this.#ownsConnection) { await this.#connection.destroy() } @@ -896,7 +942,7 @@ export class KnexAdapter implements Adapter { score: null, execute_at: retryAt.getTime(), }) - if (updated > 0) await this.#notify(this.#connection, { queue, at: retryAt.getTime() }) + if (updated > 0) await this.#signal(queue, retryAt.getTime()) return updated > 0 } @@ -912,7 +958,7 @@ export class KnexAdapter implements Adapter { score, execute_at: null, }) - if (updated > 0) await this.#notify(this.#connection, { queue }) + if (updated > 0) await this.#signal(queue) return updated > 0 } @@ -933,21 +979,14 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), score, }) - if (this.#connection.isTransaction) { - await this.#notify(this.#connection, { queue }) - } else if (this.#wakeChannel) { - this.#signalReady(queue) - } + await this.#signal(queue) return result } - await this.#pushReady(queue, { - id: jobData.id, - queue, - status: 'pending', - data: JSON.stringify(jobData), - score, - }) + await this.#insertJob( + { id: jobData.id, queue, status: 'pending', data: JSON.stringify(jobData), score }, + queue + ) } async pushLater(jobData: JobData, delay: number): Promise { @@ -965,7 +1004,7 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), execute_at: executeAt, }) - await this.#notify(this.#connection, { queue, at: executeAt }) + await this.#signal(queue, executeAt) return result } @@ -977,7 +1016,8 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), execute_at: executeAt, }, - { queue, at: executeAt } + queue, + executeAt ) } @@ -1334,7 +1374,7 @@ export class KnexAdapter implements Adapter { ]), ...definition, }) - await this.#notify(this.#connection, { schedules: true }) + await this.#notifySchedules(this.#connection) return id } @@ -1385,7 +1425,7 @@ export class KnexAdapter implements Adapter { if (Object.keys(data).length > 0) { await this.#connection(this.#schedulesTable).where('id', id).update(data) - await this.#notify(this.#connection, { schedules: true }) + await this.#notifySchedules(this.#connection) } } @@ -1393,7 +1433,7 @@ export class KnexAdapter implements Adapter { await this.#assertScheduleDatesMigrated() await this.#connection(this.#schedulesTable).where('id', id).delete() - await this.#notify(this.#connection, { schedules: true }) + await this.#notifySchedules(this.#connection) } async claimDueSchedule(): Promise { @@ -1455,7 +1495,7 @@ export class KnexAdapter implements Adapter { last_run_at: now, run_count: newRunCount, }) - await this.#notify(trx, { schedules: true }) + await this.#notifySchedules(trx) // Return schedule data (before update state for payload) return this.#rowToScheduleData(row) diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index bd2c27f..8a611a8 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -8,16 +8,10 @@ import type { JobLease, PushResult, StalledJobsRecovery, - Unsubscribe, - WakeListener, + WorkWatcher, } from '../contracts/adapter.js' import { consoleLogger, type Logger } from '../logger.js' -import { - dispatchWakeMessage, - encodeWakeMessage, - startHeartbeat, - type WakeMessage, -} from './wake_messages.js' +import { RedisWorkWatcher } from './redis_work_watcher.js' import type { AdapterFactoryContext, DedupOutcome } from '../types/main.js' import type { JobData, @@ -43,6 +37,7 @@ import { REMOVE_JOB_SCRIPT, RENEW_JOBS_SCRIPT, RETRY_JOB_SCRIPT, + SEED_MARKERS_SCRIPT, UPDATE_SCHEDULE_SCRIPT, UPSERT_SCHEDULE_SCRIPT, } from './redis_scripts.js' @@ -53,9 +48,8 @@ const schedulesDueKey = 'schedules::due' // Schedule hashes live one level below the index keys so no schedule id can collide with them. const scheduleDataPrefix = 'schedules::data::' const legacyScheduleDataPrefix = 'schedules::' -// Pub/sub channels belong to no database and ioredis does not prefix them: -// the adapter adds the key prefix and the database itself. -const wakeChannelSuffix = 'jobs::wake' +// Below the due index: a 0.7 schedule hash lives at `schedules::`. +const schedulesMarkerKey = 'schedules::due::marker' /** * An ioredis connection, or the options to create one. @@ -112,97 +106,43 @@ export class RedisAdapter implements Adapter { this.#logger = logger } - get #wakeChannel(): string { - const options = this.#connection.options - return `${options?.keyPrefix ?? ''}${wakeChannelSuffix}::${options?.db ?? 0}` - } - - /** - * The channel and message of a wake signal, passed as the last two ARGV of - * the script that announces it (see PUBLISH_WAKE_LUA). - */ - #wake(message: WakeMessage): [string, string] { - return [this.#wakeChannel, encodeWakeMessage(message)] - } - /** - * Listen on the wake channel through a dedicated connection: a connection - * in subscriber mode cannot run other commands. + * Wait for work with BZPOPMIN on the markers of the queues and schedules, + * through a dedicated connection: a blocking command holds its connection. */ - async subscribe( - queues: readonly string[], - onWake: WakeListener, - signal?: AbortSignal - ): Promise { + async watch(queues: readonly string[], signal?: AbortSignal): Promise { signal?.throwIfAborted() - const subscriber = this.#connection.duplicate() - let subscribed = false - - const logError = (error: unknown, message: string) => { - this.#logger.error({ err: error as Error }, message) - } - - // Signals sent before subscribing, or while disconnected, are lost. - const announce = async () => { - onWake(Date.now()) - for (const queue of queues) { - const [, score] = await this.#connection.zrange( - this.#getKeys(queue).delayed, - '0', - '0', - 'WITHSCORES' - ) - if (score !== undefined) onWake(Number(score)) - } - const nextSchedule = await this.#nextScheduleAt() - if (nextSchedule !== null) onWake(nextSchedule) - } - - subscriber.on('error', (error) => logError(error, 'Redis wake subscriber error')) - subscriber.on('message', (channel: string, raw: string) => { - if (channel !== this.#wakeChannel) return - dispatchWakeMessage(raw, queues, onWake, () => this.#nextScheduleAt()).catch((error) => - logError(error, 'Failed to handle a wake signal') - ) - }) - // ioredis subscribes again on reconnection. - subscriber.on('ready', () => { - if (subscribed) announce().catch((error) => logError(error, 'Failed to announce due work')) + const markers = queues.map((queue) => ({ + key: this.#getKeys(queue).marker, + source: this.#getKeys(queue).delayed, + })) + markers.push({ key: schedulesMarkerKey, source: schedulesDueKey }) + + // A command interrupted by a reconnection fails instead of blocking again. + const blocking = this.#connection.duplicate({ autoResendUnfulfilledCommands: false }) + blocking.on('error', (error) => { + this.#logger.error({ err: error }, 'Redis blocking connection error') }) - - const abort = () => subscriber.disconnect() + const abort = () => blocking.disconnect() signal?.addEventListener('abort', abort, { once: true }) try { - await subscriber.subscribe(this.#wakeChannel) - subscribed = true - await announce() + await blocking.ping() + const seedKeys = queues.flatMap((queue) => { + const keys = this.#getKeys(queue) + return [keys.pending, keys.delayed, keys.marker] + }) + seedKeys.push(schedulesDueKey, schedulesMarkerKey) + await this.#connection.eval(SEED_MARKERS_SCRIPT, seedKeys.length, ...seedKeys) signal?.throwIfAborted() } catch (error) { - subscriber.disconnect() + blocking.disconnect() throw error } finally { signal?.removeEventListener('abort', abort) } - const stopHeartbeat = startHeartbeat( - () => (subscriber.status === 'ready' ? subscriber.ping() : undefined), - () => { - logError(new Error('No answer to PING'), 'Redis wake subscriber is silent, reconnecting') - subscriber.disconnect(true) - } - ) - - return async () => { - subscribed = false - stopHeartbeat() - subscriber.disconnect() - } - } - - async #nextScheduleAt(): Promise { - const [, score] = await this.#connection.zrange(schedulesDueKey, '0', '0', 'WITHSCORES') - return score === undefined ? null : Number(score) + return new RedisWorkWatcher(this.#connection, blocking, markers, this.#logger) } #getKeys(queue: string) { @@ -212,6 +152,7 @@ export class RedisAdapter implements Adapter { delayed: `${redisKey}::${queue}::delayed`, active: `${redisKey}::${queue}::active`, overlay: `${redisKey}::${queue}::metadata`, + marker: `${redisKey}::${queue}::marker`, completed: `${redisKey}::${queue}::completed`, completedIndex: `${redisKey}::${queue}::completed::index`, failed: `${redisKey}::${queue}::failed`, @@ -252,17 +193,16 @@ export class RedisAdapter implements Adapter { const result = await this.#connection.eval( ACQUIRE_JOB_SCRIPT, - 5, + 6, keys.data, keys.pending, keys.active, keys.delayed, keys.overlay, + keys.marker, this.#workerId, now.toString(), - leaseToken, - this.#wakeChannel, - queue + leaseToken ) if (!result) { @@ -369,19 +309,17 @@ export class RedisAdapter implements Adapter { const retried = await this.#connection.eval( RETRY_JOB_SCRIPT, - 5, + 6, keys.data, keys.active, keys.pending, keys.delayed, keys.overlay, + keys.marker, job.id, retryAt ? retryAt.getTime().toString() : '0', now.toString(), - job.leaseToken, - ...this.#wake( - retryAt && retryAt.getTime() > now ? { queue, at: retryAt.getTime() } : { queue } - ) + job.leaseToken ) return retried === 1 } @@ -431,12 +369,13 @@ export class RedisAdapter implements Adapter { const [payloadData, payloadIsUndefined] = encodeRedisJobPayloadOverlay(jobData.payload) const result = (await this.#connection.eval( PUSH_DEDUP_JOB_SCRIPT, - 5, + 6, keys.data, keys.delayed, dedupKey, keys.pending, keys.overlay, + keys.marker, jobData.id, JSON.stringify(jobData), executeAt.toString(), @@ -445,21 +384,21 @@ export class RedisAdapter implements Adapter { jobData.dedup.replace ? '1' : '0', payloadData, payloadIsUndefined, - ...this.#wake({ queue, at: executeAt }) + '1' )) as [string, string] return { outcome: result[0] as DedupOutcome, jobId: result[1] } } await this.#connection.eval( PUSH_DELAYED_JOB_SCRIPT, - 3, + 4, keys.data, keys.delayed, keys.overlay, + keys.marker, jobData.id, JSON.stringify(jobData), - executeAt.toString(), - ...this.#wake({ queue, at: executeAt }) + executeAt.toString() ) } @@ -474,12 +413,13 @@ export class RedisAdapter implements Adapter { const [payloadData, payloadIsUndefined] = encodeRedisJobPayloadOverlay(jobData.payload) const result = (await this.#connection.eval( PUSH_DEDUP_JOB_SCRIPT, - 5, + 6, keys.data, keys.pending, dedupKey, keys.delayed, keys.overlay, + keys.marker, jobData.id, JSON.stringify(jobData), score.toString(), @@ -488,21 +428,21 @@ export class RedisAdapter implements Adapter { jobData.dedup.replace ? '1' : '0', payloadData, payloadIsUndefined, - ...this.#wake({ queue }) + '0' )) as [string, string] return { outcome: result[0] as DedupOutcome, jobId: result[1] } } await this.#connection.eval( PUSH_JOB_SCRIPT, - 3, + 4, keys.data, keys.pending, keys.overlay, + keys.marker, jobData.id, JSON.stringify(jobData), - score.toString(), - ...this.#wake({ queue }) + score.toString() ) } @@ -529,7 +469,7 @@ export class RedisAdapter implements Adapter { multi.zadd(keys.pending, score, job.id) } - multi.publish(...this.#wake({ queue })) + multi.zadd(keys.marker, 0, '0') await multi.exec() } @@ -555,18 +495,18 @@ export class RedisAdapter implements Adapter { const [recovered, ...exceeded] = (await this.#connection.eval( RECOVER_STALLED_JOBS_SCRIPT, - 4, + 5, keys.data, keys.active, keys.pending, keys.overlay, + keys.marker, now.toString(), stalledThreshold.toString(), maxStalledCount.toString(), this.#workerId, maxExceeded.toString(), - leaseTokenPrefix, - ...this.#wake({ queue }) + leaseTokenPrefix )) as [number, ...string[]] return { @@ -623,16 +563,16 @@ export class RedisAdapter implements Adapter { const unfinalizedClaim = (await this.#connection.eval( UPSERT_SCHEDULE_SCRIPT, - 4, + 5, scheduleKey, schedulesIndexKey, schedulesDueKey, `${legacyScheduleDataPrefix}${id}`, + schedulesMarkerKey, id, now.toString(), JSON.stringify(scheduleData), - config.nextRunAt?.getTime().toString() ?? '', - ...this.#wake({ schedules: true }) + config.nextRunAt?.getTime().toString() ?? '' )) as [string, string, string] | null // Finalize it as its worker would have, from the time of the claim. The @@ -729,12 +669,12 @@ export class RedisAdapter implements Adapter { await this.#connection.eval( UPDATE_SCHEDULE_SCRIPT, - 2, + 3, scheduleKey, schedulesDueKey, + schedulesMarkerKey, id, - JSON.stringify(data), - ...this.#wake({ schedules: true }) + JSON.stringify(data) ) } @@ -745,7 +685,6 @@ export class RedisAdapter implements Adapter { .del(scheduleKey) .srem(schedulesIndexKey, id) .zrem(schedulesDueKey, id) - .publish(...this.#wake({ schedules: true })) .exec() } @@ -767,12 +706,12 @@ export class RedisAdapter implements Adapter { while (true) { const result = (await this.#connection.eval( CLAIM_SCHEDULE_SCRIPT, - 2, + 3, schedulesDueKey, scheduleDataPrefix, + schedulesMarkerKey, now.toString(), - claimToken, - ...this.#wake({ schedules: true }) + claimToken )) as ['claimed' | 'unfinalized', string] | null if (!result) { @@ -837,15 +776,15 @@ export class RedisAdapter implements Adapter { await this.#connection.eval( FINALIZE_CRON_SCHEDULE_SCRIPT, - 2, + 3, `${scheduleDataPrefix}${claim.id}`, schedulesDueKey, + schedulesMarkerKey, claim.id, claim.cronExpression, claim.configRevision, claim.claimToken, - nextRunAt.toString(), - ...this.#wake({ schedules: true }) + nextRunAt.toString() ) } diff --git a/src/drivers/redis_scripts.ts b/src/drivers/redis_scripts.ts index aea992f..103218d 100644 --- a/src/drivers/redis_scripts.ts +++ b/src/drivers/redis_scripts.ts @@ -1,17 +1,97 @@ import { REDIS_DEDUP_LUA, REDIS_JOB_STORAGE_LUA } from './redis_job_storage.js' /** - * Publishes the wake signal of a script, given as its last two ARGV: the - * channel and the message. Publishing from the script keeps one round trip - * and sends the signal with the write it announces. + * Markers wake idle workers, as in BullMQ. A marker key is a sorted set that + * workers wait on with BZPOPMIN: each marker wakes one worker only, and a + * marker written while every worker is busy waits for the first idle one. * - * The signal is a hint: pcall keeps a refused PUBLISH, such as for an ACL - * user without channel permissions (the Redis 7 default), from failing a - * script whose writes Redis does not roll back. Workers then poll. + * - Member '0', score 0: a job is ready. Many pushes leave one marker. The + * worker that pops a job writes it again while jobs remain, to wake the + * next worker. + * - Member '1': the earliest known time at which a delayed job or a schedule + * becomes due. A worker holds it until then. + * + * The marker key of a script is its last key. + */ +const MARKER_LUA = ` + local marker_key = KEYS[#KEYS] + + local function mark_ready() + redis.call('ZADD', marker_key, 0, '0') + end + + -- A later time would hide the earlier one. + local function mark_due(at) + local current = redis.call('ZSCORE', marker_key, '1') + if not current or tonumber(current) > at then + redis.call('ZADD', marker_key, at, '1') + end + end + + -- Exactly the first score of a sorted set, once the previous one is handled. + local function mark_first_of(key) + local first = redis.call('ZRANGE', key, 0, 0, 'WITHSCORES') + if #first > 0 then + redis.call('ZADD', marker_key, first[2], '1') + else + redis.call('ZREM', marker_key, '1') + end + end +` + +/** + * Writes the markers of work stored before a worker waits for it, or by an + * older version of this package. KEYS = per queue its pending, delayed and + * marker keys, then the schedules due index and its marker. + */ +export const SEED_MARKERS_SCRIPT = ` + local function seed(source_key, marker_key, ready) + local first = redis.call('ZRANGE', source_key, 0, 0, 'WITHSCORES') + if #first == 0 then + return + end + if ready then + redis.call('ZADD', marker_key, 0, '0') + return + end + local current = redis.call('ZSCORE', marker_key, '1') + if not current or tonumber(current) > tonumber(first[2]) then + redis.call('ZADD', marker_key, first[2], '1') + end + end + + for i = 1, #KEYS - 2, 3 do + seed(KEYS[i], KEYS[i + 2], true) + seed(KEYS[i + 1], KEYS[i + 2], false) + end + seed(KEYS[#KEYS - 1], KEYS[#KEYS], false) +` + +/** + * Marks the first entry of a sorted set due after now, ARGV[1]. KEYS = the + * sorted set (delayed jobs or schedules), its marker. A worker woken by a + * due marker runs it: what is due now is its own work, and the marker of + * the next entry is not lost if its cycle writes none. + */ +export const ADVANCE_MARKER_SCRIPT = ` + local next = redis.call('ZRANGEBYSCORE', KEYS[1], '(' .. ARGV[1], '+inf', 'WITHSCORES', 'LIMIT', 0, 1) + if #next == 0 then + return + end + local current = redis.call('ZSCORE', KEYS[2], '1') + if not current or tonumber(current) > tonumber(next[2]) then + redis.call('ZADD', KEYS[2], next[2], '1') + end +` + +/** + * Puts back a marker a worker popped but does not act on: ARGV = member, + * score. A due time only replaces a later one. */ -const PUBLISH_WAKE_LUA = ` - local function publish_wake() - redis.pcall('PUBLISH', ARGV[#ARGV - 1], ARGV[#ARGV]) +export const RELEASE_MARKER_SCRIPT = ` + local current = redis.call('ZSCORE', KEYS[1], ARGV[1]) + if not current or tonumber(current) > tonumber(ARGV[2]) then + redis.call('ZADD', KEYS[1], ARGV[2], ARGV[1]) end ` @@ -28,12 +108,11 @@ export const PUSH_JOB_SCRIPT = ` local score = tonumber(ARGV[3]) ${REDIS_JOB_STORAGE_LUA} - -${PUBLISH_WAKE_LUA} +${MARKER_LUA} store_job_data(data_key, overlay_key, job_id, job_data) redis.call('ZADD', pending_key, score, job_id) - publish_wake() + mark_ready() return 1 ` @@ -72,13 +151,18 @@ export const PUSH_DEDUP_JOB_SCRIPT = ` local replace = tonumber(ARGV[6]) local payload_data = ARGV[7] local payload_is_undefined = tonumber(ARGV[8]) + local delayed = ARGV[9] == '1' ${REDIS_JOB_STORAGE_LUA} ${REDIS_DEDUP_LUA} -${PUBLISH_WAKE_LUA} +${MARKER_LUA} - -- The job may be skipped: a spurious signal only costs a poll. - publish_wake() + -- The job may be skipped: a spurious marker only costs one worker a look. + if delayed then + mark_due(score) + else + mark_ready() + end local existing_result = resolve_dedup_existing_job( data_key, @@ -117,12 +201,11 @@ export const PUSH_DELAYED_JOB_SCRIPT = ` local execute_at = tonumber(ARGV[3]) ${REDIS_JOB_STORAGE_LUA} - -${PUBLISH_WAKE_LUA} +${MARKER_LUA} store_job_data(data_key, overlay_key, job_id, job_data) redis.call('ZADD', delayed_key, execute_at, job_id) - publish_wake() + mark_due(execute_at) return 1 ` @@ -143,10 +226,9 @@ export const ACQUIRE_JOB_SCRIPT = ` local worker_id = ARGV[1] local now = tonumber(ARGV[2]) local lease_token = ARGV[3] - local wake_channel = ARGV[4] - local queue = ARGV[5] ${REDIS_JOB_STORAGE_LUA} +${MARKER_LUA} -- Process delayed jobs: move ready jobs to pending local ready_job_ids = redis.call('ZRANGEBYSCORE', delayed_key, 0, now) @@ -162,12 +244,7 @@ ${REDIS_JOB_STORAGE_LUA} end end - -- Workers only know the next delayed job: announce the one after it. - local next_delayed = redis.call('ZRANGE', delayed_key, 0, 0, 'WITHSCORES') - if #next_delayed > 0 then - redis.pcall('PUBLISH', wake_channel, - cjson.encode({ queue = queue, at = tonumber(next_delayed[2]) })) - end + mark_first_of(delayed_key) end -- Pop highest priority job (lowest score) @@ -176,6 +253,11 @@ ${REDIS_JOB_STORAGE_LUA} return nil end + -- Wake the next idle worker while jobs remain. + if redis.call('ZCARD', pending_key) > 0 then + mark_ready() + end + local job_id = result[1] local job_data = redis.call('HGET', data_key, job_id) if not job_data then @@ -352,7 +434,7 @@ export const RETRY_JOB_SCRIPT = ` ${REDIS_JOB_STORAGE_LUA} ${REDIS_LEASE_LUA} -${PUBLISH_WAKE_LUA} +${MARKER_LUA} -- Verify the caller still holds the job if not holds_lease(active_key, job_id, lease_token) then @@ -380,15 +462,16 @@ ${PUBLISH_WAKE_LUA} -- Add back to pending or delayed if retry_at and retry_at > now then redis.call('ZADD', delayed_key, retry_at, job_id) + mark_due(retry_at) else -- Score = priority * 1e13 + timestamp -- Lower score = higher priority, FIFO within same priority local priority = job.priority or 5 local score = priority * 10000000000000 + now redis.call('ZADD', pending_key, score, job_id) + mark_ready() end - publish_wake() return 1 ` @@ -414,7 +497,7 @@ export const RECOVER_STALLED_JOBS_SCRIPT = ` local lease_token_prefix = ARGV[6] ${REDIS_JOB_STORAGE_LUA} -${PUBLISH_WAKE_LUA} +${MARKER_LUA} local recovered = 0 -- The first element is replaced by the recovered count before returning. @@ -471,7 +554,7 @@ ${PUBLISH_WAKE_LUA} result[1] = recovered if recovered > 0 then - publish_wake() + mark_ready() end return result ` @@ -630,9 +713,7 @@ export const UPSERT_SCHEDULE_SCRIPT = ` local next_run_at = ARGV[4] ${SCHEDULE_DUE_INDEX_LUA} -${PUBLISH_WAKE_LUA} - - publish_wake() +${MARKER_LUA} -- The same test as migrate(): an indexed id with a 0.7 hash at its old key. if redis.call('SISMEMBER', schedules_index_key, id) == 1 @@ -685,6 +766,7 @@ ${PUBLISH_WAKE_LUA} ) redis.call('SADD', schedules_index_key, id) sync_schedule_due_index(schedule_key, due_key, id) + mark_first_of(due_key) -- A finished schedule never keeps a claim token, so an empty next run with -- one is a cron claim not finalized yet. @@ -711,12 +793,11 @@ export const UPDATE_SCHEDULE_SCRIPT = ` local updates = cjson.decode(ARGV[2]) ${SCHEDULE_DUE_INDEX_LUA} -${PUBLISH_WAKE_LUA} - - publish_wake() +${MARKER_LUA} if redis.call('EXISTS', schedule_key) == 0 then redis.call('ZREM', due_key, id) + mark_first_of(due_key) return 0 end @@ -731,6 +812,7 @@ ${PUBLISH_WAKE_LUA} end sync_schedule_due_index(schedule_key, due_key, id) + mark_first_of(due_key) return 1 ` @@ -749,12 +831,11 @@ export const FINALIZE_CRON_SCHEDULE_SCRIPT = ` local next_run_at = ARGV[5] ${SCHEDULE_DUE_INDEX_LUA} -${PUBLISH_WAKE_LUA} - - publish_wake() +${MARKER_LUA} if redis.call('EXISTS', schedule_key) == 0 then redis.call('ZREM', due_key, id) + mark_first_of(due_key) return 0 end @@ -772,6 +853,7 @@ ${PUBLISH_WAKE_LUA} redis.call('HDEL', schedule_key, 'claim_token', 'claimed_at') end sync_schedule_due_index(schedule_key, due_key, id) + mark_first_of(due_key) return 0 end @@ -788,6 +870,7 @@ ${PUBLISH_WAKE_LUA} redis.call('HSET', schedule_key, 'next_run_at', next_run_at) redis.call('HDEL', schedule_key, 'claim_token', 'claimed_at') sync_schedule_due_index(schedule_key, due_key, id) + mark_first_of(due_key) return 1 ` @@ -901,7 +984,7 @@ ${SCHEDULE_DUE_INDEX_LUA} * KEYS[2] = schedule key prefix (e.g. "schedules::data::") * ARGV[1] = now (epoch milliseconds) * ARGV[2] = claim token, kept by the schedule when it is a cron - * ARGV[3], ARGV[4] = wake channel and message, published when the due index changes + * KEYS[3] = schedules marker, written when the due index changes * * Returns nil, or `{ 'claimed' | 'unfinalized', }`. */ @@ -912,7 +995,7 @@ export const CLAIM_SCHEDULE_SCRIPT = ` local claim_token = ARGV[2] ${SCHEDULE_DUE_INDEX_LUA} -${PUBLISH_WAKE_LUA} +${MARKER_LUA} local skipped = false @@ -920,9 +1003,8 @@ ${PUBLISH_WAKE_LUA} local candidates = redis.call('ZRANGEBYSCORE', due_key, '-inf', tostring(now), 'LIMIT', 0, 1) if #candidates == 0 then - -- Subscribers may wait for a skipped entry: let them read the next one. if skipped then - publish_wake() + mark_first_of(due_key) end return nil end @@ -1011,7 +1093,7 @@ ${PUBLISH_WAKE_LUA} 'claimed_at', new_claimed_at) sync_schedule_due_index(schedule_key, due_key, id) - publish_wake() + mark_first_of(due_key) -- Return the schedule data (before update) as JSON return { 'claimed', cjson.encode(schedule) } diff --git a/src/drivers/redis_work_watcher.ts b/src/drivers/redis_work_watcher.ts new file mode 100644 index 0000000..4ef3dad --- /dev/null +++ b/src/drivers/redis_work_watcher.ts @@ -0,0 +1,201 @@ +import { setTimeout as sleep } from 'node:timers/promises' +import type { Redis } from 'ioredis' +import type { WorkWatcher } from '../contracts/adapter.js' +import type { Logger } from '../logger.js' +import { ADVANCE_MARKER_SCRIPT, RELEASE_MARKER_SCRIPT } from './redis_scripts.js' +import { subscriptionHeartbeat } from './wake_messages.js' + +/** + * A marker key, and the sorted set whose due times it announces: the + * delayed jobs of a queue, or the schedules. + */ +export interface RedisMarker { + key: string + source: string +} + +interface PoppedMarker { + key: string + member: string + score: number +} + +const ERROR_RETRY_DELAY_MS = 1_000 + +/** + * Waits for the markers that writers add for the queues and schedules (see + * MARKER_LUA). BZPOPMIN pops each marker for one waiting worker only, so a + * job wakes one worker, not all of them: `cooldown` does not apply. + * + * A popped due time is held while the worker waits for it, and put back + * when the worker stops waiting first, so that another idle worker gets it. + * A marker popped once the worker stopped waiting is put back as well. + */ +export class RedisWorkWatcher implements WorkWatcher { + readonly #connection: Redis + readonly #blocking: Redis + readonly #markers: readonly RedisMarker[] + readonly #logger: Logger + /** The key prefix of the connection: replies of BZPOPMIN include it. */ + readonly #prefix: string + /** Due times popped by the current wait, by marker key. */ + readonly #held = new Map() + /** The BZPOPMIN in flight. It may outlive the wait that sent it. */ + #reading?: Promise + /** Receives the result of the BZPOPMIN in flight while a wait reads it. */ + #deliver?: (marker: PoppedMarker | null) => void + #closed = false + + constructor(connection: Redis, blocking: Redis, markers: readonly RedisMarker[], logger: Logger) { + this.#connection = connection + this.#blocking = blocking + this.#markers = markers + this.#logger = logger + this.#prefix = blocking.options?.keyPrefix ?? '' + } + + reset(): void {} + + async wait(maxDelay: number, signal: AbortSignal): Promise { + const deadline = Date.now() + maxDelay + + try { + while (!signal.aborted && !this.#closed) { + const now = Date.now() + const [heldKey, heldAt] = this.#nextHeld() + if (heldKey !== undefined && heldAt <= now) { + this.#held.delete(heldKey) + await this.#advance(heldKey, now) + return true + } + if (deadline <= now) return false + + const marker = await this.#read(Math.min(deadline, heldAt), signal) + if (!marker) continue + if (marker.member === '0') return true + if (marker.score <= Date.now()) { + await this.#advance(marker.key, Date.now()) + return true + } + + const held = this.#held.get(marker.key) + if (held === undefined || marker.score < held) this.#held.set(marker.key, marker.score) + } + return false + } finally { + for (const [key, at] of this.#held) void this.#release({ key, member: '1', score: at }) + this.#held.clear() + } + } + + async close(): Promise { + this.#closed = true + this.#deliver?.(null) + this.#blocking.disconnect() + } + + #nextHeld(): [string | undefined, number] { + let next: [string | undefined, number] = [undefined, Infinity] + for (const [key, at] of this.#held) { + if (at < next[1]) next = [key, at] + } + return next + } + + /** + * Resolve with the next popped marker, or null at `until`, on abort, or + * when the BZPOPMIN in flight times out. + */ + #read(until: number, signal: AbortSignal): Promise { + if (!this.#reading) this.#reading = this.#pop(until) + + return new Promise((resolve) => { + const done = (marker: PoppedMarker | null) => { + clearTimeout(timer) + signal.removeEventListener('abort', abort) + if (this.#deliver === done) this.#deliver = undefined + resolve(marker) + } + const abort = () => done(null) + const timer = setTimeout(abort, until - Date.now()) + signal.addEventListener('abort', abort, { once: true }) + this.#deliver = done + }) + } + + async #pop(until: number): Promise { + // A command blocked longer may not survive a reconnection, as in BullMQ. + // It also bounds how long a silent connection goes unnoticed. + const timeout = Math.min(Math.max(until - Date.now(), 10), subscriptionHeartbeat.interval) + let watchdog: NodeJS.Timeout | undefined + let marker: PoppedMarker | null = null + + try { + const command = this.#blocking.bzpopmin( + ...this.#markers.map((marker) => marker.key), + timeout / 1000 + ) + // ioredis may never settle a command on a connection that went silent, + // nor one it dropped on reconnection: past the timeout, give up on it. + command.catch(() => {}) + const stuck = new Promise<'stuck'>((resolve) => { + watchdog = setTimeout(() => resolve('stuck'), timeout + subscriptionHeartbeat.timeout) + }) + const reply = await Promise.race([command, stuck]) + if (reply === 'stuck') { + this.#logger.error( + { err: new Error('BZPOPMIN did not return in time') }, + 'Redis blocking connection is silent, reconnecting' + ) + this.#blocking.disconnect(true) + marker = this.#mayBeLost() + } else if (reply) { + marker = this.#parse(reply) + } + } catch (error) { + if (!this.#closed) { + this.#logger.error({ err: error as Error }, 'Failed to wait for work on Redis') + await sleep(ERROR_RETRY_DELAY_MS) + marker = this.#mayBeLost() + } + } finally { + clearTimeout(watchdog) + this.#reading = undefined + } + + if (this.#deliver) { + this.#deliver(marker) + } else if (marker) { + await this.#release(marker) + } + } + + /** + * Redis may have popped a marker whose reply was lost with the connection: + * look for work rather than wait for the next poll. + */ + #mayBeLost(): PoppedMarker { + return { key: this.#markers[0].key, member: '0', score: 0 } + } + + #parse([prefixedKey, member, score]: [string, string, string]): PoppedMarker | null { + const key = prefixedKey.slice(this.#prefix.length) + if (!this.#markers.some((marker) => marker.key === key)) return null + return { key, member, score: Number(score) } + } + + /** Put back a marker this worker does not act on, for another worker. */ + async #release(marker: PoppedMarker): Promise { + await this.#connection + .eval(RELEASE_MARKER_SCRIPT, 1, marker.key, marker.member, marker.score.toString()) + .catch((error) => this.#logger.error({ err: error }, 'Failed to put back a Redis marker')) + } + + /** Mark the next due time of a marker whose due time this worker runs. */ + async #advance(key: string, now: number): Promise { + const source = this.#markers.find((marker) => marker.key === key)!.source + await this.#connection + .eval(ADVANCE_MARKER_SCRIPT, 2, source, key, now.toString()) + .catch((error) => this.#logger.error({ err: error }, 'Failed to advance a Redis marker')) + } +} diff --git a/src/drivers/wake_messages.ts b/src/drivers/wake_messages.ts index ac74ed3..cca8ca5 100644 --- a/src/drivers/wake_messages.ts +++ b/src/drivers/wake_messages.ts @@ -1,34 +1,37 @@ -import type { WakeListener } from '../contracts/adapter.js' +/** + * Receives the time (epoch ms) at which work may become due: now for a job + * ready to run, later for a delayed job, a retry, or a schedule. + */ +export type WakeListener = (at: number) => void /** - * Message adapters publish on their wake channel. + * Message published on the LISTEN channel of the Knex adapter. * * - `{ queue, at }`: a job of `queue` becomes due at `at` (epoch ms). * - `{ queue }`: a job of `queue` is ready now. Without a timestamp, a - * writer whose clock runs ahead cannot delay the subscriber. - * - `{ schedules: true }`: schedules changed. A schedule is not tied to a - * queue and its next run is not always known by the writer, so subscribers - * read the next due schedule from storage. - * - `{ probe }`: sent by a subscriber to check that its connection receives - * notifications. Other subscribers ignore it. + * writer whose clock runs ahead cannot delay the watcher. + * - `{ schedule }`: the next schedule run after a schedule changed, read by + * the writer so watchers do not each read it. + * - `{ probe }`: sent by a watcher to check that its connection receives + * notifications. Other watchers ignore it. */ -export type WakeMessage = { queue: string; at?: number } | { schedules: true } | { probe: string } +export type WakeMessage = { queue: string; at?: number } | { schedule: number } | { probe: string } export function encodeWakeMessage(message: WakeMessage): string { return JSON.stringify(message) } /** - * Route a raw message of the wake channel to `onWake`. Messages for other - * queues are ignored; schedule changes call `readNextSchedule`. + * Route a raw message of the wake channel: a job of a watched queue to + * `onWake`, the next schedule run to `onSchedule`. Others are ignored. */ -export async function dispatchWakeMessage( +export function dispatchWakeMessage( raw: string, queues: readonly string[], onWake: WakeListener, - readNextSchedule: () => Promise -): Promise { - let message: Partial<{ queue: unknown; at: unknown; schedules: unknown }> + onSchedule: WakeListener +): void { + let message: Partial<{ queue: unknown; at: unknown; schedule: unknown }> try { message = JSON.parse(raw) @@ -36,20 +39,17 @@ export async function dispatchWakeMessage( return } - if (message.schedules === true) { - const at = await readNextSchedule() - if (at !== null) onWake(at) - return - } - - if (typeof message.queue === 'string' && queues.includes(message.queue)) { + if (typeof message.schedule === 'number') { + onSchedule(message.schedule) + } else if (typeof message.queue === 'string' && queues.includes(message.queue)) { onWake(typeof message.at === 'number' ? message.at : Date.now()) } } /** - * How often a subscription connection is pinged, and how long it has to - * answer. Tests shorten them. + * How often a watcher checks its connection, and how long the connection has + * to answer: a PING on the LISTEN connection, or the timeout of BZPOPMIN on + * Redis. Tests shorten them. */ export const subscriptionHeartbeat = { interval: 10_000, timeout: 5_000 } diff --git a/src/worker_wakeup.ts b/src/drivers/worker_wakeup.ts similarity index 76% rename from src/worker_wakeup.ts rename to src/drivers/worker_wakeup.ts index dab81c9..e891dcc 100644 --- a/src/worker_wakeup.ts +++ b/src/drivers/worker_wakeup.ts @@ -42,16 +42,22 @@ export class WorkerWakeup { } /** - * Resolve on a signal for now, when the next timer is due, after - * `maxDelay`, or when `signal` aborts. + * Resolve true on a signal for now or when the next timer is due, false + * after `maxDelay` or when `signal` aborts. Signals and timers wake no + * earlier than `cooldown`. */ - async wait(maxDelay: number, signal: AbortSignal): Promise { - const deadline = Date.now() + maxDelay + async wait(maxDelay: number, signal: AbortSignal, cooldown = 0): Promise { + const start = Date.now() + const deadline = start + maxDelay + const quietUntil = start + cooldown - while (!signal.aborted && !this.#requested) { + while (!signal.aborted) { const now = Date.now() - const until = Math.min(deadline, this.#timers[0] ?? Infinity) - if (until <= now) return + if (deadline <= now) return false + + const due = this.#requested ? now : (this.#timers[0] ?? Infinity) + const wakeAt = Math.max(due, quietUntil) + if (wakeAt <= now) return true await new Promise((resolve) => { const done = () => { @@ -60,11 +66,13 @@ export class WorkerWakeup { this.#interrupt = undefined resolve() } - const timer = setTimeout(done, until - now) + const timer = setTimeout(done, Math.min(deadline, wakeAt) - now) signal.addEventListener('abort', done, { once: true }) this.#interrupt = done }) } + + return false } /** Returns false when `at` was already known or past the bound. */ diff --git a/src/worker_session.ts b/src/worker_session.ts index e71e5bb..f954f59 100644 --- a/src/worker_session.ts +++ b/src/worker_session.ts @@ -5,9 +5,8 @@ import { parse, retryOnDeadlock } from './utils.js' import { JobPool, type PoolEntry } from './job_pool.js' import { WorkerHeartbeat, type HeartbeatOperationWrapper } from './worker_heartbeat.js' import { Locator } from './locator.js' -import { WorkerWakeup } from './worker_wakeup.js' import type { SingleJobDispatchRequest } from './job_dispatch_runtime.js' -import type { Adapter, AcquiredJob, Unsubscribe } from './contracts/adapter.js' +import type { Adapter, AcquiredJob, WorkWatcher } from './contracts/adapter.js' import type { JobExecutionOutcome, JobExecutionRuntime } from './job_runtime.js' import type { Logger, WorkerCycle } from './types/main.js' import { DEFAULT_ERROR_RETRY_DELAY, UNKNOWN_JOB_RETRY_DELAY } from './constants.js' @@ -81,8 +80,10 @@ export class WorkerSession { #completionDelayController?: AbortController #lastStalledCheck = 0 #delayController?: AbortController - /** Set while `start()` holds a subscription: idle waits sleep until a signal. */ - #wakeup?: WorkerWakeup + /** Set while `start()` holds a watcher: idle waits sleep until work may be due. */ + #watcher?: WorkWatcher + /** The last wait ended on a wake: if the next look finds no work, it cools down. */ + #woken = false constructor(options: WorkerSessionOptions) { this.#workerId = options.workerId @@ -125,15 +126,20 @@ export class WorkerSession { const completion = Promise.withResolvers() this.#startCompletion = completion.promise - // Polls until the subscription is ready: a slow handshake delays no job. - const subscribeAbort = new AbortController() - const subscription = this.#subscribe(subscribeAbort.signal) + // Polls until the watcher is ready: a slow handshake delays no job. + const watchAbort = new AbortController() + const watching = this.#watch(watchAbort.signal) try { debug('starting worker %s on queues: %O', this.#workerId, this.#queues) for await (const cycle of generator) { - if (cycle.type === 'started' || cycle.type === 'completed') { + if (cycle.type === 'started') { + this.#woken = false + continue + } + + if (cycle.type === 'completed') { continue } @@ -148,14 +154,14 @@ export class WorkerSession { debug('worker %s is idle, waiting for %dms', this.#workerId, delay) } - await this.#waitBeforeNextCycle(cycle.type === 'idle' && this.#wakeup ? null : delay) + await this.#waitBeforeNextCycle(cycle.type === 'idle' && this.#watcher ? null : delay) } } finally { - this.#wakeup = undefined - subscribeAbort.abort() - const unsubscribe = await subscription - await unsubscribe?.().catch((error) => { - this.#logger.error({ err: error, workerId: this.#workerId }, 'Failed to unsubscribe') + this.#watcher = undefined + watchAbort.abort() + const watcher = await watching + await watcher?.close().catch((error) => { + this.#logger.error({ err: error, workerId: this.#workerId }, 'Failed to stop watching') }) completion.resolve() if (this.#startCompletion === completion.promise) { @@ -284,40 +290,44 @@ export class WorkerSession { } /** - * Subscribe to the wake signals of the adapter, when it supports them. A - * failure is logged and the worker keeps polling. `signal` aborts a - * subscription that is not ready when the session stops. + * Watch for work through the adapter, when it supports it. A failure is + * logged and the worker keeps polling. `signal` aborts a watcher that is + * not ready when the session stops. */ - async #subscribe(signal: AbortSignal): Promise { - if (!this.#adapter.subscribe) return - - const wakeup = new WorkerWakeup() + async #watch(signal: AbortSignal): Promise { + if (!this.#adapter.watch) return try { - const unsubscribe = await this.#adapter.subscribe( - this.#queues, - (at) => wakeup.notify(at), - signal - ) + const watcher = await this.#adapter.watch(this.#queues, signal) if (!signal.aborted) { - this.#wakeup = wakeup - debug('worker %s subscribed to wake signals', this.#workerId) - // The current wait polls: end it, so the next one sleeps until a signal. + this.#watcher = watcher + debug('worker %s watches for work', this.#workerId) + // The current wait polls: end it, so the next one sleeps until work. this.#delayController?.abort() this.#completionDelayController?.abort() } - return unsubscribe + return watcher } catch (error) { if (signal.aborted) return this.#logger.error( { err: error as Error, workerId: this.#workerId }, - 'Failed to subscribe to wake signals, polling instead' + 'Failed to watch for work, polling instead' ) } } /** - * Time left before the next stalled check. A subscribed worker sleeps at + * Sleep until work may be due. After a wake that found no work, the + * watcher cools down for `idleDelay`: idle workers woken together look for + * work at most as often as when polling. + */ + async #waitForWork(watcher: WorkWatcher, signal: AbortSignal): Promise { + const cooldown = this.#woken ? this.#settings.idleDelay : 0 + this.#woken = await watcher.wait(this.#untilStalledCheck(), signal, cooldown) + } + + /** + * Time left before the next stalled check. A watching worker sleeps at * most this long: the check doubles as the poll that catches lost signals. */ #untilStalledCheck(): number { @@ -325,7 +335,7 @@ export class WorkerSession { } /** - * Sleep for `delay`, or until a wake signal when `delay` is null. + * Sleep for `delay`, or until work may be due when `delay` is null. */ async #waitBeforeNextCycle(delay: number | null): Promise { if (!this.#running) return @@ -335,7 +345,7 @@ export class WorkerSession { try { if (delay === null) { - await this.#wakeup?.wait(this.#untilStalledCheck(), controller.signal) + if (this.#watcher) await this.#waitForWork(this.#watcher, controller.signal) } else { await setTimeout(delay, undefined, { signal: controller.signal }) } @@ -356,7 +366,7 @@ export class WorkerSession { try { while (this.#running) { try { - this.#wakeup?.reset() + this.#watcher?.reset() await this.#checkStalledJobs() if (!this.#running) break @@ -427,8 +437,8 @@ export class WorkerSession { this.#completionDelayController = controller try { - if (this.#wakeup) { - await this.#wakeup.wait(this.#untilStalledCheck(), controller.signal) + if (this.#watcher) { + await this.#waitForWork(this.#watcher, controller.signal) } else { await setTimeout(this.#settings.idleDelay, undefined, { signal: controller.signal }) } diff --git a/tests/_utils/register_wake_signal_suite.ts b/tests/_utils/register_wake_signal_suite.ts deleted file mode 100644 index 67fc3dc..0000000 --- a/tests/_utils/register_wake_signal_suite.ts +++ /dev/null @@ -1,285 +0,0 @@ -import { setTimeout } from 'node:timers/promises' -import { test as JapaTest } from '@japa/runner' -import type { Adapter } from '../../src/contracts/adapter.js' - -interface WakeSignalSuiteOptions { - test: typeof JapaTest - /** Creates an adapter that implements `subscribe`. */ - createAdapter: () => Adapter - /** See `inTransaction` of the driver test suite. */ - inTransaction?: (operation: (adapter: Adapter) => Promise) => Promise -} - -const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) - -/** Subscribe and record the signals received after the initial announcement. */ -async function listen(adapter: Adapter, queues = ['default']) { - const wakes: number[] = [] - const unsubscribe = await adapter.subscribe!(queues, (at) => wakes.push(at)) - - return { - wakes, - unsubscribe, - clear: () => wakes.splice(0), - async next(timeout = 2000): Promise { - const start = Date.now() - while (wakes.length === 0) { - if (Date.now() - start > timeout) throw new Error('No wake signal received') - await setTimeout(5) - } - return wakes.shift()! - }, - } -} - -/** - * Wake signals of adapters that implement `subscribe`. The subscriber and the - * writer use separate adapters, as a worker and a dispatcher would. - */ -export function registerWakeSignalSuite({ - test, - createAdapter, - inTransaction, -}: WakeSignalSuiteOptions) { - test('signals a push to the subscribers of its queue only', async ({ assert, cleanup }) => { - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - listener.clear() - const writer = createAdapter() - - await writer.pushOn('other', job('other-queue')) - await setTimeout(100) - assert.deepEqual(listener.wakes, []) - - const before = Date.now() - await writer.pushOn('default', job('default-queue')) - const at = await listener.next() - assert.isAtLeast(at, before) - assert.isAtMost(at, Date.now()) - }) - - test('signals when a delayed job and a retry become due', async ({ assert, cleanup }) => { - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - listener.clear() - const writer = createAdapter() - - const before = Date.now() - await writer.pushLaterOn('default', job('delayed'), 60_000) - const delayedAt = await listener.next() - assert.isAtLeast(delayedAt, before + 60_000) - assert.isAtMost(delayedAt, Date.now() + 60_000) - - await writer.pushOn('default', job('retried')) - await listener.next() - const acquired = await writer.popFrom('default') - const retryAt = new Date(Date.now() + 30_000) - await writer.retryJob(acquired!, 'default', retryAt) - assert.equal(await listener.next(), retryAt.getTime()) - }) - - test('signals the next run of a schedule when it changes or runs', async ({ - assert, - cleanup, - }) => { - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - listener.clear() - const writer = createAdapter() - - const firstRun = Date.now() - 1000 - await writer.upsertSchedule({ - id: 'wake-schedule', - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - nextRunAt: new Date(firstRun), - }) - assert.equal(await listener.next(), firstRun) - - const before = Date.now() - await writer.claimDueSchedule() - const nextRun = await listener.next() - assert.isAtLeast(nextRun, before + 60_000) - assert.isAtMost(nextRun, Date.now() + 60_000) - }) - - test('announces work stored before subscribing', async ({ assert, cleanup }) => { - const writer = createAdapter() - const delayedBefore = Date.now() - await writer.pushLaterOn('default', job('stored-delayed'), 60_000) - const delayedAfter = Date.now() - const scheduleRun = Date.now() + 30_000 - await writer.upsertSchedule({ - id: 'stored-schedule', - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - nextRunAt: new Date(scheduleRun), - }) - - const before = Date.now() - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - const [now, delayedAt, ...rest] = listener.wakes - - assert.isAtLeast(now, before) - assert.isAtLeast(delayedAt, delayedBefore + 60_000) - assert.isAtMost(delayedAt, delayedAfter + 60_000) - assert.deepEqual(rest, [scheduleRun]) - }) - - test('announces the next delayed job once the previous one is promoted', async ({ - assert, - cleanup, - }) => { - const writer = createAdapter() - await writer.pushLaterOn('default', job('first-delayed'), 50) - const before = Date.now() - await writer.pushLaterOn('default', job('second-delayed'), 60_000) - const after = Date.now() - - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - listener.clear() - - await setTimeout(100) - await writer.popFrom('default') - const at = await listener.next() - assert.isAtLeast(at, before + 60_000) - assert.isAtMost(at, after + 60_000) - }) - - test('announces the next delayed job of each queue', async ({ assert, cleanup }) => { - const writer = createAdapter() - await writer.pushLaterOn('first', job('first-queue'), 30_000) - const before = Date.now() - await writer.pushLaterOn('second', job('second-queue'), 60_000) - const after = Date.now() - - const listener = await listen(createAdapter(), ['first', 'second']) - cleanup(listener.unsubscribe) - - assert.isTrue( - listener.wakes.some((at) => at >= before + 60_000 && at <= after + 60_000), - 'the second queue is announced' - ) - }) - - test('announces the next schedule past an expired one', async ({ assert, cleanup }) => { - const writer = createAdapter() - const now = Date.now() - await writer.upsertSchedule({ - id: 'expired', - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - to: new Date(now - 500), - nextRunAt: new Date(now - 1000), - }) - const nextRun = now + 60_000 - await writer.upsertSchedule({ - id: 'next', - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - nextRunAt: new Date(nextRun), - }) - - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - - // A worker woken for the expired schedule claims nothing. - assert.isNull(await writer.claimDueSchedule()) - await setTimeout(100) - assert.include(listener.wakes, nextRun) - }) - - test('announces the next schedule when the announced one expires before running', async ({ - assert, - cleanup, - }) => { - const writer = createAdapter() - const now = Date.now() - await writer.upsertSchedule({ - id: 'expiring', - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - to: new Date(now + 150), - nextRunAt: new Date(now + 100), - }) - const nextRun = now + 60_000 - await writer.upsertSchedule({ - id: 'next', - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - nextRunAt: new Date(nextRun), - }) - - // The worker adapter is told about the expiring schedule only. - const worker = createAdapter() - const listener = await listen(worker) - cleanup(listener.unsubscribe) - assert.include(listener.wakes, now + 100) - listener.clear() - - // It wakes once the schedule has also passed its end date. - await setTimeout(200) - assert.isNull(await worker.claimDueSchedule()) - await setTimeout(100) - assert.include(listener.wakes, nextRun) - }) - - test('announces the next schedule when one is deleted', async ({ assert, cleanup }) => { - const writer = createAdapter() - const schedule = (id: string, nextRunAt: number) => - writer.upsertSchedule({ - id, - name: 'TestJob', - payload: {}, - everyMs: 60_000, - timezone: 'UTC', - nextRunAt: new Date(nextRunAt), - }) - const secondRun = Date.now() + 60_000 - await schedule('first', Date.now() + 30_000) - await schedule('second', secondRun) - - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - listener.clear() - - await writer.deleteSchedule('first') - assert.equal(await listener.next(), secondRun) - }) - - if (inTransaction) { - test('signals a push in a transaction once it commits', async ({ assert, cleanup }) => { - const listener = await listen(createAdapter()) - cleanup(listener.unsubscribe) - listener.clear() - - await inTransaction(async (adapter) => { - await adapter.pushOn('default', job('committed')) - await setTimeout(100) - assert.deepEqual(listener.wakes, [], 'no signal before the commit') - }) - await listener.next() - - await inTransaction(async (adapter) => { - await adapter.pushOn('default', job('rolled-back')) - throw new Error('rollback') - }).catch(() => {}) - await setTimeout(100) - assert.deepEqual(listener.wakes, [], 'no signal after a rollback') - }) - } -} diff --git a/tests/_utils/register_work_watcher_suite.ts b/tests/_utils/register_work_watcher_suite.ts new file mode 100644 index 0000000..4f27aa3 --- /dev/null +++ b/tests/_utils/register_work_watcher_suite.ts @@ -0,0 +1,261 @@ +import { setTimeout } from 'node:timers/promises' +import { test as JapaTest } from '@japa/runner' +import type { Adapter, WorkWatcher } from '../../src/contracts/adapter.js' + +interface WorkWatcherSuiteOptions { + test: typeof JapaTest + /** Creates an adapter that implements `watch`. */ + createAdapter: () => Adapter + /** See `inTransaction` of the driver test suite. */ + inTransaction?: (operation: (adapter: Adapter) => Promise) => Promise +} + +const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) + +/** + * Watch, as a worker does: `next()` looks for work (reset), then waits and + * resolves with the time the wait took, or null when nothing woke it. + */ +async function watch(adapter: Adapter, queues = ['default']) { + const watcher: WorkWatcher = await adapter.watch!(queues) + // The worker looks for work once ready: what is stored is covered. + watcher.reset() + + return { + watcher, + close: () => watcher.close(), + async next(maxDelay = 2000): Promise { + watcher.reset() + const start = Date.now() + const woken = await watcher.wait(maxDelay, new AbortController().signal, 0) + return woken ? Date.now() - start : null + }, + /** Wait for the first wake at least `atLeast` ms after now. */ + async wakeAfter(atLeast: number, maxDelay = 2000): Promise { + const start = Date.now() + while (Date.now() - start < maxDelay) { + const woken = await this.next(maxDelay - (Date.now() - start)) + if (woken === null) return null + if (Date.now() - start >= atLeast) return Date.now() - start + } + return null + }, + } +} + +/** + * Wakes of adapters that implement `watch`. The watcher and the writer use + * separate adapters, as a worker and a dispatcher would. Due times are + * short, so the suite checks when a wait ends, within a margin. + */ +export function registerWorkWatcherSuite({ + test, + createAdapter, + inTransaction, +}: WorkWatcherSuiteOptions) { + test('wakes for a push to its queue only', async ({ assert, cleanup }) => { + const watching = await watch(createAdapter()) + cleanup(watching.close) + const writer = createAdapter() + + const waiting = watching.next() + await writer.pushOn('other', job('other-queue')) + await setTimeout(100) + await writer.pushOn('default', job('default-queue')) + + const elapsed = await waiting + assert.isNotNull(elapsed) + assert.isAtLeast(elapsed!, 100, 'not woken by the other queue') + assert.isBelow(elapsed!, 400) + }) + + test('wakes when a delayed job and a retry become due', async ({ assert, cleanup }) => { + const watching = await watch(createAdapter()) + cleanup(watching.close) + const writer = createAdapter() + + await writer.pushLaterOn('default', job('delayed'), 300) + assert.closeTo((await watching.wakeAfter(250))!, 300, 100) + await writer.popFrom('default') + + await writer.pushOn('default', job('retried')) + await watching.next() + const acquired = await writer.popFrom('default') + await writer.retryJob(acquired!, 'default', new Date(Date.now() + 300)) + assert.closeTo((await watching.wakeAfter(250))!, 300, 100) + }) + + test('wakes when a schedule becomes due', async ({ assert, cleanup }) => { + const watching = await watch(createAdapter()) + cleanup(watching.close) + const writer = createAdapter() + + await writer.upsertSchedule({ + id: 'watched-schedule', + name: 'TestJob', + payload: {}, + everyMs: 300, + timezone: 'UTC', + nextRunAt: new Date(Date.now() + 300), + }) + assert.closeTo((await watching.wakeAfter(250))!, 300, 100) + + // Its next run, written by the claim. + assert.isNotNull(await writer.claimDueSchedule()) + assert.closeTo((await watching.wakeAfter(250))!, 300, 100) + }) + + test('wakes for work stored before watching', async ({ assert, cleanup }) => { + const writer = createAdapter() + await writer.pushLaterOn('default', job('stored-delayed'), 300) + await writer.upsertSchedule({ + id: 'stored-schedule', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(Date.now() + 600), + }) + + const watching = await watch(createAdapter()) + cleanup(watching.close) + + assert.closeTo((await watching.wakeAfter(250))!, 300, 100) + await writer.popFrom('default') + assert.closeTo((await watching.wakeAfter(200))!, 300, 100) + }) + + test('wakes for the next delayed job once one is promoted', async ({ assert, cleanup }) => { + const writer = createAdapter() + await writer.pushLaterOn('default', job('first-delayed'), 100) + await writer.pushLaterOn('default', job('second-delayed'), 400) + + const watching = await watch(createAdapter()) + cleanup(watching.close) + + assert.closeTo((await watching.wakeAfter(50))!, 100, 80) + assert.equal((await writer.popFrom('default'))?.id, 'first-delayed') + assert.closeTo((await watching.wakeAfter(200))!, 300, 100) + }) + + test('wakes for the next delayed job of each queue', async ({ assert, cleanup }) => { + const writer = createAdapter() + await writer.pushLaterOn('first', job('first-queue'), 150) + await writer.pushLaterOn('second', job('second-queue'), 450) + + const watching = await watch(createAdapter(), ['first', 'second']) + cleanup(watching.close) + + assert.closeTo((await watching.wakeAfter(100))!, 150, 80) + await writer.popFrom('first') + assert.closeTo((await watching.wakeAfter(200))!, 300, 100) + }) + + test('wakes for the next schedule past an expired one', async ({ assert, cleanup }) => { + const writer = createAdapter() + const now = Date.now() + await writer.upsertSchedule({ + id: 'expired', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + to: new Date(now - 500), + nextRunAt: new Date(now - 1000), + }) + await writer.upsertSchedule({ + id: 'next', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(now + 400), + }) + + const worker = createAdapter() + const watching = await watch(worker) + cleanup(watching.close) + + // A worker woken for the expired schedule claims nothing. + assert.isNull(await worker.claimDueSchedule()) + const expected = 400 - (Date.now() - now) + assert.closeTo((await watching.wakeAfter(expected - 100))!, expected, 100) + }) + + test('wakes for the next schedule when the announced one expires before running', async ({ + assert, + cleanup, + }) => { + const writer = createAdapter() + const now = Date.now() + await writer.upsertSchedule({ + id: 'expiring', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + to: new Date(now + 150), + nextRunAt: new Date(now + 100), + }) + await writer.upsertSchedule({ + id: 'next', + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(now + 600), + }) + + const worker = createAdapter() + const watching = await watch(worker) + cleanup(watching.close) + + // Woken for the expiring schedule once it has also passed its end date. + await setTimeout(200) + assert.isNull(await worker.claimDueSchedule()) + const expected = 600 - (Date.now() - now) + assert.closeTo((await watching.wakeAfter(expected - 100))!, expected, 100) + }) + + test('wakes for the next schedule once one is deleted', async ({ assert, cleanup }) => { + const writer = createAdapter() + const schedule = (id: string, inMs: number) => + writer.upsertSchedule({ + id, + name: 'TestJob', + payload: {}, + everyMs: 60_000, + timezone: 'UTC', + nextRunAt: new Date(Date.now() + inMs), + }) + await schedule('first', 200) + await schedule('second', 500) + + const watching = await watch(createAdapter()) + cleanup(watching.close) + await writer.deleteSchedule('first') + + assert.closeTo((await watching.wakeAfter(400))!, 500, 100) + }) + + if (inTransaction) { + test('wakes for a push in a transaction once it commits', async ({ assert, cleanup }) => { + const watching = await watch(createAdapter()) + cleanup(watching.close) + + let waiting = watching.next(300) + await inTransaction(async (adapter) => { + await adapter.pushOn('default', job('committed')) + assert.isNull(await waiting, 'no wake before the commit') + waiting = watching.next() + }) + assert.isNotNull(await waiting) + + await inTransaction(async (adapter) => { + await adapter.pushOn('default', job('rolled-back')) + throw new Error('rollback') + }).catch(() => {}) + assert.isNull(await watching.next(300), 'no wake after a rollback') + }) + } +} diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 8706623..8e4002f 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -5,14 +5,14 @@ import Knex from 'knex' import type { Knex as KnexTypes } from 'knex' import { test } from '@japa/runner' import type { Assert } from '@japa/assert' -import { Redis } from 'ioredis' +import { Redis, type RedisOptions } from 'ioredis' import { CronExpressionParser } from 'cron-parser' import { MemoryAdapter } from './_mocks/memory_adapter.js' import { redis, RedisAdapter } from '../src/drivers/redis_adapter.js' import { knex, KnexAdapter } from '../src/drivers/knex_adapter.js' import { KnexQueueSchemaService } from '../src/services/knex_queue_schema.js' import { registerDriverTestSuite } from './_utils/register_driver_test_suite.js' -import { registerWakeSignalSuite } from './_utils/register_wake_signal_suite.js' +import { registerWorkWatcherSuite } from './_utils/register_work_watcher_suite.js' import { withRedisWriteSpy } from './_utils/with_redis_write_spy.js' import { withKnexQuerySpy } from './_utils/with_knex_query_spy.js' import { pauseKnexDeletes } from './_utils/pause_deletes.js' @@ -118,12 +118,15 @@ test.group('Adapter | Redis', (group) => { createAdapter: () => new RedisAdapter(connection), }) - registerWakeSignalSuite({ + registerWorkWatcherSuite({ test, createAdapter: () => new RedisAdapter(connection), }) - test('dispatches for an ACL user without channel permissions', async ({ assert, cleanup }) => { + test('dispatches and watches for an ACL user without channel permissions', async ({ + assert, + cleanup, + }) => { // New ACL users get no channel permission by default since Redis 7. await connection.call( 'ACL', @@ -148,49 +151,71 @@ test.group('Adapter | Redis', (group) => { await connection.call('ACL', 'DELUSER', 'queue-no-channels') }) const adapter = new RedisAdapter(restricted) + const watcher = await adapter.watch(['default']) + cleanup(() => watcher.close()) + const waiting = watcher.wait(2000, new AbortController().signal, 0) await adapter.pushOn('default', { id: 'acl-job', name: 'TestJob', payload: {}, attempts: 0 }) - await adapter.pushLaterOn( - 'default', - { id: 'acl-delayed', name: 'TestJob', payload: {}, attempts: 0 }, - 0 - ) - const acquired = await adapter.popFrom('default') - assert.equal(acquired?.id, 'acl-job') - assert.isTrue(await adapter.retryJob(acquired!, 'default')) - - // The worker cannot subscribe: it polls instead. - await assert.rejects(() => adapter.subscribe(['default'], () => {}), /NOPERM/) + assert.isTrue(await waiting) }) - test('does not wake subscribers of another database', async ({ assert, cleanup }) => { - const other = new Redis({ - host: process.env.REDIS_HOST || 'localhost', - port: Number.parseInt(process.env.REDIS_PORT || '6379', 10), - keyPrefix: KEY_PREFIX, - db: 14, - }) + test('wakes one waiting watcher per marker', async ({ assert, cleanup }) => { + const writer = new RedisAdapter(connection) + const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) + // Pushed while every worker is busy: two jobs leave one marker. + await writer.pushOn('default', job('first')) + await writer.pushOn('default', job('second')) + + const watchers = await Promise.all([ + new RedisAdapter(connection).watch(['default']), + new RedisAdapter(connection).watch(['default']), + ]) + const controller = new AbortController() cleanup(async () => { - await other.quit() + controller.abort() + await Promise.all(watchers.map((watcher) => watcher.close())) }) - const wakes: number[] = [] - const unsubscribe = await new RedisAdapter(connection).subscribe(['default'], (at) => - wakes.push(at) - ) - cleanup(unsubscribe) - wakes.splice(0) + const woken: number[] = [] + for (const [index, watcher] of watchers.entries()) { + void watcher.wait(5000, controller.signal, 0).then((wake) => wake && woken.push(index)) + } + await new Promise((resolve) => setTimeout(resolve, 200)) + assert.lengthOf(woken, 1) - await new RedisAdapter(other).pushOn('default', { - id: 'other-db', - name: 'TestJob', - payload: {}, - attempts: 0, - }) + // The woken worker takes a job while another remains: the next one wakes. + await writer.popFrom('default') + await new Promise((resolve) => setTimeout(resolve, 200)) + assert.sameMembers(woken, [0, 1]) + }) + + test('hands a due time to another watcher when its watcher stops waiting', async ({ + assert, + cleanup, + }) => { + const first = await new RedisAdapter(connection).watch(['default']) + const second = await new RedisAdapter(connection).watch(['default']) + cleanup(() => Promise.all([first.close(), second.close()]).then(() => {})) + + const busy = new AbortController() + const firstWait = first.wait(5000, busy.signal, 0) + await new Promise((resolve) => setTimeout(resolve, 50)) + const writer = new RedisAdapter(connection) + await writer.pushLaterOn( + 'default', + { id: 'later', name: 'TestJob', payload: {}, attempts: 0 }, + 300 + ) await new Promise((resolve) => setTimeout(resolve, 100)) - assert.deepEqual(wakes, []) + + // The first watcher holds the due time, then its worker gets busy. + busy.abort() + assert.isFalse(await firstWait) + const start = Date.now() + assert.isTrue(await second.wait(2000, new AbortController().signal, 0)) + assert.closeTo(Date.now() - start, 200, 100) }) - test('reconnects a subscription that stops answering', async ({ cleanup }) => { + test('reconnects a blocking connection that stops answering', async ({ assert, cleanup }) => { shortenHeartbeat(cleanup) const target = { host: process.env.REDIS_HOST || 'localhost', @@ -198,27 +223,37 @@ test.group('Adapter | Redis', (group) => { } const proxy = await startSilentProxy(target) cleanup(() => proxy.close()) - // Only the subscriber connection goes through the proxy. + // Only the blocking connection goes through the proxy. const direct = new Redis({ ...target, keyPrefix: KEY_PREFIX, db: 15 }) - direct.duplicate = () => - new Redis({ host: '127.0.0.1', port: proxy.port, keyPrefix: KEY_PREFIX, db: 15 }) + direct.duplicate = (override?: Partial) => + new Redis({ host: '127.0.0.1', port: proxy.port, keyPrefix: KEY_PREFIX, db: 15, ...override }) cleanup(() => direct.disconnect()) - const wakes: number[] = [] - const subscriber = new RedisAdapter(direct, false, new MemoryLogger()) - const unsubscribe = await subscriber.subscribe(['default'], (at) => wakes.push(at)) - cleanup(unsubscribe) + const logger = new MemoryLogger() + const watcher = await new RedisAdapter(direct, false, logger).watch(['default']) + cleanup(() => watcher.close()) + const silences = () => + logger.logs.filter((entry) => entry.message.includes('connection is silent')).length + const waiting = watcher.wait(2000, new AbortController().signal, 0) + await new Promise((resolve) => setTimeout(resolve, 50)) proxy.silence() - wakes.splice(0) - await new RedisAdapter(connection).pushOn('default', { - id: 'after-silence', - name: 'TestJob', - payload: {}, - attempts: 0, - }) - await waitFor(() => wakes.length > 0) - }) + const writer = new RedisAdapter(connection) + const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) + // The marker of this push may be lost with the silent connection: the + // watcher wakes to look once it gives up on it. + await writer.pushOn('default', job('during-silence')) + assert.isTrue(await waiting) + await writer.popFrom('default') + + assert.equal(silences(), 1) + + // The new connection receives the next marker. + const next = watcher.wait(2000, new AbortController().signal, 0) + await writer.pushOn('default', job('after-reconnection')) + assert.isTrue(await next) + assert.equal(silences(), 1) + }).timeout(5000) test('listSchedules should use bounded network round-trips as schedule count grows', async ({ assert, @@ -2228,21 +2263,13 @@ test.group('Adapter | Redis', (group) => { * A jobs table as the previous versions left it: no unique index, and expired * owners that still hold their dedup id. */ -/** Ping subscription connections every 50 ms, with 100 ms to answer. */ +/** Check watcher connections every 50 ms, with 300 ms to answer. */ function shortenHeartbeat(cleanup: (callback: () => void) => void) { const defaults = { ...subscriptionHeartbeat } - Object.assign(subscriptionHeartbeat, { interval: 50, timeout: 100 }) + Object.assign(subscriptionHeartbeat, { interval: 50, timeout: 300 }) cleanup(() => Object.assign(subscriptionHeartbeat, defaults)) } -async function waitFor(condition: () => boolean, timeout = 2000) { - const start = Date.now() - while (!condition()) { - if (Date.now() - start > timeout) throw new Error('Condition not met in time') - await new Promise((resolve) => setTimeout(resolve, 10)) - } -} - async function assertDedupMigration( assert: Assert, connection: ReturnType, @@ -2474,7 +2501,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { }, }) - registerWakeSignalSuite({ + registerWorkWatcherSuite({ test, inTransaction: (operation) => connection.transaction((trx) => @@ -2495,18 +2522,17 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { execute_at: executeAt, }) const now = Date.now() - const nextAt = now + 60_000 + const nextAt = now + 400 await connection(tableName).insert([ row('locked', now - 2000), row('own', now - 1000), row('next', nextAt), ]) - const wakes: number[] = [] - const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) - const unsubscribe = await subscriber.subscribe!(['default'], (at) => wakes.push(at)) - cleanup(unsubscribe) - wakes.splice(0) + const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName }).watch!([ + 'default', + ]) + cleanup(() => watcher.close()) // Another worker holds the oldest due row while it promotes it. const trx = await connection.transaction() @@ -2516,8 +2542,9 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await trx(tableName).where('id', 'locked').forUpdate().first() await new KnexAdapter({ connection, tableName, schedulesTableName }).popFrom('default') - await new Promise((resolve) => setTimeout(resolve, 100)) - assert.deepEqual(wakes, [nextAt]) + watcher.reset() + assert.isTrue(await watcher.wait(2000, new AbortController().signal, 0)) + assert.isAtLeast(Date.now(), nextAt - 20, 'not woken for the locked row') }) /** @@ -2597,24 +2624,24 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { test('rejects a LISTEN connection that receives no notification', async ({ assert, cleanup }) => { // As behind PgBouncer in transaction mode: LISTEN succeeds, nothing arrives. fakeListenClients(cleanup, () => ({})) - const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) + const watching = new KnexAdapter({ connection, tableName, schedulesTableName }) await assert.rejects( - () => subscriber.subscribe!(['default'], () => {}), + () => watching.watch!(['default']), /pass \{ notifications: false \} to knex\(\)/ ) }).timeout(5000) test('aborts a first LISTEN connection still in its handshake', async ({ assert, cleanup }) => { const created = fakeListenClients(cleanup, () => ({ connect: () => new Promise(() => {}) })) - const subscriber = new KnexAdapter({ connection, tableName, schedulesTableName }) + const watching = new KnexAdapter({ connection, tableName, schedulesTableName }) const controller = new AbortController() - const subscription = subscriber.subscribe!(['default'], () => {}, controller.signal) + const watcher = watching.watch!(['default'], controller.signal) while (created.length < 1) await new Promise((resolve) => setTimeout(resolve, 5)) controller.abort() - await assert.rejects(() => subscription) + await assert.rejects(() => watcher) assert.isTrue(created[0].ended) }) @@ -2634,10 +2661,8 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { created_at: Date.now(), }) const worker = new KnexAdapter({ connection, tableName, schedulesTableName }) - const wakes: number[] = [] - const unsubscribe = await worker.subscribe!(['default'], (at) => wakes.push(at)) - cleanup(unsubscribe) - wakes.splice(0) + const watcher = await worker.watch!(['default']) + cleanup(() => watcher.close()) // Another worker is claiming the schedule when it becomes due. const trx = await connection.transaction() @@ -2648,8 +2673,11 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await new Promise((resolve) => setTimeout(resolve, 150)) assert.isNull(await worker.claimDueSchedule()) - await new Promise((resolve) => setTimeout(resolve, 50)) - assert.deepEqual(wakes, [], 'the commit of the other claim notifies') + watcher.reset() + assert.isFalse( + await watcher.wait(100, new AbortController().signal, 0), + 'the commit of the other claim notifies' + ) }) test('calls the connection provider again when its settings expire', async ({ @@ -2677,7 +2705,8 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { cleanup(() => provider.destroy()) const listenerName = async () => { const result = await connection.raw( - `select application_name from pg_stat_activity where query like 'LISTEN%' and application_name like 'listen-%'` + // The LISTEN connection, not the probe that notifies through another one. + `select application_name from pg_stat_activity where application_name like 'listen-%' and query not like '%pg_notify%'` ) return result.rows.map((row: { application_name: string }) => row.application_name) } @@ -2688,8 +2717,8 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { schedulesTableName, logger: new MemoryLogger(), }) - const unsubscribe = await subscriber.subscribe!(['default'], () => {}) - cleanup(unsubscribe) + const watcher = await subscriber.watch!(['default']) + cleanup(() => watcher.close()) const [first] = await listenerName() // Rotated credentials: the provider marks its settings expired. @@ -2705,7 +2734,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.notEqual(second, first) }) - test('does not reconnect a LISTEN connection that failed to subscribe', async ({ + test('does not reconnect a LISTEN connection that failed to start', async ({ assert, cleanup, }) => { @@ -2723,23 +2752,20 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { schedulesTableName, logger: new MemoryLogger(), }) - await assert.rejects( - () => subscriber.subscribe!(['default'], () => {}), - 'Connection terminated' - ) + await assert.rejects(() => subscriber.watch!(['default']), 'Connection terminated') // Past the reconnection delay await new Promise((resolve) => setTimeout(resolve, 1200)) assert.lengthOf(created, 1) }) - test('aborts a LISTEN reconnection still in its handshake when unsubscribing', async ({ + test('aborts a LISTEN reconnection still in its handshake when closed', async ({ assert, cleanup, }) => { - // The second connection never completes its handshake. + // The first connection and its probe work, the next never completes its handshake. const created = fakeListenClients(cleanup, (index) => - index === 1 ? 'real' : { connect: () => new Promise(() => {}) } + index <= 2 ? 'real' : { connect: () => new Promise(() => {}) } ) const subscriber = new KnexAdapter({ @@ -2748,12 +2774,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { schedulesTableName, logger: new MemoryLogger(), }) - const unsubscribe = await subscriber.subscribe!(['default'], () => {}) + const watcher = await subscriber.watch!(['default']) created[0].emit('error', new Error('Connection terminated')) - while (created.length < 2) await new Promise((resolve) => setTimeout(resolve, 20)) - await unsubscribe() - assert.isTrue(created[1].ended) + while (created.length < 3) await new Promise((resolve) => setTimeout(resolve, 20)) + await watcher.close() + assert.isTrue(created[2].ended) }) test('signals jobs of a table whose name is too long for a channel', async ({ @@ -2768,21 +2794,21 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await connection.raw('create table ?? (like ?? including all)', [longTableName, tableName]) const options = { tableName: longTableName, schedulesTableName } - const wakes: number[] = [] const subscriber = new KnexAdapter({ connection, ...options }) - const unsubscribe = await subscriber.subscribe!(['default'], (at) => wakes.push(at)) - cleanup(unsubscribe) - wakes.splice(0) + const watcher = await subscriber.watch!(['default']) + cleanup(() => watcher.close()) + watcher.reset() + const waiting = watcher.wait(2000, new AbortController().signal, 0) const job = { id: 'long-table-job', name: 'TestJob', payload: {}, attempts: 0 } await connection.transaction((trx) => new KnexAdapter({ connection: trx, ...options }).pushOn('default', job) ) - while (wakes.length === 0) await new Promise((resolve) => setTimeout(resolve, 10)) + assert.isTrue(await waiting) assert.isNotNull(await subscriber.getJob(job.id, 'default')) }) - test('reconnects a LISTEN connection that stops answering', async ({ cleanup }) => { + test('reconnects a LISTEN connection that stops answering', async ({ assert, cleanup }) => { shortenHeartbeat(cleanup) const proxy = await startSilentProxy({ host: process.env.PG_HOST || 'localhost', @@ -2804,25 +2830,99 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { knexClient.connectionConfigProvider = undefined }) - const wakes: number[] = [] - const subscriber = new KnexAdapter({ + const logger = new MemoryLogger() + const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName, - logger: new MemoryLogger(), - }) - const unsubscribe = await subscriber.subscribe!(['default'], (at) => wakes.push(at)) - cleanup(unsubscribe) + logger, + }).watch!(['default']) + cleanup(() => watcher.close()) + watcher.reset() + const waiting = watcher.wait(4000, new AbortController().signal, 0) proxy.silence() - wakes.splice(0) + // Its notification is lost: the new connection announces it. await new KnexAdapter({ connection, tableName, schedulesTableName }).pushOn('default', { id: 'after-silence', name: 'TestJob', payload: {}, attempts: 0, }) - await waitFor(() => wakes.length > 0) + assert.isTrue(await waiting) + assert.include( + logger.logs.map((entry) => String(entry.obj?.err)), + 'Error: The LISTEN connection did not answer a ping' + ) + }).timeout(6000) + + test('a watcher woken for nothing sleeps through its cooldown', async ({ assert, cleanup }) => { + const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName }).watch!([ + 'default', + ]) + cleanup(() => watcher.close()) + watcher.reset() + + const start = Date.now() + const waiting = watcher.wait(2000, new AbortController().signal, 300) + await new KnexAdapter({ connection, tableName, schedulesTableName }).pushOn('default', { + id: 'during-cooldown', + name: 'TestJob', + payload: {}, + attempts: 0, + }) + assert.isTrue(await waiting) + assert.closeTo(Date.now() - start, 300, 80) + }) + + test('sends one notification per interval for a burst of pushes', async ({ assert, cleanup }) => { + const listener = (await connection.client.acquireRawConnection()) as { + query(sql: string): Promise + on(event: 'notification', listener: (message: { payload?: string }) => void): void + } + cleanup(() => connection.client.destroyRawConnection(listener)) + const payloads: string[] = [] + listener.on('notification', (message) => payloads.push(message.payload ?? '')) + await listener.query(`LISTEN "${tableName}"`) + + const writer = new KnexAdapter({ connection, tableName, schedulesTableName }) + const start = Date.now() + for (let index = 0; index < 50; index++) { + await writer.pushOn('default', { + id: `burst-${index}`, + name: 'TestJob', + payload: {}, + attempts: 0, + }) + } + const elapsed = Date.now() - start + await writer.destroy() + await new Promise((resolve) => setTimeout(resolve, 50)) + + assert.isAtLeast(payloads.length, 1) + assert.isAtMost(payloads.length, Math.ceil(elapsed / 50) + 1) + }) + + test('watches without holding a connection of the pool', async ({ assert, cleanup }) => { + // The worker holds a pool connection while its watcher starts. + const trx = await connection.transaction() + cleanup(async () => { + await trx.rollback() + }) + await trx.raw('select 1') + const pool = ( + connection.client as KnexTypes.Client & { + pool: { numUsed(): number; numFree(): number } + } + ).pool + const before = pool.numUsed() + pool.numFree() + + const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName }).watch!([ + 'default', + ]) + cleanup(() => watcher.close()) + + assert.equal(pool.numUsed() + pool.numFree(), before) }) test('knex() factory accepts a table name or options', async ({ assert }) => { @@ -2831,11 +2931,11 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await knex(connection, tableName)().pushOn('default', job) const polling = knex(connection, { tableName, schedulesTableName, notifications: false })() - assert.isUndefined(polling.subscribe) + assert.isUndefined(polling.watch) assert.isNotNull(await polling.getJob(job.id, 'default'), 'the string sets the jobs table') const listening = knex(connection, { tableName, schedulesTableName })() - assert.isFunction(listening.subscribe) + assert.isFunction(listening.watch) }) registerPruneFailureSuite({ diff --git a/tests/worker_session.spec.ts b/tests/worker_session.spec.ts index bb328d8..1ff745f 100644 --- a/tests/worker_session.spec.ts +++ b/tests/worker_session.spec.ts @@ -11,7 +11,8 @@ import { import { ControllableAdapter } from './_mocks/controllable_adapter.js' import { trackPromise } from './_utils/track_promise.js' import { MemoryLogger } from './_mocks/memory_logger.js' -import type { Unsubscribe, WakeListener } from '../src/contracts/adapter.js' +import type { WorkWatcher } from '../src/contracts/adapter.js' +import { WorkerWakeup } from '../src/drivers/worker_wakeup.js' type SessionOverrides = Partial> & { jobExecutionRuntime?: Partial @@ -871,32 +872,38 @@ test.group('WorkerSession', () => { }) }) -/** Hands the wake listener of `subscribe` to the test. */ -class SubscribableAdapter extends ControllableAdapter { - onWake?: WakeListener - subscribeError?: Error - - async subscribe( - _queues: readonly string[], - onWake: WakeListener, - _signal?: AbortSignal - ): Promise { - if (this.subscribeError) throw this.subscribeError - this.onWake = onWake - return async () => { - this.onWake = undefined +/** Hands the watcher of `watch` to the test: `notify` wakes it. */ +class WatchableAdapter extends ControllableAdapter { + wakeup?: WorkerWakeup + watchError?: Error + /** The cooldown of each wait. */ + cooldowns: number[] = [] + + async watch(_queues: readonly string[], _signal?: AbortSignal): Promise { + if (this.watchError) throw this.watchError + const wakeup = new WorkerWakeup() + this.wakeup = wakeup + return { + reset: () => wakeup.reset(), + wait: (maxDelay, signal, cooldown) => { + this.cooldowns.push(cooldown) + return wakeup.wait(maxDelay, signal, cooldown) + }, + close: async () => { + this.wakeup = undefined + }, } } } const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) -test.group('WorkerSession | wake signals', () => { +test.group('WorkerSession | work watcher', () => { test('sleeps until a wake signal instead of polling every idleDelay', async ({ assert, cleanup, }) => { - const adapter = new SubscribableAdapter() + const adapter = new WatchableAdapter() const executed = Promise.withResolvers() const session = createSession({ adapter, @@ -916,22 +923,22 @@ test.group('WorkerSession | wake signals', () => { assert.equal(adapter.acquisitions.calls, 1) await adapter.pushOn('default', job('woken')) - adapter.onWake!(Date.now()) + adapter.wakeup!.notify(Date.now()) await executed.promise await session.stop() await start - assert.isUndefined(adapter.onWake, 'stopping ends the subscription') + assert.isUndefined(adapter.wakeup, 'stopping closes the watcher') }) - test('wakes when a signalled due time is reached', async ({ assert, cleanup }) => { - const adapter = new SubscribableAdapter() + test('wakes when a due time is reached', async ({ assert, cleanup }) => { + const adapter = new WatchableAdapter() const session = createSession({ adapter }) cleanup(() => session.stop()) void session.start() await adapter.acquisitions.waitForSettled(1) - adapter.onWake!(Date.now() + 150) + adapter.wakeup!.notify(Date.now() + 150) await setTimeout(75) assert.equal(adapter.acquisitions.calls, 1) @@ -939,8 +946,8 @@ test.group('WorkerSession | wake signals', () => { assert.equal(adapter.acquisitions.calls, 2) }) - test('keeps a signal received while looking for work', async ({ cleanup }) => { - const adapter = new SubscribableAdapter() + test('keeps a wake received while looking for work', async ({ cleanup }) => { + const adapter = new WatchableAdapter() adapter.acquisitions.block(1) const session = createSession({ adapter }) cleanup(async () => { @@ -950,18 +957,18 @@ test.group('WorkerSession | wake signals', () => { void session.start() await adapter.acquisitions.waitForStarted(1) - adapter.onWake!(Date.now()) + adapter.wakeup!.notify(Date.now()) adapter.acquisitions.release(1) // Lost, the signal would leave the session asleep until the stalled check. await adapter.acquisitions.waitForStarted(2) }) - test('polls and stops while the subscription is not ready', async ({ assert }) => { - const adapter = new SubscribableAdapter() + test('polls and stops while the watcher is not ready', async ({ assert }) => { + const adapter = new WatchableAdapter() let aborted = false - adapter.subscribe = (_queues, _onWake, signal) => - new Promise((_resolve, reject) => { + adapter.watch = (_queues, signal) => + new Promise((_resolve, reject) => { signal?.addEventListener('abort', () => { aborted = true reject(signal.reason) @@ -975,20 +982,20 @@ test.group('WorkerSession | wake signals', () => { await session.stop() await start - assert.isTrue(aborted, 'stopping aborts the pending subscription') - assert.deepEqual(logger.logs, [], 'an aborted subscription is not an error') + assert.isTrue(aborted, 'stopping aborts the pending watch') + assert.deepEqual(logger.logs, [], 'an aborted watch is not an error') }) - test('follows the signals of a subscription that gets ready while polling', async ({ + test('follows the wakes of a watcher that gets ready while polling', async ({ assert, cleanup, }) => { - const adapter = new SubscribableAdapter() + const adapter = new WatchableAdapter() const ready = Promise.withResolvers() - const subscribe = adapter.subscribe.bind(adapter) - adapter.subscribe = async (queues, onWake, signal) => { + const watch = adapter.watch.bind(adapter) + adapter.watch = async (queues, signal) => { await ready.promise - return subscribe(queues, onWake, signal) + return watch(queues, signal) } const session = createSession({ adapter, settings: { idleDelay: 60_000 } }) cleanup(() => session.stop()) @@ -997,17 +1004,17 @@ test.group('WorkerSession | wake signals', () => { await adapter.acquisitions.waitForSettled(1) await setTimeout(20) // the session now sleeps for idleDelay ready.resolve() - while (!adapter.onWake) await setTimeout(1) - adapter.onWake(Date.now() + 100) + while (!adapter.wakeup) await setTimeout(1) + adapter.wakeup.notify(Date.now() + 100) // Without it, the first poll would wait for idleDelay. await setTimeout(200) assert.isAtLeast(adapter.acquisitions.calls, 2) }) - test('polls every idleDelay when subscribing fails', async ({ assert, cleanup }) => { - const adapter = new SubscribableAdapter() - adapter.subscribeError = new Error('LISTEN is not supported') + test('polls every idleDelay when watching fails', async ({ assert, cleanup }) => { + const adapter = new WatchableAdapter() + adapter.watchError = new Error('LISTEN is not supported') const logger = new MemoryLogger() const session = createSession({ adapter, logger, settings: { idleDelay: 10 } }) cleanup(() => session.stop()) @@ -1016,7 +1023,27 @@ test.group('WorkerSession | wake signals', () => { await adapter.acquisitions.waitForStarted(3) const errors = logger.logs.filter((entry) => entry.level === 'error') - assert.equal(errors[0].message, 'Failed to subscribe to wake signals, polling instead') - assert.strictEqual(errors[0].obj?.err, adapter.subscribeError) + assert.equal(errors[0].message, 'Failed to watch for work, polling instead') + assert.strictEqual(errors[0].obj?.err, adapter.watchError) + }) + + test('cools down for idleDelay after a wake that found no work', async ({ assert, cleanup }) => { + const adapter = new WatchableAdapter() + const session = createSession({ adapter, settings: { idleDelay: 50 } }) + cleanup(() => session.stop()) + + void session.start() + while (adapter.cooldowns.length === 0) await setTimeout(1) + + // Another worker took the job: this wake finds nothing. + adapter.wakeup!.notify(Date.now()) + while (adapter.cooldowns.length < 2) await setTimeout(1) + assert.equal(adapter.cooldowns[1], 50) + + // A wake that finds a job: no cooldown once it is done. + await adapter.pushOn('default', job('found')) + adapter.wakeup!.notify(Date.now()) + while (adapter.cooldowns.length < 3) await setTimeout(1) + assert.deepEqual(adapter.cooldowns, [0, 50, 0]) }) }) From ef192d1493e250fdcd82a0e46d0720ed8465255f Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 14:46:32 +0000 Subject: [PATCH 05/15] fix(worker): look for work when the Redis blocking connection closes ioredis reconnects a closed connection but never settles the command that was in flight on it. After a server-side kill, the watcher waited for its watchdog, up to the BZPOPMIN timeout plus 5 s, and work due meanwhile started that late. The watcher now ends the read when the connection closes, and looks for work at once, since Redis may have popped a marker whose reply was lost. --- src/drivers/redis_work_watcher.ts | 16 ++++++++++++++-- tests/adapter.spec.ts | 28 ++++++++++++++++++++++++++++ 2 files changed, 42 insertions(+), 2 deletions(-) diff --git a/src/drivers/redis_work_watcher.ts b/src/drivers/redis_work_watcher.ts index 4ef3dad..eef59d3 100644 --- a/src/drivers/redis_work_watcher.ts +++ b/src/drivers/redis_work_watcher.ts @@ -45,6 +45,8 @@ export class RedisWorkWatcher implements WorkWatcher { /** Receives the result of the BZPOPMIN in flight while a wait reads it. */ #deliver?: (marker: PoppedMarker | null) => void #closed = false + /** Ends the BZPOPMIN in flight when its connection closes. */ + #onClose?: () => void constructor(connection: Redis, blocking: Redis, markers: readonly RedisMarker[], logger: Logger) { this.#connection = connection @@ -52,6 +54,7 @@ export class RedisWorkWatcher implements WorkWatcher { this.#markers = markers this.#logger = logger this.#prefix = blocking.options?.keyPrefix ?? '' + blocking.on('close', () => this.#onClose?.()) } reset(): void {} @@ -141,8 +144,16 @@ export class RedisWorkWatcher implements WorkWatcher { const stuck = new Promise<'stuck'>((resolve) => { watchdog = setTimeout(() => resolve('stuck'), timeout + subscriptionHeartbeat.timeout) }) - const reply = await Promise.race([command, stuck]) - if (reply === 'stuck') { + // ioredis reconnects a closed connection, but drops its command. + const closed = new Promise<'closed'>((resolve) => { + this.#onClose = () => resolve('closed') + }) + const reply = await Promise.race([command, stuck, closed]) + if (this.#closed) { + marker = null + } else if (reply === 'closed') { + marker = this.#mayBeLost() + } else if (reply === 'stuck') { this.#logger.error( { err: new Error('BZPOPMIN did not return in time') }, 'Redis blocking connection is silent, reconnecting' @@ -160,6 +171,7 @@ export class RedisWorkWatcher implements WorkWatcher { } } finally { clearTimeout(watchdog) + this.#onClose = undefined this.#reading = undefined } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 8e4002f..46e7b1f 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -255,6 +255,34 @@ test.group('Adapter | Redis', (group) => { assert.equal(silences(), 1) }).timeout(5000) + test('reconnects a blocking connection the server closes', async ({ assert, cleanup }) => { + const logger = new MemoryLogger() + const watcher = await new RedisAdapter(connection, false, logger).watch(['default']) + cleanup(() => watcher.close()) + const waiting = watcher.wait(3000, new AbortController().signal, 0) + await new Promise((resolve) => setTimeout(resolve, 50)) + + // Its reply may be lost: the watcher looks for work at once, not after + // the timeout of BZPOPMIN. + const start = Date.now() + const clients = (await connection.client('LIST')) as string + const blocked = clients.split('\n').find((line) => line.includes('cmd=bzpopmin'))! + await connection.client('KILL', 'ID', blocked.match(/id=(\d+)/)![1]) + assert.isTrue(await waiting) + assert.isBelow(Date.now() - start, 500) + + // The new connection receives the next marker. + const next = watcher.wait(3000, new AbortController().signal, 0) + await new RedisAdapter(connection).pushOn('default', { + id: 'after-kill', + name: 'TestJob', + payload: {}, + attempts: 0, + }) + assert.isTrue(await next) + assert.isBelow(Date.now() - start, 1000) + }).timeout(5000) + test('listSchedules should use bounded network round-trips as schedule count grows', async ({ assert, }) => { From 2433ae5b5b9cf20d925716d122cd1f45a9268b96 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 19:03:17 +0000 Subject: [PATCH 06/15] perf(worker): acquire jobs one at a time After a probe found a job, the worker asked for one job per free slot at once. A worker woken for a single job with a concurrency of 10 sent 10 acquisitions, 9 of them empty: on Redis, about 6 times the commands per job of polling. The worker now acquires one job at a time until its pool is full or a queue runs dry, as BullMQ does. An empty queue costs one acquisition. --- src/worker_session.ts | 44 +++++++----------- tests/worker_session.spec.ts | 87 +++++------------------------------- 2 files changed, 26 insertions(+), 105 deletions(-) diff --git a/src/worker_session.ts b/src/worker_session.ts index f954f59..e422d95 100644 --- a/src/worker_session.ts +++ b/src/worker_session.ts @@ -480,40 +480,28 @@ export class WorkerSession { return completed } + /** + * Acquire jobs one at a time until the pool is full or the queues run dry. + * An empty queue then costs one acquisition, not one per free slot: a + * watching worker looks for work on every wake. + */ async #fillPool(): Promise { - const slotsAvailable = this.#settings.concurrency - this.#pool.size - - if (slotsAvailable <= 0) return { cycles: [], errors: [] } - - let probe: StartedCycle | null - - try { - probe = await this.#acquireAndStartNextJob() - } catch (error) { - return { cycles: [], errors: [error] } - } - - if (!probe) return { cycles: [], errors: [] } - if (!this.#running) return { cycles: [probe], errors: [] } + const cycles: StartedCycle[] = [] - const acquisitions: Array> = [] - for (let index = 1; index < slotsAvailable; index++) { - acquisitions.push(this.#acquireAndStartNextJob()) - } - - const results = await Promise.allSettled(acquisitions) - const cycles = [probe] - const errors: unknown[] = [] + while (this.#running && this.#pool.size < this.#settings.concurrency) { + let cycle: StartedCycle | null - for (const result of results) { - if (result.status === 'rejected') { - errors.push(result.reason) - } else if (result.value) { - cycles.push(result.value) + try { + cycle = await this.#acquireAndStartNextJob() + } catch (error) { + return { cycles, errors: [error] } } + + if (!cycle) break + cycles.push(cycle) } - return { cycles, errors } + return { cycles, errors: [] } } async #acquireAndStartNextJob(): Promise { diff --git a/tests/worker_session.spec.ts b/tests/worker_session.spec.ts index 1ff745f..7731110 100644 --- a/tests/worker_session.spec.ts +++ b/tests/worker_session.spec.ts @@ -83,20 +83,13 @@ test.group('WorkerSession', () => { assert.deepEqual(adapter.polledQueues, ['critical', 'default', 'low']) }) - test('fans out remaining acquisitions after the initial probe finds work', async ({ - assert, - cleanup, - }) => { + test('acquires one job at a time until the pool is full', async ({ assert, cleanup }) => { const adapter = new ControllableAdapter() const executionGate = Promise.withResolvers() - let executionsStarted = 0 - adapter.acquisitions.block(2, 3) - const session = createSession({ adapter, jobExecutionRuntime: { async execute() { - executionsStarted++ await executionGate.promise return { type: 'completed' } }, @@ -105,12 +98,11 @@ test.group('WorkerSession', () => { }) cleanup(async () => { - adapter.releaseAll() executionGate.resolve() await session.stop() }) - for (let index = 1; index <= 3; index++) { + for (let index = 1; index <= 4; index++) { await adapter.pushOn('default', { id: `backlog-job-${index}`, name: 'TestJob', @@ -120,18 +112,11 @@ test.group('WorkerSession', () => { }) } - const cycle = session.processCycle() - await adapter.acquisitions.waitForStarted(3) - - assert.equal(adapter.acquisitions.calls, 3) - - adapter.acquisitions.release(2, 3) - - assert.equal((await cycle)?.type, 'started') - assert.equal(executionsStarted, 3) + assert.equal((await session.processCycle())?.type, 'started') + assert.equal(adapter.acquisitions.calls, 3, 'stops once the pool is full') }) - test('uses one probe per subsequent empty tick after processing one job', async ({ + test('uses one acquisition per empty tick after processing one job', async ({ assert, cleanup, }) => { @@ -149,14 +134,14 @@ test.group('WorkerSession', () => { }) assert.equal((await session.processCycle())?.type, 'started') - assert.equal(adapter.acquisitions.calls, 10) + assert.equal(adapter.acquisitions.calls, 2, 'stops at the first empty acquisition') assert.equal((await session.processCycle())?.type, 'completed') assert.equal((await session.processCycle())?.type, 'idle') - assert.equal(adapter.acquisitions.calls, 11) + assert.equal(adapter.acquisitions.calls, 3) assert.equal((await session.processCycle())?.type, 'idle') - assert.equal(adapter.acquisitions.calls, 12) + assert.equal(adapter.acquisitions.calls, 4) }) test('reuses one completion wait across idle ticks and observes a later job', async ({ @@ -798,61 +783,9 @@ test.group('WorkerSession', () => { await Promise.all([stop, start]) }) - test('waits for sibling acquisitions when one acquisition fails', async ({ assert, cleanup }) => { - const adapter = new ControllableAdapter() - let jobCompleted = false - adapter.acquisitions.block(2, 3).fail(2, new Error('Failed to acquire job')) - adapter.finalizations.block(1) - - const session = createSession({ - adapter, - jobExecutionRuntime: { - async execute() { - jobCompleted = true - return { type: 'completed' } - }, - }, - settings: { concurrency: 3 }, - }) - - cleanup(async () => { - adapter.releaseAll() - await session.stop() - }) - - await adapter.pushOn('default', { - id: 'late-job-after-sibling-error', - name: 'TestJob', - payload: {}, - attempts: 0, - priority: 0, - }) - - const start = session.start() - await adapter.acquisitions.waitForStarted(3) - adapter.acquisitions.release(2) - await adapter.acquisitions.waitForSettled(2) - - const stop = trackPromise(session.stop()) - assert.isFalse(stop.settled) - - adapter.acquisitions.release(3) - await adapter.finalizations.waitForStarted() - assert.isTrue(jobCompleted) - assert.isFalse(stop.settled) - - adapter.finalizations.release(1) - await Promise.all([stop.promise, start]) - assert.equal(adapter.acquisitions.calls, 3) - assert.isNull(await adapter.getJob('late-job-after-sibling-error', 'default')) - }) - - test('emits successful acquisitions before a sibling acquisition error', async ({ - assert, - cleanup, - }) => { + test('emits a started job before a later acquisition error', async ({ assert, cleanup }) => { const adapter = new ControllableAdapter() - adapter.acquisitions.fail(2, new Error('Failed to acquire sibling job')) + adapter.acquisitions.fail(2, new Error('Failed to acquire the next job')) const session = createSession({ adapter, settings: { concurrency: 2 } }) cleanup(() => session.stop()) From df34750764ce02ede24e7d243a3b0862b814a648 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 19:35:29 +0000 Subject: [PATCH 07/15] feat(knex): make PostgreSQL notifications opt-in On PostgreSQL, LISTEN/NOTIFY costs grow with the number of workers: each worker holds one more connection, and every NOTIFY reaches every LISTEN connection. A load test with 100 workers doubled the database CPU, and with max_connections at 100, 40 workers fit instead of 90. Enabled by default, an upgrade alone could exhaust the connections of a deployment. Workers on PostgreSQL now poll unless the adapter is created with `notifications: true`, on every process that dispatches jobs. An adapter now sends at most one NOTIFY per 50 ms for all its queues, instead of one per queue: with 50 queues, the limit did not hold. --- README.md | 38 ++++++------ src/drivers/knex_adapter.ts | 92 ++++++++++++++++------------- src/drivers/wake_messages.ts | 25 +++++--- tests/adapter.spec.ts | 108 ++++++++++++++++++++++++++--------- 4 files changed, 170 insertions(+), 93 deletions(-) diff --git a/README.md b/README.md index e634ce2..f2eb274 100644 --- a/README.md +++ b/README.md @@ -418,8 +418,8 @@ const adapter = knex(config, { schedulesTableName: 'custom_schedules_table', }) -// Behind PgBouncer in transaction mode, which does not support LISTEN: poll instead -const adapter = knex(config, { notifications: false }) +// PostgreSQL: wake Workers with LISTEN/NOTIFY instead of polling (see Worker Configuration) +const adapter = knex(config, { notifications: true }) ``` @@ -950,26 +950,26 @@ const config = { } ``` -On Redis and PostgreSQL (Knex), an idle Worker does not poll: it waits until a job is dispatched, or -a delayed job, a retry, or a schedule becomes due. The Worker still checks its queues every -`stalledInterval`, in case a wake was lost. - -- Redis: Workers wait on a marker with `BZPOPMIN`, as in BullMQ. A dispatched job wakes one idle - Worker, which wakes the next one while jobs remain. -- PostgreSQL: Workers `LISTEN` for a `NOTIFY` that wakes all of them. A Worker woken for a job - another Worker took waits `idleDelay` before it looks again, so idle Workers never query more - often than when polling. A job dispatched in a transaction wakes Workers when it commits. Behind - a pooler that does not support `LISTEN`, such as PgBouncer in transaction mode, pass - `notifications: false` to `knex()`. -- MySQL, SQLite, and Kysely poll every `idleDelay`. +On Redis, an idle Worker does not poll: it waits on a marker with `BZPOPMIN`, as in BullMQ, until a +job is dispatched, or a delayed job, a retry, or a schedule becomes due. A dispatched job wakes one +idle Worker, which wakes the next one while jobs remain. The Worker still checks its queues every +`stalledInterval`, in case a wake was lost, and holds one more connection to wait for work. The process that dispatches a job wakes the Workers. A job dispatched by an older version of the -package, or written to the storage without the Adapter, wakes none: the Worker finds it at its next -stalled check. Upgrade the processes that dispatch jobs with, or before, the Workers. Each Worker -holds one more connection to wait for work, checked every 10 seconds. +package, or written to Redis without the Adapter, wakes none: the Worker finds it at its next +stalled check. Upgrade the processes that dispatch jobs with, or before, the Workers. + +On PostgreSQL, Workers poll every `idleDelay` by default. With `knex(config, { notifications: true })`, +they `LISTEN` for a `NOTIFY` instead, and a job dispatched in a transaction wakes them when it +commits. Enable it on every process that dispatches jobs, not only on Workers. It suits a few +Workers with a high `concurrency`: + +- Each Worker holds one more connection. +- Every `NOTIFY` reaches every Worker. A Worker woken for a job another Worker took waits + `idleDelay` before it looks again, so idle Workers never query more often than when polling. +- It does not work behind a pooler in transaction mode, such as PgBouncer. -Prefer fewer Workers with a higher `concurrency` to many Workers with a `concurrency` of 1: each -Worker holds connections, and on PostgreSQL every `NOTIFY` reaches every Worker. +MySQL, SQLite, and Kysely poll every `idleDelay`. Run one Worker per process. A Worker listens on one Adapter, so to process the queues of several Adapters, start one process per Adapter. Starting a second Worker while another one runs in the diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 904e1db..114f6c5 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -59,8 +59,12 @@ export interface KnexAdapterOptions { logger?: Logger /** * PostgreSQL only. Wake workers through LISTEN/NOTIFY instead of polling. - * Disable it behind a pooler that does not support LISTEN, such as - * PgBouncer in transaction mode. Defaults to true. + * Defaults to false. Enable it on every process that dispatches jobs, not + * only on workers: a job dispatched without it wakes no worker. + * + * Each worker holds one more connection, and every NOTIFY reaches every + * worker: suited to a few workers with a high concurrency. Not supported + * behind a pooler in transaction mode, such as PgBouncer. */ notifications?: boolean } @@ -89,6 +93,11 @@ function wakeChannelName(table: string): string { return `queue_jobs_${createHash('sha256').update(table).digest('hex').slice(0, 40)}` } +/** The message of a job of `queue` ready now, or due at `at`. */ +function jobMessage(queue: string, at?: number): WakeMessage { + return at === undefined ? { ready: [queue] } : { due: { [queue]: at } } +} + const LISTEN_RECONNECT_DELAY = 1000 const LISTEN_PROBE_TIMEOUT = 2000 const LISTEN_MAX_RECONNECT_DELAY = 30_000 @@ -106,10 +115,11 @@ interface ScheduleWatcher { at: number | null } -/** Signals of a queue that wait for the next interval. */ -interface QueueSignal { - ready: boolean - at: number | null +/** Signals that wait for the next NOTIFY of an adapter. */ +interface PendingSignals { + ready: Set + /** The earliest due time by queue. */ + due: Map sent: Promise } @@ -158,7 +168,7 @@ export type KnexFactoryOptions = Pick< * ```ts * knex(config) * knex(config, 'custom_jobs_table') - * knex(config, { tableName: 'custom_jobs_table', notifications: false }) + * knex(config, { tableName: 'custom_jobs_table', notifications: true }) * ``` */ export function knex(config: KnexConfig, options?: string | KnexFactoryOptions) { @@ -188,8 +198,8 @@ export class KnexAdapter implements Adapter { readonly #logger: Logger /** Set on PostgreSQL with notifications enabled: the jobs table names the channel. */ readonly #wakeChannel?: string - /** Queues with a signal in flight: see #signal. */ - readonly #signals = new Map() + /** Signals asked for since the last NOTIFY: see #signal. */ + #pendingSignals?: PendingSignals /** Watchers of this adapter: see claimDueSchedule. */ readonly #scheduleWatchers = new Set() #workerId: string = '' @@ -205,7 +215,7 @@ export class KnexAdapter implements Adapter { this.#ownsConnection = config.ownsConnection ?? false this.#logger = config.logger ?? consoleLogger - if (this.#connection.client.dialect === 'postgresql' && config.notifications !== false) { + if (this.#connection.client.dialect === 'postgresql' && config.notifications === true) { this.#wakeChannel = wakeChannelName(this.#jobsTable) this.watch = async (queues, signal) => { const wakeup = new WorkerWakeup() @@ -250,38 +260,43 @@ export class KnexAdapter implements Adapter { * * In a transaction, the NOTIFY joins it. Otherwise, the work is stored and * the signal is sent in the background: PostgreSQL serializes the commits - * that NOTIFY, and delivers each NOTIFY to every LISTEN connection. A queue - * gets at most one signal per SIGNAL_INTERVAL per adapter; the signals - * asked for meanwhile join the next one, with the earliest due time. That - * is enough: promoting a delayed job announces the next one. `destroy()` - * waits for them. + * that NOTIFY, and delivers each NOTIFY to every LISTEN connection. An + * adapter sends at most one NOTIFY per SIGNAL_INTERVAL, for all its queues; + * the signals asked for meanwhile join the next one, with the earliest due + * time of each queue. That is enough: promoting a delayed job announces the + * next one. `destroy()` waits for them. */ async #signal(queue: string, at?: number): Promise { if (!this.#wakeChannel) return + const ready = at === undefined || at <= Date.now() if (this.#connection.isTransaction) { - return this.#notify(this.#connection, at === undefined ? { queue } : { queue, at }) + return this.#notify(this.#connection, jobMessage(queue, ready ? undefined : at)) } - const pending = this.#signals.get(queue) - const state = pending ?? { ready: false, at: null, sent: Promise.resolve() } - if (at === undefined || at <= Date.now()) { - state.ready = true + const pending = this.#pendingSignals ?? { + ready: new Set(), + due: new Map(), + sent: Promise.resolve(), + } + if (ready) { + pending.ready.add(queue) } else { - state.at = Math.min(state.at ?? Infinity, at) + pending.due.set(queue, Math.min(pending.due.get(queue) ?? Infinity, at!)) } - if (pending) return - - this.#signals.set(queue, state) - state.sent = (async () => { - while (state.ready || state.at !== null) { - const { ready, at: dueAt } = state - state.ready = false - state.at = null - if (ready) await this.#notify(this.#connection, { queue }) - if (dueAt !== null) await this.#notify(this.#connection, { queue, at: dueAt }) + if (this.#pendingSignals) return + + this.#pendingSignals = pending + pending.sent = (async () => { + while (pending.ready.size > 0 || pending.due.size > 0) { + const message: WakeMessage = {} + if (pending.ready.size > 0) message.ready = [...pending.ready] + if (pending.due.size > 0) message.due = Object.fromEntries(pending.due) + pending.ready.clear() + pending.due.clear() + await this.#notify(this.#connection, message) await sleep(SIGNAL_INTERVAL) } - this.#signals.delete(queue) + this.#pendingSignals = undefined })() } @@ -297,11 +312,10 @@ export class KnexAdapter implements Adapter { return } - const message: WakeMessage = at === undefined ? { queue } : { queue, at } await this.#connection.raw('with inserted as (?) select pg_notify(?, ?)', [ insert, this.#wakeChannel, - encodeWakeMessage(message), + encodeWakeMessage(jobMessage(queue, at)), ]) } @@ -420,7 +434,7 @@ export class KnexAdapter implements Adapter { reject( new Error( 'LISTEN received no notification within 2s. Behind a pooler in transaction ' + - 'mode, such as PgBouncer, pass { notifications: false } to knex()' + 'mode, such as PgBouncer, do not enable notifications' ) ), LISTEN_PROBE_TIMEOUT @@ -531,7 +545,7 @@ export class KnexAdapter implements Adapter { } async destroy(): Promise { - await Promise.all([...this.#signals.values()].map((state) => state.sent)) + await this.#pendingSignals?.sent if (this.#ownsConnection) { await this.#connection.destroy() } @@ -742,7 +756,7 @@ export class KnexAdapter implements Adapter { .min('execute_at as at') .first() if (next?.at !== null && next?.at !== undefined) { - await this.#notify(trx, { queue, at: Number(next.at) }) + await this.#notify(trx, jobMessage(queue, Number(next.at))) } } }) @@ -1204,7 +1218,7 @@ export class KnexAdapter implements Adapter { for (let start = 0; start < rows.length; start += SQL_INSERT_CHUNK_SIZE) { await connection(this.#jobsTable).insert(rows.slice(start, start + SQL_INSERT_CHUNK_SIZE)) } - await this.#notify(connection, { queue }) + await this.#notify(connection, jobMessage(queue)) } if (this.#connection.isTransaction) { @@ -1292,7 +1306,7 @@ export class KnexAdapter implements Adapter { } } - if (recovered > 0) await this.#notify(trx, { queue }) + if (recovered > 0) await this.#notify(trx, jobMessage(queue)) return { recovered, exceeded } }) } diff --git a/src/drivers/wake_messages.ts b/src/drivers/wake_messages.ts index cca8ca5..a6e253b 100644 --- a/src/drivers/wake_messages.ts +++ b/src/drivers/wake_messages.ts @@ -7,22 +7,25 @@ export type WakeListener = (at: number) => void /** * Message published on the LISTEN channel of the Knex adapter. * - * - `{ queue, at }`: a job of `queue` becomes due at `at` (epoch ms). - * - `{ queue }`: a job of `queue` is ready now. Without a timestamp, a + * - `{ ready, due }`: jobs of the `ready` queues are ready now, and a job of + * each `due` queue becomes due at its time (epoch ms). Without a time, a * writer whose clock runs ahead cannot delay the watcher. * - `{ schedule }`: the next schedule run after a schedule changed, read by * the writer so watchers do not each read it. * - `{ probe }`: sent by a watcher to check that its connection receives * notifications. Other watchers ignore it. */ -export type WakeMessage = { queue: string; at?: number } | { schedule: number } | { probe: string } +export type WakeMessage = + | { ready?: string[]; due?: Record } + | { schedule: number } + | { probe: string } export function encodeWakeMessage(message: WakeMessage): string { return JSON.stringify(message) } /** - * Route a raw message of the wake channel: a job of a watched queue to + * Route a raw message of the wake channel: jobs of the watched queues to * `onWake`, the next schedule run to `onSchedule`. Others are ignored. */ export function dispatchWakeMessage( @@ -31,7 +34,7 @@ export function dispatchWakeMessage( onWake: WakeListener, onSchedule: WakeListener ): void { - let message: Partial<{ queue: unknown; at: unknown; schedule: unknown }> + let message: Partial<{ ready: unknown; due: unknown; schedule: unknown }> try { message = JSON.parse(raw) @@ -41,8 +44,16 @@ export function dispatchWakeMessage( if (typeof message.schedule === 'number') { onSchedule(message.schedule) - } else if (typeof message.queue === 'string' && queues.includes(message.queue)) { - onWake(typeof message.at === 'number' ? message.at : Date.now()) + return + } + + if (Array.isArray(message.ready) && message.ready.some((queue) => queues.includes(queue))) { + onWake(Date.now()) + } + if (message.due && typeof message.due === 'object') { + for (const [queue, at] of Object.entries(message.due)) { + if (typeof at === 'number' && queues.includes(queue)) onWake(at) + } } } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 46e7b1f..f90e1f1 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -2533,9 +2533,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { test, inTransaction: (operation) => connection.transaction((trx) => - operation(new KnexAdapter({ connection: trx, tableName, schedulesTableName })) + operation( + new KnexAdapter({ connection: trx, tableName, schedulesTableName, notifications: true }) + ) ), - createAdapter: () => new KnexAdapter({ connection, tableName, schedulesTableName }), + createAdapter: () => + new KnexAdapter({ connection, tableName, schedulesTableName, notifications: true }), }) test('announces a future delayed job past rows another transaction promotes', async ({ @@ -2557,9 +2560,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { row('next', nextAt), ]) - const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName }).watch!([ - 'default', - ]) + const watcher = await new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }).watch!(['default']) cleanup(() => watcher.close()) // Another worker holds the oldest due row while it promotes it. @@ -2569,7 +2575,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { }) await trx(tableName).where('id', 'locked').forUpdate().first() - await new KnexAdapter({ connection, tableName, schedulesTableName }).popFrom('default') + await new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }).popFrom('default') watcher.reset() assert.isTrue(await watcher.wait(2000, new AbortController().signal, 0)) assert.isAtLeast(Date.now(), nextAt - 20, 'not woken for the locked row') @@ -2652,17 +2663,24 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { test('rejects a LISTEN connection that receives no notification', async ({ assert, cleanup }) => { // As behind PgBouncer in transaction mode: LISTEN succeeds, nothing arrives. fakeListenClients(cleanup, () => ({})) - const watching = new KnexAdapter({ connection, tableName, schedulesTableName }) + const watching = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) - await assert.rejects( - () => watching.watch!(['default']), - /pass \{ notifications: false \} to knex\(\)/ - ) + await assert.rejects(() => watching.watch!(['default']), /do not enable notifications/) }).timeout(5000) test('aborts a first LISTEN connection still in its handshake', async ({ assert, cleanup }) => { const created = fakeListenClients(cleanup, () => ({ connect: () => new Promise(() => {}) })) - const watching = new KnexAdapter({ connection, tableName, schedulesTableName }) + const watching = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) const controller = new AbortController() const watcher = watching.watch!(['default'], controller.signal) @@ -2688,7 +2706,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { status: 'active', created_at: Date.now(), }) - const worker = new KnexAdapter({ connection, tableName, schedulesTableName }) + const worker = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) const watcher = await worker.watch!(['default']) cleanup(() => watcher.close()) @@ -2741,6 +2764,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { const subscriber = new KnexAdapter({ connection: provider, + notifications: true, tableName, schedulesTableName, logger: new MemoryLogger(), @@ -2779,6 +2803,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { tableName, schedulesTableName, logger: new MemoryLogger(), + notifications: true, }) await assert.rejects(() => subscriber.watch!(['default']), 'Connection terminated') @@ -2801,6 +2826,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { tableName, schedulesTableName, logger: new MemoryLogger(), + notifications: true, }) const watcher = await subscriber.watch!(['default']) created[0].emit('error', new Error('Connection terminated')) @@ -2820,7 +2846,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await connection.raw('create schema if not exists ??', [schema]) cleanup(() => connection.raw('drop schema ?? cascade', [schema])) await connection.raw('create table ?? (like ?? including all)', [longTableName, tableName]) - const options = { tableName: longTableName, schedulesTableName } + const options = { tableName: longTableName, schedulesTableName, notifications: true } const subscriber = new KnexAdapter({ connection, ...options }) const watcher = await subscriber.watch!(['default']) @@ -2864,6 +2890,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { tableName, schedulesTableName, logger, + notifications: true, }).watch!(['default']) cleanup(() => watcher.close()) watcher.reset() @@ -2871,7 +2898,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { proxy.silence() // Its notification is lost: the new connection announces it. - await new KnexAdapter({ connection, tableName, schedulesTableName }).pushOn('default', { + await new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }).pushOn('default', { id: 'after-silence', name: 'TestJob', payload: {}, @@ -2885,15 +2917,23 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { }).timeout(6000) test('a watcher woken for nothing sleeps through its cooldown', async ({ assert, cleanup }) => { - const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName }).watch!([ - 'default', - ]) + const watcher = await new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }).watch!(['default']) cleanup(() => watcher.close()) watcher.reset() const start = Date.now() const waiting = watcher.wait(2000, new AbortController().signal, 300) - await new KnexAdapter({ connection, tableName, schedulesTableName }).pushOn('default', { + await new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }).pushOn('default', { id: 'during-cooldown', name: 'TestJob', payload: {}, @@ -2903,7 +2943,10 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.closeTo(Date.now() - start, 300, 80) }) - test('sends one notification per interval for a burst of pushes', async ({ assert, cleanup }) => { + test('sends one notification per interval for a burst of pushes to several queues', async ({ + assert, + cleanup, + }) => { const listener = (await connection.client.acquireRawConnection()) as { query(sql: string): Promise on(event: 'notification', listener: (message: { payload?: string }) => void): void @@ -2913,10 +2956,16 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { listener.on('notification', (message) => payloads.push(message.payload ?? '')) await listener.query(`LISTEN "${tableName}"`) - const writer = new KnexAdapter({ connection, tableName, schedulesTableName }) + const writer = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) const start = Date.now() for (let index = 0; index < 50; index++) { - await writer.pushOn('default', { + // Spread over queues: the interval holds for the adapter. + await writer.pushOn(`queue-${index % 5}`, { id: `burst-${index}`, name: 'TestJob', payload: {}, @@ -2945,9 +2994,12 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { ).pool const before = pool.numUsed() + pool.numFree() - const watcher = await new KnexAdapter({ connection, tableName, schedulesTableName }).watch!([ - 'default', - ]) + const watcher = await new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }).watch!(['default']) cleanup(() => watcher.close()) assert.equal(pool.numUsed() + pool.numFree(), before) @@ -2958,11 +3010,11 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await knex(connection, tableName)().pushOn('default', job) - const polling = knex(connection, { tableName, schedulesTableName, notifications: false })() - assert.isUndefined(polling.watch) + const polling = knex(connection, { tableName, schedulesTableName })() + assert.isUndefined(polling.watch, 'polls by default') assert.isNotNull(await polling.getJob(job.id, 'default'), 'the string sets the jobs table') - const listening = knex(connection, { tableName, schedulesTableName })() + const listening = knex(connection, { tableName, schedulesTableName, notifications: true })() assert.isFunction(listening.watch) }) From 5f9360b6b3e6f6b5e7f2c142f88826f108d3f91d Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 19:52:45 +0000 Subject: [PATCH 08/15] fix(worker): harden the failure paths of watching for work Four failure paths escaped the fallback to polling: - The PostgreSQL probe armed its 2s timeout before its connection completed. A probe connection that stalled left the rejection unobserved, and Node exited instead of falling back to polling. - Aborting a Redis watch only disconnected the blocking client. A PING queued during a silent handshake never settled, so stopping the worker hung. Abort now rejects the PING. - A notification whose payload parsed to null threw in the pg event handler. Any role that can connect can send one, and it killed the worker. Payloads that are not objects are now ignored. - The LISTEN connection did not apply the Knex searchPath, so its announcement queries failed for unqualified tables found only through it. It now sets the search path as the pool does. --- src/drivers/knex_adapter.ts | 17 ++++++--- src/drivers/redis_adapter.ts | 7 +++- src/drivers/wake_messages.ts | 4 +- tests/adapter.spec.ts | 74 ++++++++++++++++++++++++++++++++++++ 4 files changed, 94 insertions(+), 8 deletions(-) diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 114f6c5..9b89fdc 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -426,7 +426,8 @@ export class KnexAdapter implements Adapter { payload: encodeWakeMessage({ probe: randomUUID() }), received: Promise.withResolvers(), } - const { received } = probe + const { received, payload } = probe + const sender = await createClient() let timer: NodeJS.Timeout | undefined const timeout = new Promise((_resolve, reject) => { timer = setTimeout( @@ -440,11 +441,15 @@ export class KnexAdapter implements Adapter { LISTEN_PROBE_TIMEOUT ) }) - const sender = await createClient() + // The timeout covers the connection of the sender too: it may stall. + const exchange = (async () => { + await sender.connect() + await sender.query('select pg_notify($1, $2)', [channel, payload]) + await received.promise + })() + exchange.catch(() => {}) try { - await Promise.race([sender.connect(), closing.promise]) - await sender.query('select pg_notify($1, $2)', [channel, probe.payload]) - await Promise.race([received.promise, timeout, closing.promise]) + await Promise.race([exchange, timeout, closing.promise]) } finally { clearTimeout(timer) probe = undefined @@ -466,6 +471,8 @@ export class KnexAdapter implements Adapter { }) }) await Promise.race([connection.connect(), closing.promise]) + // Announcements read unqualified tables, as the pool does. + await knexClient.setSchemaSearchPath(connection) await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) if (closed) return release() await verify() diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index 8a611a8..2da6d50 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -123,11 +123,14 @@ export class RedisAdapter implements Adapter { blocking.on('error', (error) => { this.#logger.error({ err: error }, 'Redis blocking connection error') }) - const abort = () => blocking.disconnect() + // A PING queued during a silent handshake never settles: abort rejects. + const aborted = Promise.withResolvers() + aborted.promise.catch(() => {}) + const abort = () => aborted.reject(signal!.reason) signal?.addEventListener('abort', abort, { once: true }) try { - await blocking.ping() + await Promise.race([blocking.ping(), aborted.promise]) const seedKeys = queues.flatMap((queue) => { const keys = this.#getKeys(queue) return [keys.pending, keys.delayed, keys.marker] diff --git a/src/drivers/wake_messages.ts b/src/drivers/wake_messages.ts index a6e253b..d2e2ec7 100644 --- a/src/drivers/wake_messages.ts +++ b/src/drivers/wake_messages.ts @@ -34,13 +34,15 @@ export function dispatchWakeMessage( onWake: WakeListener, onSchedule: WakeListener ): void { - let message: Partial<{ ready: unknown; due: unknown; schedule: unknown }> + let message: Partial<{ ready: unknown; due: unknown; schedule: unknown }> | null try { message = JSON.parse(raw) } catch { return } + // Any role allowed to connect can notify the channel, with any payload. + if (!message || typeof message !== 'object') return if (typeof message.schedule === 'number') { onSchedule(message.schedule) diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index f90e1f1..fd8fb01 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -1,6 +1,7 @@ import { mkdtemp, rm } from 'node:fs/promises' import { tmpdir } from 'node:os' import { join } from 'node:path' +import { createServer, type AddressInfo } from 'node:net' import Knex from 'knex' import type { Knex as KnexTypes } from 'knex' import { test } from '@japa/runner' @@ -215,6 +216,25 @@ test.group('Adapter | Redis', (group) => { assert.closeTo(Date.now() - start, 200, 100) }) + test('aborts a blocking connection stuck in its handshake', async ({ assert, cleanup }) => { + // Accepts connections and never answers. + const blackhole = createServer(() => {}) + await new Promise((resolve) => blackhole.listen(0, '127.0.0.1', resolve)) + cleanup(() => void blackhole.close()) + const port = (blackhole.address() as AddressInfo).port + const direct = new Redis(connection.options) + direct.duplicate = (override?: Partial) => + new Redis({ ...connection.options, host: '127.0.0.1', port, ...override }) + cleanup(() => direct.disconnect()) + + const controller = new AbortController() + const adapter = new RedisAdapter(direct, false, new MemoryLogger()) + const watching = adapter.watch(['default'], controller.signal) + setTimeout(() => controller.abort(), 100) + + await assert.rejects(() => watching) + }).timeout(2000) + test('reconnects a blocking connection that stops answering', async ({ assert, cleanup }) => { shortenHeartbeat(cleanup) const target = { @@ -2691,6 +2711,60 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.isTrue(created[0].ended) }) + test('rejects a LISTEN probe whose connection stalls', async ({ assert, cleanup }) => { + // The LISTEN connection works, the probe never completes its handshake. + fakeListenClients(cleanup, (index) => + index === 1 ? 'real' : { connect: () => new Promise(() => {}) } + ) + const watching = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) + + await assert.rejects(() => watching.watch!(['default']), /do not enable notifications/) + }).timeout(5000) + + test('ignores a notification that is not a wake message', async ({ assert, cleanup }) => { + const options = { connection, tableName, schedulesTableName, notifications: true } + const watcher = await new KnexAdapter(options).watch!(['default']) + cleanup(() => watcher.close()) + watcher.reset() + const waiting = watcher.wait(2000, new AbortController().signal, 0) + + await connection.raw(`select pg_notify(?, 'null')`, [tableName]) + const job = { id: 'after-null', name: 'TestJob', payload: {}, attempts: 0 } + await new KnexAdapter(options).pushOn('default', job) + assert.isTrue(await waiting) + }) + + test('watches tables found through the search path', async ({ assert, cleanup }) => { + const schema = 'queue_search_path' + await connection.raw('create schema if not exists ??', [schema]) + cleanup(() => connection.raw('drop schema ?? cascade', [schema])) + // Tables only the search path finds, unlike those of the other tests. + const tables = { tableName: 'tenant_jobs', schedulesTableName: 'tenant_schedules' } + for (const [table, like] of [ + [tables.tableName, tableName], + [tables.schedulesTableName, schedulesTableName], + ]) { + await connection.raw('create table ?? (like ?? including all)', [`${schema}.${table}`, like]) + } + const tenant = Knex({ ...connection.client.config, searchPath: [schema] }) + cleanup(() => tenant.destroy()) + const options = { connection: tenant, ...tables, notifications: true } + + const watcher = await new KnexAdapter(options).watch!(['default']) + cleanup(() => watcher.close()) + watcher.reset() + const waiting = watcher.wait(2000, new AbortController().signal, 0) + + const job = { id: 'tenant-job', name: 'TestJob', payload: {}, attempts: 0 } + await new KnexAdapter(options).pushOn('default', job) + assert.isTrue(await waiting) + }) + test('does not wake again for a due schedule a concurrent claim holds', async ({ assert, cleanup, From b5b62b20bc72a9a5f0ba8e589b9ddd3e76d00b11 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 20:28:50 +0000 Subject: [PATCH 09/15] fix(knex): bound LISTEN startup and skip deduplicated signals A replacement LISTEN connection that stalled in its handshake or setup never failed: the heartbeat skips a connection until it listens, so the watcher stayed without notifications until the worker restarted, and closing it waited on a server that never answered. The whole startup of a LISTEN connection now has a deadline, after which the connection is dropped and the reconnection goes on. A connection that does not end gracefully is destroyed. A deduplicated dispatch signalled its attempted due time even when it added no job. That time could replace the real due time of another job in the same notification, and the wake found nothing to promote, so nothing announced the real one. Only added jobs signal now. --- src/drivers/knex_adapter.ts | 49 +++++++++++++++++++++++++++------- tests/adapter.spec.ts | 53 +++++++++++++++++++++++++++++++++++++ 2 files changed, 93 insertions(+), 9 deletions(-) diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 9b89fdc..8ff72a0 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -41,6 +41,7 @@ import { dispatchWakeMessage, encodeWakeMessage, startHeartbeat, + subscriptionHeartbeat, type WakeListener, type WakeMessage, } from './wake_messages.js' @@ -82,6 +83,8 @@ interface PgListenClient { ): void on(event: 'error' | 'end', listener: (error?: Error) => void): void removeAllListeners(): void + /** The socket of node-postgres, to destroy a connection that does not end. */ + connection?: { stream?: { destroy(): void } } } /** @@ -356,7 +359,13 @@ export class KnexAdapter implements Adapter { client = undefined if (!current) return current.removeAllListeners() + // A graceful end waits for the server, which a stalled connection never answers. + const timer = setTimeout( + () => current.connection?.stream?.destroy(), + subscriptionHeartbeat.timeout + ) await current.end().catch(() => {}) + clearTimeout(timer) } // A connection config provider is called again once its settings expire, @@ -470,14 +479,33 @@ export class KnexAdapter implements Adapter { onWake(at) }) }) - await Promise.race([connection.connect(), closing.promise]) - // Announcements read unqualified tables, as the pool does. - await knexClient.setSchemaSearchPath(connection) - await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) + const start = async () => { + await connection.connect() + // Announcements read unqualified tables, as the pool does. + await knexClient.setSchemaSearchPath(connection) + await connection.query(`LISTEN "${channel.replaceAll('"', '""')}"`) + if (closed) return + await verify() + listening = true + await announce(connection) + } + // A connection may stall before the heartbeat watches it: give up on + // it, so that the caller falls back to polling or reconnects. + let timer: NodeJS.Timeout | undefined + const stalled = new Promise((_resolve, reject) => { + timer = setTimeout( + () => reject(new Error('The LISTEN connection did not start in time')), + LISTEN_PROBE_TIMEOUT + subscriptionHeartbeat.timeout + ) + }) + const starting = start() + starting.catch(() => {}) + try { + await Promise.race([starting, stalled, closing.promise]) + } finally { + clearTimeout(timer) + } if (closed) return release() - await verify() - listening = true - await announce(connection) } const stopHeartbeat = startHeartbeat( () => (listening ? client?.query('select 1') : undefined), @@ -1000,7 +1028,8 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), score, }) - await this.#signal(queue) + // Other outcomes leave the existing job as it was. + if (result.outcome === 'added') await this.#signal(queue) return result } @@ -1025,7 +1054,9 @@ export class KnexAdapter implements Adapter { data: JSON.stringify(jobData), execute_at: executeAt, }) - await this.#signal(queue, executeAt) + // A due time no job has would wake watchers in vain, and could hide + // the one of another job signalled with it. + if (result.outcome === 'added') await this.#signal(queue, executeAt) return result } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index fd8fb01..21157b7 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -2910,6 +2910,59 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.isTrue(created[2].ended) }) + test('reconnects a LISTEN connection whose replacement stalls', async ({ assert, cleanup }) => { + shortenHeartbeat(cleanup) + // The first connection and its probe work, the next never completes its handshake. + const created = fakeListenClients(cleanup, (index) => + index === 3 ? { connect: () => new Promise(() => {}) } : 'real' + ) + const options = { connection, tableName, schedulesTableName, notifications: true } + const watcher = await new KnexAdapter({ ...options, logger: new MemoryLogger() }).watch!([ + 'default', + ]) + cleanup(() => watcher.close()) + created[0].emit('error', new Error('Connection terminated')) + + // The stalled connection is given up, and the next one listens. + const deadline = Date.now() + 8000 + while (created.length < 5 && Date.now() < deadline) { + await new Promise((resolve) => setTimeout(resolve, 50)) + } + assert.lengthOf(created, 5) + assert.isTrue(created[2].ended) + await new Promise((resolve) => setTimeout(resolve, 200)) + watcher.reset() + const waiting = watcher.wait(2000, new AbortController().signal, 0) + const job = { id: 'after-stall', name: 'TestJob', payload: {}, attempts: 0 } + await new KnexAdapter(options).pushOn('default', job) + assert.isTrue(await waiting) + }).timeout(10_000) + + test('signals no due time for a delayed job deduplicated away', async ({ assert, cleanup }) => { + const options = { connection, tableName, schedulesTableName, notifications: true } + const watcher = await new KnexAdapter(options).watch!(['default']) + cleanup(() => watcher.close()) + watcher.reset() + const start = Date.now() + const waiting = watcher.wait(2000, new AbortController().signal, 0) + + const writer = new KnexAdapter(options) + const job = (id: string, dedup?: { id: string }) => ({ + id, + name: 'TestJob', + payload: {}, + attempts: 0, + dedup, + }) + await writer.pushLaterOn('default', job('owner', { id: 'slot' }), 3000) + // Skipped: no job is due at 200ms. Its time would hide the next one. + await writer.pushLaterOn('default', job('duplicate', { id: 'slot' }), 200) + await writer.pushLaterOn('default', job('next'), 500) + + assert.isTrue(await waiting) + assert.isAtLeast(Date.now() - start, 450) + }) + test('signals jobs of a table whose name is too long for a channel', async ({ assert, cleanup, From 451ca66fa95e179209d09ee8a4630f78daa4603b Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 20:47:10 +0000 Subject: [PATCH 10/15] fix(knex): handle errors and stalls of the LISTEN probe client The probe client had no error listener: a connection failure while it waited for its notification emitted an unhandled error event and killed the process, instead of rejecting watch(). Its errors now reject the probe. The probe client also ended gracefully without a bound, so a connection stalled in its handshake kept its socket open and could hold the process at shutdown. It now ends like the LISTEN client: its socket is destroyed when end() does not settle in time. Both keep an error listener while they end. --- src/drivers/knex_adapter.ts | 32 +++++++++++++------ tests/adapter.spec.ts | 64 +++++++++++++++++++++++++++++++++---- 2 files changed, 80 insertions(+), 16 deletions(-) diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 8ff72a0..eb7ab99 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -96,6 +96,21 @@ function wakeChannelName(table: string): string { return `queue_jobs_${createHash('sha256').update(table).digest('hex').slice(0, 40)}` } +/** + * End a LISTEN or probe client. A graceful end waits for the server, which a + * stalled connection never answers: its socket is destroyed after a while. + */ +async function endListenClient(client: PgListenClient): Promise { + client.removeAllListeners() + client.on('error', () => {}) + const timer = setTimeout( + () => client.connection?.stream?.destroy(), + subscriptionHeartbeat.timeout + ) + await client.end().catch(() => {}) + clearTimeout(timer) +} + /** The message of a job of `queue` ready now, or due at `at`. */ function jobMessage(queue: string, at?: number): WakeMessage { return at === undefined ? { ready: [queue] } : { due: { [queue]: at } } @@ -358,14 +373,7 @@ export class KnexAdapter implements Adapter { const current = client client = undefined if (!current) return - current.removeAllListeners() - // A graceful end waits for the server, which a stalled connection never answers. - const timer = setTimeout( - () => current.connection?.stream?.destroy(), - subscriptionHeartbeat.timeout - ) - await current.end().catch(() => {}) - clearTimeout(timer) + await endListenClient(current) } // A connection config provider is called again once its settings expire, @@ -437,6 +445,10 @@ export class KnexAdapter implements Adapter { } const { received, payload } = probe const sender = await createClient() + // An error event without a listener would crash the process. + const failed = Promise.withResolvers() + failed.promise.catch(() => {}) + sender.on('error', (error) => failed.reject(error)) let timer: NodeJS.Timeout | undefined const timeout = new Promise((_resolve, reject) => { timer = setTimeout( @@ -458,11 +470,11 @@ export class KnexAdapter implements Adapter { })() exchange.catch(() => {}) try { - await Promise.race([exchange, timeout, closing.promise]) + await Promise.race([exchange, failed.promise, timeout, closing.promise]) } finally { clearTimeout(timer) probe = undefined - void sender.end().catch(() => {}) + void endListenClient(sender) } } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 21157b7..7db9647 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -2611,11 +2611,15 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { * client gets the behavior `behave` returns for its 1-based creation * number: 'real' for a working connection, or a fake one. */ + type FakeBehavior = { + connect?: () => Promise + query?: () => Promise + end?: () => Promise + } + function fakeListenClients( cleanup: (callback: () => void) => void, - behave: ( - index: number - ) => 'real' | { connect?: () => Promise; query?: () => Promise } + behave: (index: number) => 'real' | FakeBehavior ) { type PgClient = new (settings: unknown) => { end(): Promise @@ -2630,16 +2634,24 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { client.driver = driver }) - const created: Array<{ ended: boolean; emit: (event: string, error?: Error) => void }> = [] + const created: Array<{ + ended: boolean + destroyed?: boolean + emit: (event: string, error?: Error) => void + }> = [] const FakeClient = class { #listeners = new Map void>() - #behavior: { connect?: () => Promise; query?: () => Promise } + #behavior: FakeBehavior state = { ended: false, + destroyed: false, emit: (event: string, error?: Error) => this.#listeners.get(event)?.(error), } - constructor(behavior: { connect?: () => Promise; query?: () => Promise }) { + // As node-postgres: the socket, destroyed when end() does not settle. + connection = { stream: { destroy: () => (this.state.destroyed = true) } } + + constructor(behavior: FakeBehavior) { this.#behavior = behavior created.push(this.state) } @@ -2658,6 +2670,7 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { } async end() { this.state.ended = true + await this.#behavior.end?.() } } client.driver.Client = function (settings: unknown) { @@ -2693,6 +2706,45 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { await assert.rejects(() => watching.watch!(['default']), /do not enable notifications/) }).timeout(5000) + test('rejects a LISTEN probe whose connection fails', async ({ assert, cleanup }) => { + // The probe sends its notification, then its connection fails. + const created = fakeListenClients(cleanup, (index) => + index === 1 + ? 'real' + : { + async query() { + setTimeout(() => created[1].emit('error', new Error('Connection terminated')), 10) + }, + } + ) + const watching = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) + + await assert.rejects(() => watching.watch!(['default']), 'Connection terminated') + }) + + test('destroys a LISTEN probe connection that does not end', async ({ assert, cleanup }) => { + shortenHeartbeat(cleanup) + const never = () => new Promise(() => {}) + const created = fakeListenClients(cleanup, (index) => + index === 1 ? 'real' : { connect: never, end: never } + ) + const watching = new KnexAdapter({ + connection, + tableName, + schedulesTableName, + notifications: true, + }) + + await assert.rejects(() => watching.watch!(['default']), /do not enable notifications/) + await new Promise((resolve) => setTimeout(resolve, 400)) + assert.isTrue(created[1].destroyed) + }).timeout(5000) + test('aborts a first LISTEN connection still in its handshake', async ({ assert, cleanup }) => { const created = fakeListenClients(cleanup, () => ({ connect: () => new Promise(() => {}) })) const watching = new KnexAdapter({ From 1d758aae51a89191fd67df6ef6515b242266a08f Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 21:08:19 +0000 Subject: [PATCH 11/15] fix(knex): bound the connection settings lookup of LISTEN A LISTEN connection looked its settings up, through the async provider of Knex, before its startup deadline and abort handling applied. A lookup that stalled made aborting the watch wait for it, so stopping a worker hung, and a reconnection could stall forever. The lookup now runs within the bounded startup, and a client it returns once the attempt was given up stays unused. --- src/drivers/knex_adapter.ts | 31 +++++++++++++++++++------------ tests/adapter.spec.ts | 17 +++++++++++++++++ 2 files changed, 36 insertions(+), 12 deletions(-) diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index eb7ab99..3c55e71 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -479,19 +479,23 @@ export class KnexAdapter implements Adapter { } const connect = async () => { - const connection = await createClient() - client = connection - connection.on('error', onLost) - connection.on('end', () => onLost()) - connection.on('notification', (message) => { - if (message.channel !== channel || !message.payload) return - if (message.payload === probe?.payload) return probe.received.resolve() - dispatchWakeMessage(message.payload, queues, onWake, (at) => { - watcher.at = at - onWake(at) - }) - }) + // Set when the caller gave up on this attempt: a late client stays unused. + let abandoned = false const start = async () => { + // A connection config provider may look settings up: it may stall too. + const connection = await createClient() + if (abandoned) return + client = connection + connection.on('error', onLost) + connection.on('end', () => onLost()) + connection.on('notification', (message) => { + if (message.channel !== channel || !message.payload) return + if (message.payload === probe?.payload) return probe.received.resolve() + dispatchWakeMessage(message.payload, queues, onWake, (at) => { + watcher.at = at + onWake(at) + }) + }) await connection.connect() // Announcements read unqualified tables, as the pool does. await knexClient.setSchemaSearchPath(connection) @@ -514,6 +518,9 @@ export class KnexAdapter implements Adapter { starting.catch(() => {}) try { await Promise.race([starting, stalled, closing.promise]) + } catch (error) { + abandoned = true + throw error } finally { clearTimeout(timer) } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 7db9647..1307614 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -2745,6 +2745,23 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.isTrue(created[1].destroyed) }).timeout(5000) + test('aborts a watch whose connection settings lookup stalls', async ({ assert, cleanup }) => { + const stalled = Knex({ client: 'pg', connection: () => new Promise(() => {}) }) + cleanup(() => stalled.destroy()) + const watching = new KnexAdapter({ + connection: stalled, + tableName, + schedulesTableName, + notifications: true, + }) + const controller = new AbortController() + + const watcher = watching.watch!(['default'], controller.signal) + setTimeout(() => controller.abort(), 50) + + await assert.rejects(() => watcher) + }).timeout(2000) + test('aborts a first LISTEN connection still in its handshake', async ({ assert, cleanup }) => { const created = fakeListenClients(cleanup, () => ({ connect: () => new Promise(() => {}) })) const watching = new KnexAdapter({ From 15c34b6c1e7c374205b3d5efd80e403b7c56b9cb Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Mon, 19 Oct 2026 22:07:00 +0000 Subject: [PATCH 12/15] fix(redis): poll for a user that cannot run blocking commands A Redis user without the @blocking ACL category could watch, then every BZPOPMIN failed with NOPERM: the worker logged an error and retried every second, forever. watch() now probes BZPOPMIN in a MULTI, where it returns at once, so such a worker fails to watch and polls instead. --- src/drivers/redis_adapter.ts | 16 +++++++++++++--- tests/adapter.spec.ts | 29 +++++++++++++++++++++++++++++ 2 files changed, 42 insertions(+), 3 deletions(-) diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index 2da6d50..c261057 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -123,20 +123,30 @@ export class RedisAdapter implements Adapter { blocking.on('error', (error) => { this.#logger.error({ err: error }, 'Redis blocking connection error') }) - // A PING queued during a silent handshake never settles: abort rejects. + // A command queued during a silent handshake never settles: abort rejects. const aborted = Promise.withResolvers() aborted.promise.catch(() => {}) const abort = () => aborted.reject(signal!.reason) signal?.addEventListener('abort', abort, { once: true }) try { - await Promise.race([blocking.ping(), aborted.promise]) const seedKeys = queues.flatMap((queue) => { const keys = this.#getKeys(queue) return [keys.pending, keys.delayed, keys.marker] }) seedKeys.push(schedulesDueKey, schedulesMarkerKey) - await this.#connection.eval(SEED_MARKERS_SCRIPT, seedKeys.length, ...seedKeys) + // A user without the @blocking ACL category cannot wait: probe BZPOPMIN, + // so that such a worker polls instead. In MULTI, it returns at once. + const probe = blocking + .multi() + .bzpopmin(`${markers[0].key}::probe`, 0) + .exec() + .catch((error: { previousErrors?: Error[] }) => { + // EXECABORT tells nothing: the NOPERM error is the one to log. + throw error.previousErrors?.[0] ?? error + }) + const seed = this.#connection.eval(SEED_MARKERS_SCRIPT, seedKeys.length, ...seedKeys) + await Promise.race([Promise.all([probe, seed]), aborted.promise]) signal?.throwIfAborted() } catch (error) { blocking.disconnect() diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index 1307614..a5cb311 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -160,6 +160,35 @@ test.group('Adapter | Redis', (group) => { assert.isTrue(await waiting) }) + test('refuses to watch for an ACL user that cannot block', async ({ assert, cleanup }) => { + await connection.call( + 'ACL', + 'SETUSER', + 'queue-no-blocking', + 'on', + '>pw', + '~*', + '&*', + '+@all', + '-@blocking' + ) + const restricted = new Redis({ + host: process.env.REDIS_HOST || 'localhost', + port: Number.parseInt(process.env.REDIS_PORT || '6379', 10), + keyPrefix: KEY_PREFIX, + db: 15, + username: 'queue-no-blocking', + password: 'pw', + }) + cleanup(async () => { + restricted.disconnect() + await connection.call('ACL', 'DELUSER', 'queue-no-blocking') + }) + + // The worker polls instead of logging a failed wait every second. + await assert.rejects(() => new RedisAdapter(restricted).watch(['default']), /NOPERM/) + }) + test('wakes one waiting watcher per marker', async ({ assert, cleanup }) => { const writer = new RedisAdapter(connection) const job = (id: string) => ({ id, name: 'TestJob', payload: {}, attempts: 0 }) From 4b80e106e3a18b42b6608ac932b7ad493ef2b605 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Tue, 20 Oct 2026 05:19:41 +0000 Subject: [PATCH 13/15] docs: connections for PostgreSQL notifications and silent connections With notifications, each Worker holds 2 connections: a max_connections sized for 1 per Worker leaves dispatchers without any. A connection that goes silent is detected by the heartbeat within 15 s, and the stalled check finds work until then. --- README.md | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/README.md b/README.md index f2eb274..d9f6976 100644 --- a/README.md +++ b/README.md @@ -954,6 +954,8 @@ On Redis, an idle Worker does not poll: it waits on a marker with `BZPOPMIN`, as job is dispatched, or a delayed job, a retry, or a schedule becomes due. A dispatched job wakes one idle Worker, which wakes the next one while jobs remain. The Worker still checks its queues every `stalledInterval`, in case a wake was lost, and holds one more connection to wait for work. +A connection that goes silent is detected within 15 s; until then, the Worker finds work at its +stalled check. The process that dispatches a job wakes the Workers. A job dispatched by an older version of the package, or written to Redis without the Adapter, wakes none: the Worker finds it at its next @@ -964,7 +966,8 @@ they `LISTEN` for a `NOTIFY` instead, and a job dispatched in a transaction wake commits. Enable it on every process that dispatches jobs, not only on Workers. It suits a few Workers with a high `concurrency`: -- Each Worker holds one more connection. +- Each Worker holds one more connection: size `max_connections` for 2 connections per Worker, + or dispatchers may get none. - Every `NOTIFY` reaches every Worker. A Worker woken for a job another Worker took waits `idleDelay` before it looks again, so idle Workers never query more often than when polling. - It does not work behind a pooler in transaction mode, such as PgBouncer. From 0e2e77f829397d424bcb6c66b24afc6efb808bc5 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Tue, 20 Oct 2026 06:35:53 +0000 Subject: [PATCH 14/15] fix(knex): cache only the latest connection settings lookup of LISTEN A lookup abandoned at the startup deadline could answer after a later one had restored LISTEN, and overwrite its settings. The next reconnection then used stale credentials, and failed. Only the latest lookup updates the cached settings now. --- src/drivers/knex_adapter.ts | 12 ++++-- tests/adapter.spec.ts | 76 +++++++++++++++++++++++++++++++++++++ 2 files changed, 85 insertions(+), 3 deletions(-) diff --git a/src/drivers/knex_adapter.ts b/src/drivers/knex_adapter.ts index 3c55e71..3bef291 100644 --- a/src/drivers/knex_adapter.ts +++ b/src/drivers/knex_adapter.ts @@ -380,16 +380,22 @@ export class KnexAdapter implements Adapter { // as the pool of Knex does, for rotated credentials for instance. let providedSettings: object | undefined let settingsExpired: (() => boolean) | null = null + // Only the latest lookup is cached: an abandoned one may answer later. + let lookups = 0 const createClient = async (): Promise => { const provider = knexClient.connectionConfigProvider if (!provider) return new knexClient.driver.Client(knexClient.connectionSettings) + if (providedSettings && !settingsExpired?.()) { + return new knexClient.driver.Client(providedSettings) + } - if (!providedSettings || settingsExpired?.()) { - const { expirationChecker, ...settings } = await provider() + const lookup = ++lookups + const { expirationChecker, ...settings } = await provider() + if (lookup === lookups) { providedSettings = settings settingsExpired = expirationChecker ?? null } - return new knexClient.driver.Client(providedSettings) + return new knexClient.driver.Client(settings) } // Signals sent before listening, or while disconnected, are lost. The diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index a5cb311..d23b029 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -2958,6 +2958,82 @@ test.group('Adapter | Knex (PostgreSQL)', (group) => { assert.notEqual(second, first) }) + test('keeps the settings of the latest connection provider lookup', async ({ + assert, + cleanup, + }) => { + shortenHeartbeat(cleanup) + // A lookup gated here answers once a later one restored LISTEN. + let gate: PromiseWithResolvers | undefined + let expired = false + let provided = 0 + const provider = Knex({ + client: 'pg', + connection: async () => { + const name = gate ? 'listen-stale' : `listen-fresh-${++provided}` + const answered = gate?.promise + gate = undefined + await answered + return { + host: process.env.PG_HOST || 'localhost', + port: Number.parseInt(process.env.PG_PORT || '5432', 10), + user: process.env.PG_USER || 'postgres', + password: process.env.PG_PASSWORD || 'postgres', + database: process.env.PG_DATABASE || 'queue_test', + application_name: name, + expirationChecker: () => expired, + } + }, + }) + cleanup(() => provider.destroy()) + const listeners = async () => { + const result = await connection.raw( + `select application_name from pg_stat_activity where application_name like 'listen-%' and query not like '%pg_notify%'` + ) + return result.rows.map((row: { application_name: string }) => row.application_name) + } + const terminate = (name: string) => + connection.raw( + `select pg_terminate_backend(pid) from pg_stat_activity where application_name = ?`, + [name] + ) + const waitFor = async (name: string, timeout: number) => { + const deadline = Date.now() + timeout + while (Date.now() < deadline) { + const names = await listeners() + if (names.includes(name)) return names + await new Promise((resolve) => setTimeout(resolve, 50)) + } + return listeners() + } + + const watcher = await new KnexAdapter({ + connection: provider, + notifications: true, + tableName, + schedulesTableName, + logger: new MemoryLogger(), + }).watch!(['default']) + cleanup(() => watcher.close()) + + // The next lookup stalls past the startup deadline, the one after it works. + const stale = Promise.withResolvers() + gate = stale + expired = true + await terminate('listen-fresh-1') + assert.include(await waitFor('listen-fresh-2', 8000), 'listen-fresh-2') + expired = false + stale.resolve() + await new Promise((resolve) => setTimeout(resolve, 100)) + + // Reconnecting reuses the cached settings: those of a lookup after the stale one. + await terminate('listen-fresh-2') + await new Promise((resolve) => setTimeout(resolve, 1500)) + const names = await listeners() + assert.lengthOf(names, 1) + assert.match(names[0], /^listen-fresh-/) + }).timeout(15_000) + test('does not reconnect a LISTEN connection that failed to start', async ({ assert, cleanup, From 8c66561780c22ee5aa458fef7becb745ac92c5b7 Mon Sep 17 00:00:00 2001 From: Romain Lanz Date: Tue, 20 Oct 2026 06:35:54 +0000 Subject: [PATCH 15/15] fix(redis): bound the startup of the blocking connection ioredis drops a command sent before a reconnection, without settling it: the startup of watch() then waited forever, and the worker polled without logging why. Its startup now has a deadline, after which watch() fails and the worker polls. --- src/drivers/redis_adapter.ts | 9 ++++++++- tests/adapter.spec.ts | 17 +++++++++++++++++ 2 files changed, 25 insertions(+), 1 deletion(-) diff --git a/src/drivers/redis_adapter.ts b/src/drivers/redis_adapter.ts index c261057..4103a8f 100644 --- a/src/drivers/redis_adapter.ts +++ b/src/drivers/redis_adapter.ts @@ -12,6 +12,7 @@ import type { } from '../contracts/adapter.js' import { consoleLogger, type Logger } from '../logger.js' import { RedisWorkWatcher } from './redis_work_watcher.js' +import { subscriptionHeartbeat } from './wake_messages.js' import type { AdapterFactoryContext, DedupOutcome } from '../types/main.js' import type { JobData, @@ -123,11 +124,16 @@ export class RedisAdapter implements Adapter { blocking.on('error', (error) => { this.#logger.error({ err: error }, 'Redis blocking connection error') }) - // A command queued during a silent handshake never settles: abort rejects. + // A command queued during a silent handshake, or dropped on reconnection, + // never settles: abort and a deadline reject, so that the worker polls. const aborted = Promise.withResolvers() aborted.promise.catch(() => {}) const abort = () => aborted.reject(signal!.reason) signal?.addEventListener('abort', abort, { once: true }) + const deadline = setTimeout( + () => aborted.reject(new Error('The Redis blocking connection did not start in time')), + subscriptionHeartbeat.interval + ) try { const seedKeys = queues.flatMap((queue) => { @@ -152,6 +158,7 @@ export class RedisAdapter implements Adapter { blocking.disconnect() throw error } finally { + clearTimeout(deadline) signal?.removeEventListener('abort', abort) } diff --git a/tests/adapter.spec.ts b/tests/adapter.spec.ts index d23b029..28cba20 100644 --- a/tests/adapter.spec.ts +++ b/tests/adapter.spec.ts @@ -264,6 +264,23 @@ test.group('Adapter | Redis', (group) => { await assert.rejects(() => watching) }).timeout(2000) + test('gives up on a blocking connection that does not start', async ({ assert, cleanup }) => { + shortenHeartbeat(cleanup) + // Accepts connections and never answers, as a connection whose command was lost. + const blackhole = createServer(() => {}) + await new Promise((resolve) => blackhole.listen(0, '127.0.0.1', resolve)) + cleanup(() => void blackhole.close()) + const port = (blackhole.address() as AddressInfo).port + const direct = new Redis(connection.options) + direct.duplicate = (override?: Partial) => + new Redis({ ...connection.options, host: '127.0.0.1', port, ...override }) + cleanup(() => direct.disconnect()) + + // Without an abort, the worker falls back to polling. + const adapter = new RedisAdapter(direct, false, new MemoryLogger()) + await assert.rejects(() => adapter.watch(['default']), /did not start in time/) + }).timeout(2000) + test('reconnects a blocking connection that stops answering', async ({ assert, cleanup }) => { shortenHeartbeat(cleanup) const target = {