Add duration property to completed jobs

[adamreisnz]

It would be nice if jobs would track how long they took to execute. If they already do, that's great, but it wasn't obvious from the docs or the properties on the job object how they do that.

Suggestion:

//Track high res start time
const startTime = process.hrtime();

//Run job handler
//...do stuff...

//Track high res end time
const endTime = process.hrtime();

//Get duration in MS
const ms = (end[0] - start[0]) * 1e3 + (end[1] - start[1]) * 1e-6;

//Store on completed job
job.duration = ms;

Currently doing this manually, but it would be nice if this was implemented in bullmq internally.

[manast]

You have properties on the Job class for all this:
https://github.com/taskforcesh/bullmq/blob/master/docs/gitbook/api/bullmq.job.md
I will add more documentation though.

[manast]

done 86e663b

[adamreisnz]

Thanks, this helps, but is still not what we are after.

I think the timestamp is a Date.now() capture, which does not have enough resolution to measure very quick tasks. Hence the suggestion to use hrtime.

And can you please clarify further, what is the difference between "timetamp when the job was processed" and "timestamp when the job was completed"? What does the life cycle look like? When is a job processed vs completed?
And why is it possible to manipulate the start timestamp of a job? What use case exists for that?

I think for now, we will still manually track the duration of the job as it seems more reliable and precise, and captures the actual execution time of the task.

      //Run through handler
      const startTime = process.hrtime();
      const returnValue = await handler(job.data, job.logger);
      const endTime = process.hrtime();

      //Store job duration
      job.duration = hrDuration(startTime, endTime);

[manast]

Using hrtime would be an improvement but it is a breaking change. Maybe the problem is the wording here, onProcessed is the timestamp when the job starts to be processed. onCompleted - onProcessed = processing time.

[manast]

but of course we could add a new sets of properties ending in hr for the high resolution version like onProcessedHr, etc.

[adamreisnz]

Yes that would be great. Personally I would also rename the properties to be a bit clearer, as it's quite confusing if you don't know BullMQ well. E.g. startedOn, completedOn is clear just from reading it, whereas processedOn could be interpreted in different ways. I realise this would be a breaking change though.

[Lp-Francois]

Hello! Just to add that I support this change, the current wording is confusing, and a property duration would make sense as an helper :)
Are there any plans of adding this to a new future major release?