[Feature request] A way to get the timestamp that a delayed job is supposed to run

[hyperair]

Is your feature request related to a problem? Please describe.

I'm trying to find out the real "runAt" timestamp of a job, for the following purposes:

1. Instrumenting job scheduling latency, i.e. the duration a job spends in waiting state, or how long after a job is supposed to run that it actually begins execution.
2. When inspecting queue state, perhaps through queue.getJobs('delayed'), I would like to be able to tell when a delayed job is supposed to run.

Describe the solution you'd like

A Job.runAt property that contains the timestamp that a job is supposed to run at, potentially stored on the job key in Redism so it would be part of the JobJsonRaw interface. This needs to match the timestamp that actually makes it to the job's score in the delayed set and stay accurate through all the job state transitions.

Describe alternatives you've considered
A clear and concise description of any alternative solutions or features you've considered.

Here's what I've tried so far:

• job.timestamp + job.delay -- doesn't really give any meaningful result once the job has sat around in redis for a while (why does it make sense to store delay on the job key in redis without actually storing the timestamp it was calculated from?)
  • job.delay is set to 0 when a job is promoted to waiting
  • job.delay is updated in moveToDelayed and changeDelay, but not job.timestamp, so we can't get the job runAt time from that
• job.timestamp + job.opts.delay -- works for some usecases, falls apart when job.changeDelay() or job.moveToDelayed() has happened at least once on the job, because job.opts.delay isn't updated by either of those calls.

At this point I'm considering just storing this timestamp as a special key on the job payload, but I think that solution's a bit of a hack.

[wenq1]

This is an extremely ancient issue. Never worked quite right from the beginning, and become worse since the addition of changeDelay.

Try this instead.

let score = await redisClient.zscore (queue_key, job_id)
let delay = parseFloat (score || '0) / 4096;

[chriscarpenter12]

Shouldn’t this be addressed by bull here since it’s choosing to store the delay as a millisecond value? Instead of resorting to fallback on the Redis client. I’m just a casual first time user of bullmq and the delay aspect is confusing to be honest. I guess I initially expected it to be stored as a date to run at or at least expose that back to the consumer.

[hyperair]

@wenq1 I'm aware of using the score of the job in the delayed zset (where queue_key = queue.key.delayed), but:

1. That doesn't solve my first usecase, which was to instrument how long a job spends in the waiting queue -- this can only be calculated when a job enters active state, but BullMQ resets the job's delay to 0 when the job is promoted from delayed to waiting, and since the job is no longer in the delayed zset, it has no score.
2. The way the runAt timestamp of the job gets turned into the job's score in the delayed queue is an internal implementation of BullMQ, not really part of the public API.

Additionally, your approach is incomplete/incorrect -- there isn't one specific queue_key, you need to use the queue's delayed key, and the runAt timestamp only forms the quotient part of the / 4096 result -- the remainder comes from a numeric jobId (ref):

let score = await redisClient.zscore(queue.keys.delayed, jobId);
let runAt = Math.floor(parseFloat(score || '0') / 0x1000);

[wenq1]

As I said yesterday, the design was never quite right from the very beginning. This is due to the waydelay is designed. First it was a simple indication of delayms when job was created. Later changeDelay was introduced, and issues on the delay not in sync was raised then fixed. However I don't think it is a proper fix considering changeDelay is somewhat a manual counterpart to the already existing moveToDelayed function, which as you have found out doesn't quite keep delay in sync.

So basically the design problem is that it much better to use a expect_to_run_at when changeDelay was introduced, rather than trying to retrofit and keep the delay prop in sync.

As for your question 1, I think if you want to additional information for instrumentation you need to store it somewhere else. In our use cases just do an ugly hack to job.stacktraces and put our custom and ugly informations there. That's the best bet for now.

As for your question 2, yes I agree with you that something like this score should be part of bull. However, before a PR is submitted your best bet is still the hack as mentioned.

[hyperair]

I guess there's a PR now 😀

[wenq1]

i guess there is one more pending PR now

[manast]

yes, I am sorry but I am a bit reluctant to increase the complexity so much for a quite small feature addition... complexity keeps adding up and then it is just more work for us long-time maintainers.

[hyperair]

yes, I am sorry but I am a bit reluctant to increase the complexity so much for a quite small feature addition... complexity keeps adding up and then it is just more work for us long-time maintainers.

@manast Would you be open to accepting the change if it also drops the delay job property as well, since it doesn't seem to be very useful and is in fact inaccurate most of the time? That should bring the complexity change to a nett-zero.

Alternatively, how about storing the timestamp of the last change to job.delay (so that we have a useful way of converting delay to an actual timestamp), or the timestamp when a job enters the waiting state?

[wenq1]

i think what @manast probably meant is just the addition of something like job.getDelayOnTheFly () is more acceptable at this time.

[hyperair]

@wenq1 Yes I know that, and since that doesn't solve usecase 1 from my first post for me, I was asking if there were any other acceptable approaches. And while I do appreciate you proposing the wild hack of abusing the job.stacktrace property, I'm also trying to avoid having to resort to that.

[wenq1]

What now?