2021-04-29 23:02:27 +00:00
|
|
|
// Copyright 2021 Signal Messenger, LLC
|
|
|
|
// SPDX-License-Identifier: AGPL-3.0-only
|
|
|
|
|
2021-09-07 20:39:14 +00:00
|
|
|
import PQueue from 'p-queue';
|
2021-04-29 23:02:27 +00:00
|
|
|
import { v4 as uuid } from 'uuid';
|
|
|
|
import { noop } from 'lodash';
|
|
|
|
|
|
|
|
import { Job } from './Job';
|
|
|
|
import { JobError } from './JobError';
|
2021-10-26 19:15:33 +00:00
|
|
|
import type { ParsedJob, StoredJob, JobQueueStore } from './types';
|
2022-09-15 19:17:15 +00:00
|
|
|
import { assertDev } from '../util/assert';
|
2021-04-29 23:02:27 +00:00
|
|
|
import * as log from '../logging/log';
|
2021-08-17 15:43:26 +00:00
|
|
|
import { JobLogger } from './JobLogger';
|
2021-08-25 23:58:33 +00:00
|
|
|
import * as Errors from '../types/errors';
|
2021-09-17 18:27:53 +00:00
|
|
|
import type { LoggerType } from '../types/Logging';
|
2023-10-28 00:14:35 +00:00
|
|
|
import { drop } from '../util/drop';
|
2021-04-29 23:02:27 +00:00
|
|
|
|
|
|
|
const noopOnCompleteCallbacks = {
|
|
|
|
resolve: noop,
|
|
|
|
reject: noop,
|
|
|
|
};
|
|
|
|
|
2021-07-21 21:10:08 +00:00
|
|
|
type JobQueueOptions = {
|
2021-04-29 23:02:27 +00:00
|
|
|
/**
|
|
|
|
* The backing store for jobs. Typically a wrapper around the database.
|
|
|
|
*/
|
|
|
|
store: JobQueueStore;
|
|
|
|
|
|
|
|
/**
|
|
|
|
* A unique name for this job queue. For example, might be "attachment downloads" or
|
|
|
|
* "message send".
|
|
|
|
*/
|
|
|
|
queueType: string;
|
|
|
|
|
|
|
|
/**
|
|
|
|
* The maximum number of attempts for a job in this queue. A value of 1 will not allow
|
|
|
|
* the job to fail; a value of 2 will allow the job to fail once; etc.
|
|
|
|
*/
|
|
|
|
maxAttempts: number;
|
2021-08-17 15:43:26 +00:00
|
|
|
|
|
|
|
/**
|
|
|
|
* A custom logger. Might be overwritten in test.
|
|
|
|
*/
|
2021-09-17 18:27:53 +00:00
|
|
|
logger?: LoggerType;
|
2021-04-29 23:02:27 +00:00
|
|
|
};
|
|
|
|
|
2023-10-28 00:14:35 +00:00
|
|
|
export enum JOB_STATUS {
|
|
|
|
SUCCESS = 'SUCCESS',
|
|
|
|
NEEDS_RETRY = 'NEEDS_RETRY',
|
|
|
|
ERROR = 'ERROR',
|
|
|
|
}
|
|
|
|
|
2021-07-21 21:10:08 +00:00
|
|
|
export abstract class JobQueue<T> {
|
2021-04-29 23:02:27 +00:00
|
|
|
private readonly maxAttempts: number;
|
|
|
|
|
|
|
|
private readonly queueType: string;
|
|
|
|
|
|
|
|
private readonly store: JobQueueStore;
|
|
|
|
|
2021-09-17 18:27:53 +00:00
|
|
|
private readonly logger: LoggerType;
|
2021-08-17 15:43:26 +00:00
|
|
|
|
2021-04-29 23:02:27 +00:00
|
|
|
private readonly logPrefix: string;
|
|
|
|
|
2023-02-24 19:03:17 +00:00
|
|
|
private shuttingDown = false;
|
|
|
|
|
2021-04-29 23:02:27 +00:00
|
|
|
private readonly onCompleteCallbacks = new Map<
|
|
|
|
string,
|
|
|
|
{
|
|
|
|
resolve: () => void;
|
|
|
|
reject: (err: unknown) => void;
|
|
|
|
}
|
|
|
|
>();
|
|
|
|
|
2022-07-21 02:40:53 +00:00
|
|
|
private readonly defaultInMemoryQueue = new PQueue({ concurrency: 1 });
|
2021-09-07 20:39:14 +00:00
|
|
|
|
2021-04-29 23:02:27 +00:00
|
|
|
private started = false;
|
|
|
|
|
2023-02-24 19:03:17 +00:00
|
|
|
get isShuttingDown(): boolean {
|
|
|
|
return this.shuttingDown;
|
|
|
|
}
|
|
|
|
|
2021-07-21 21:10:08 +00:00
|
|
|
constructor(options: Readonly<JobQueueOptions>) {
|
2022-09-15 19:17:15 +00:00
|
|
|
assertDev(
|
2021-04-29 23:02:27 +00:00
|
|
|
Number.isInteger(options.maxAttempts) && options.maxAttempts >= 1,
|
|
|
|
'maxAttempts should be a positive integer'
|
|
|
|
);
|
2022-09-15 19:17:15 +00:00
|
|
|
assertDev(
|
2021-04-29 23:02:27 +00:00
|
|
|
options.maxAttempts <= Number.MAX_SAFE_INTEGER,
|
|
|
|
'maxAttempts is too large'
|
|
|
|
);
|
2022-09-15 19:17:15 +00:00
|
|
|
assertDev(
|
2021-04-29 23:02:27 +00:00
|
|
|
options.queueType.trim().length,
|
|
|
|
'queueType should be a non-blank string'
|
|
|
|
);
|
|
|
|
|
|
|
|
this.maxAttempts = options.maxAttempts;
|
|
|
|
this.queueType = options.queueType;
|
|
|
|
this.store = options.store;
|
2021-08-17 15:43:26 +00:00
|
|
|
this.logger = options.logger ?? log;
|
2021-04-29 23:02:27 +00:00
|
|
|
|
|
|
|
this.logPrefix = `${this.queueType} job queue:`;
|
|
|
|
}
|
|
|
|
|
2021-07-21 21:10:08 +00:00
|
|
|
/**
|
|
|
|
* `parseData` will be called with the raw data from `store`. For example, if the job
|
|
|
|
* takes a single number, `parseData` should throw if `data` is a number and should
|
|
|
|
* return the number otherwise.
|
|
|
|
*
|
2022-05-05 18:55:15 +00:00
|
|
|
* If it throws, the job will be deleted from the database and the job will not be run.
|
2021-07-21 21:10:08 +00:00
|
|
|
*
|
|
|
|
* Will only be called once per job, even if `maxAttempts > 1`.
|
|
|
|
*/
|
|
|
|
protected abstract parseData(data: unknown): T;
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Run the job, given data.
|
|
|
|
*
|
|
|
|
* If it resolves, the job will be deleted from the store.
|
|
|
|
*
|
|
|
|
* If it rejects, the job will be retried up to `maxAttempts - 1` times, after which it
|
|
|
|
* will be deleted from the store.
|
2021-08-17 15:43:26 +00:00
|
|
|
*
|
|
|
|
* If your job logs things, you're encouraged to use the logger provided, as it
|
|
|
|
* automatically includes debugging information.
|
2021-07-21 21:10:08 +00:00
|
|
|
*/
|
2021-07-23 22:02:36 +00:00
|
|
|
protected abstract run(
|
|
|
|
job: Readonly<ParsedJob<T>>,
|
2021-09-17 18:27:53 +00:00
|
|
|
extra?: Readonly<{ attempt?: number; log?: LoggerType }>
|
2023-10-28 00:14:35 +00:00
|
|
|
): Promise<JOB_STATUS.NEEDS_RETRY | undefined>;
|
2021-07-21 21:10:08 +00:00
|
|
|
|
2023-02-24 19:03:17 +00:00
|
|
|
protected getQueues(): ReadonlySet<PQueue> {
|
|
|
|
return new Set([this.defaultInMemoryQueue]);
|
|
|
|
}
|
|
|
|
|
2021-04-29 23:02:27 +00:00
|
|
|
/**
|
|
|
|
* Start streaming jobs from the store.
|
|
|
|
*/
|
|
|
|
async streamJobs(): Promise<void> {
|
|
|
|
if (this.started) {
|
|
|
|
throw new Error(
|
|
|
|
`${this.logPrefix} should not start streaming more than once`
|
|
|
|
);
|
|
|
|
}
|
|
|
|
this.started = true;
|
|
|
|
|
|
|
|
log.info(`${this.logPrefix} starting to stream jobs`);
|
|
|
|
|
|
|
|
const stream = this.store.stream(this.queueType);
|
|
|
|
for await (const storedJob of stream) {
|
2023-02-24 19:03:17 +00:00
|
|
|
if (this.shuttingDown) {
|
|
|
|
log.info(`${this.logPrefix} is shutting down. Can't accept more work.`);
|
|
|
|
break;
|
|
|
|
}
|
2023-10-28 00:14:35 +00:00
|
|
|
drop(this.enqueueStoredJob(storedJob));
|
2021-04-29 23:02:27 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
/**
|
|
|
|
* Add a job, which should cause it to be enqueued and run.
|
|
|
|
*
|
2021-08-27 20:20:16 +00:00
|
|
|
* If `streamJobs` has not been called yet, this will throw an error.
|
2021-10-29 23:19:44 +00:00
|
|
|
*
|
|
|
|
* You can override `insert` to change the way the job is added to the database. This is
|
|
|
|
* useful if you're trying to save a message and a job in the same database transaction.
|
2021-04-29 23:02:27 +00:00
|
|
|
*/
|
2021-10-29 23:19:44 +00:00
|
|
|
async add(
|
|
|
|
data: Readonly<T>,
|
|
|
|
insert?: (job: ParsedJob<T>) => Promise<void>
|
|
|
|
): Promise<Job<T>> {
|
2024-01-11 00:09:54 +00:00
|
|
|
const job = this.createJob(data);
|
|
|
|
|
2021-04-29 23:02:27 +00:00
|
|
|
if (!this.started) {
|
2024-01-11 00:09:54 +00:00
|
|
|
log.warn(
|
|
|
|
`${this.logPrefix} This queue has not started streaming, adding job ${job.id} to database only.`
|
2021-04-29 23:02:27 +00:00
|
|
|
);
|
|
|
|
}
|
2021-10-29 23:19:44 +00:00
|
|
|
|
|
|
|
if (insert) {
|
|
|
|
await insert(job);
|
|
|
|
}
|
|
|
|
await this.store.insert(job, { shouldPersist: !insert });
|
|
|
|
|
|
|
|
log.info(`${this.logPrefix} added new job ${job.id}`);
|
|
|
|
return job;
|
2021-08-31 20:58:39 +00:00
|
|
|
}
|
2021-04-29 23:02:27 +00:00
|
|
|
|
2021-08-31 20:58:39 +00:00
|
|
|
protected createJob(data: Readonly<T>): Job<T> {
|
2021-04-29 23:02:27 +00:00
|
|
|
const id = uuid();
|
|
|
|
const timestamp = Date.now();
|
|
|
|
|
|
|
|
const completionPromise = new Promise<void>((resolve, reject) => {
|
|
|
|
this.onCompleteCallbacks.set(id, { resolve, reject });
|
|
|
|
});
|
|
|
|
const completion = (async () => {
|
|
|
|
try {
|
|
|
|
await completionPromise;
|
|
|
|
} catch (err: unknown) {
|
|
|
|
throw new JobError(err);
|
|
|
|
} finally {
|
|
|
|
this.onCompleteCallbacks.delete(id);
|
|
|
|
}
|
|
|
|
})();
|
|
|
|
|
2021-08-31 20:58:39 +00:00
|
|
|
return new Job(id, timestamp, this.queueType, data, completion);
|
2021-04-29 23:02:27 +00:00
|
|
|
}
|
|
|
|
|
2021-09-07 20:39:14 +00:00
|
|
|
protected getInMemoryQueue(_parsedJob: ParsedJob<T>): PQueue {
|
|
|
|
return this.defaultInMemoryQueue;
|
|
|
|
}
|
|
|
|
|
2023-10-28 00:14:35 +00:00
|
|
|
protected async enqueueStoredJob(
|
|
|
|
storedJob: Readonly<StoredJob>
|
|
|
|
): Promise<void> {
|
2022-09-15 19:17:15 +00:00
|
|
|
assertDev(
|
2021-04-29 23:02:27 +00:00
|
|
|
storedJob.queueType === this.queueType,
|
|
|
|
'Received a mis-matched queue type'
|
|
|
|
);
|
|
|
|
|
|
|
|
log.info(`${this.logPrefix} enqueuing job ${storedJob.id}`);
|
|
|
|
|
|
|
|
// It's okay if we don't have a callback; that likely means the job was created before
|
|
|
|
// the process was started (e.g., from a previous run).
|
|
|
|
const { resolve, reject } =
|
|
|
|
this.onCompleteCallbacks.get(storedJob.id) || noopOnCompleteCallbacks;
|
|
|
|
|
|
|
|
let parsedData: T;
|
|
|
|
try {
|
|
|
|
parsedData = this.parseData(storedJob.data);
|
|
|
|
} catch (err) {
|
|
|
|
log.error(
|
2022-05-05 18:55:15 +00:00
|
|
|
`${this.logPrefix} failed to parse data for job ${storedJob.id}, created ${storedJob.timestamp}. Deleting job. Parse error:`,
|
2022-03-24 21:28:56 +00:00
|
|
|
Errors.toLogFormat(err)
|
2021-04-29 23:02:27 +00:00
|
|
|
);
|
2022-05-05 18:55:15 +00:00
|
|
|
await this.store.delete(storedJob.id);
|
2021-04-29 23:02:27 +00:00
|
|
|
reject(
|
|
|
|
new Error(
|
|
|
|
'Failed to parse job data. Was unexpected data loaded from the database?'
|
|
|
|
)
|
|
|
|
);
|
|
|
|
return;
|
|
|
|
}
|
|
|
|
|
|
|
|
const parsedJob: ParsedJob<T> = {
|
|
|
|
...storedJob,
|
|
|
|
data: parsedData,
|
|
|
|
};
|
|
|
|
|
2021-09-07 20:39:14 +00:00
|
|
|
const queue: PQueue = this.getInMemoryQueue(parsedJob);
|
|
|
|
|
2021-08-17 15:43:26 +00:00
|
|
|
const logger = new JobLogger(parsedJob, this.logger);
|
|
|
|
|
2021-09-07 20:39:14 +00:00
|
|
|
const result:
|
2021-04-29 23:02:27 +00:00
|
|
|
| undefined
|
2023-10-28 00:14:35 +00:00
|
|
|
| { status: JOB_STATUS.SUCCESS }
|
|
|
|
| { status: JOB_STATUS.NEEDS_RETRY }
|
|
|
|
| { status: JOB_STATUS.ERROR; err: unknown } = await queue.add(
|
|
|
|
async () => {
|
|
|
|
for (let attempt = 1; attempt <= this.maxAttempts; attempt += 1) {
|
|
|
|
const isFinalAttempt = attempt === this.maxAttempts;
|
2021-08-17 15:43:26 +00:00
|
|
|
|
2023-10-28 00:14:35 +00:00
|
|
|
logger.attempt = attempt;
|
2023-03-16 20:17:35 +00:00
|
|
|
|
2021-09-07 20:39:14 +00:00
|
|
|
log.info(
|
2023-10-28 00:14:35 +00:00
|
|
|
`${this.logPrefix} running job ${storedJob.id}, attempt ${attempt} of ${this.maxAttempts}`
|
2021-09-07 20:39:14 +00:00
|
|
|
);
|
2023-10-28 00:14:35 +00:00
|
|
|
|
|
|
|
if (this.isShuttingDown) {
|
|
|
|
log.warn(
|
|
|
|
`${this.logPrefix} returning early for job ${storedJob.id}; shutting down`
|
|
|
|
);
|
|
|
|
return {
|
|
|
|
status: JOB_STATUS.ERROR,
|
|
|
|
err: new Error('Shutting down'),
|
|
|
|
};
|
|
|
|
}
|
|
|
|
|
|
|
|
try {
|
|
|
|
// We want an `await` in the loop, as we don't want a single job running more
|
|
|
|
// than once at a time. Ideally, the job will succeed on the first attempt.
|
|
|
|
// eslint-disable-next-line no-await-in-loop
|
|
|
|
const jobStatus = await this.run(parsedJob, {
|
|
|
|
attempt,
|
|
|
|
log: logger,
|
|
|
|
});
|
|
|
|
if (!jobStatus) {
|
|
|
|
log.info(
|
|
|
|
`${this.logPrefix} job ${storedJob.id} succeeded on attempt ${attempt}`
|
|
|
|
);
|
|
|
|
return { status: JOB_STATUS.SUCCESS };
|
|
|
|
}
|
|
|
|
log.info(
|
|
|
|
`${this.logPrefix} job ${storedJob.id} returned status ${jobStatus} on attempt ${attempt}`
|
|
|
|
);
|
|
|
|
return { status: jobStatus };
|
|
|
|
} catch (err: unknown) {
|
|
|
|
log.error(
|
|
|
|
`${this.logPrefix} job ${
|
|
|
|
storedJob.id
|
|
|
|
} failed on attempt ${attempt}. ${Errors.toLogFormat(err)}`
|
|
|
|
);
|
|
|
|
if (isFinalAttempt) {
|
|
|
|
return { status: JOB_STATUS.ERROR, err };
|
|
|
|
}
|
2021-09-07 20:39:14 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2023-10-28 00:14:35 +00:00
|
|
|
// This should never happen. See the assertion below.
|
|
|
|
return undefined;
|
|
|
|
}
|
|
|
|
);
|
2021-04-29 23:02:27 +00:00
|
|
|
|
2023-10-28 00:14:35 +00:00
|
|
|
if (result?.status === JOB_STATUS.NEEDS_RETRY) {
|
|
|
|
const addJobSuccess = await this.retryJobOnQueueIdle({
|
|
|
|
storedJob,
|
|
|
|
job: parsedJob,
|
|
|
|
logger,
|
|
|
|
});
|
|
|
|
if (!addJobSuccess) {
|
|
|
|
await this.store.delete(storedJob.id);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
if (
|
|
|
|
result?.status === JOB_STATUS.SUCCESS ||
|
|
|
|
(result?.status === JOB_STATUS.ERROR && !this.isShuttingDown)
|
|
|
|
) {
|
2023-03-16 20:17:35 +00:00
|
|
|
await this.store.delete(storedJob.id);
|
|
|
|
}
|
2021-04-29 23:02:27 +00:00
|
|
|
|
2022-09-15 19:17:15 +00:00
|
|
|
assertDev(
|
2021-04-29 23:02:27 +00:00
|
|
|
result,
|
|
|
|
'The job never ran. This indicates a developer error in the job queue'
|
|
|
|
);
|
2023-10-28 00:14:35 +00:00
|
|
|
if (result.status === JOB_STATUS.ERROR) {
|
2021-04-29 23:02:27 +00:00
|
|
|
reject(result.err);
|
2023-10-28 00:14:35 +00:00
|
|
|
} else {
|
|
|
|
resolve();
|
2021-04-29 23:02:27 +00:00
|
|
|
}
|
|
|
|
}
|
2023-02-24 19:03:17 +00:00
|
|
|
|
2023-10-28 00:14:35 +00:00
|
|
|
async retryJobOnQueueIdle({
|
|
|
|
logger,
|
|
|
|
}: {
|
|
|
|
job: Readonly<ParsedJob<T>>;
|
|
|
|
storedJob: Readonly<StoredJob>;
|
|
|
|
logger: LoggerType;
|
|
|
|
}): Promise<boolean> {
|
|
|
|
logger.error(
|
|
|
|
`retryJobOnQueueIdle: not implemented for queue ${this.queueType}; dropping job`
|
|
|
|
);
|
|
|
|
return false;
|
|
|
|
}
|
|
|
|
|
2023-02-24 19:03:17 +00:00
|
|
|
async shutdown(): Promise<void> {
|
|
|
|
const queues = this.getQueues();
|
|
|
|
log.info(
|
|
|
|
`${this.logPrefix} shutdown: stop accepting new work and drain ${queues.size} promise queues`
|
|
|
|
);
|
|
|
|
this.shuttingDown = true;
|
|
|
|
await Promise.all([...queues].map(q => q.onIdle()));
|
|
|
|
log.info(`${this.logPrefix} shutdown: complete`);
|
|
|
|
}
|
2021-04-29 23:02:27 +00:00
|
|
|
}
|