Improve insight reporting of job queue timing:

Prior to this commit, the queue and execution times for individual jobs
were reported indepedently and could, potentially, be out of sync. This
change reports both values when either one of the exceeds the reporting
threshold.
This commit is contained in:
mbhandary
2019-11-12 12:42:00 -05:00
committed by Nik Bougalis
parent 1f5d9404d0
commit 9fcc30df89

View File

@@ -420,19 +420,27 @@ JobQueue::processTask (int instance)
}
type = job.getType();
JobTypeData& data(getJobTypeData(type));
JLOG(m_journal.trace()) << "Doing " << data.name () << " job";
auto const us = date::ceil<microseconds>(
JLOG(m_journal.trace()) << "Doing " << data.name () << "job";
//The amount of time that the job was in the queue
auto const q_time = date::ceil<microseconds>(
start_time - job.queue_time());
perfLog_.jobStart(type, us, start_time, instance);
if (us >= 10ms)
getJobTypeData(type).dequeue.notify(us);
perfLog_.jobStart(type, q_time, start_time, instance);
job.doJob ();
//The amount of time it took to execute the job
auto const x_time = date::ceil<microseconds>(
Job::clock_type::now() - start_time);
if (x_time >= 10ms || q_time >= 10ms)
{
getJobTypeData(type).dequeue.notify(q_time);
getJobTypeData(type).execute.notify(x_time);
}
perfLog_.jobFinish(type, x_time, instance);
}
auto const us (
date::ceil<microseconds>(Job::clock_type::now() - start_time));
perfLog_.jobFinish(type, us, instance);
if (us >= 10ms)
getJobTypeData(type).execute.notify(us);
}
{