From 9fcc30df892a3dfc8a5ada64779e0612aa412483 Mon Sep 17 00:00:00 2001 From: mbhandary Date: Tue, 12 Nov 2019 12:42:00 -0500 Subject: [PATCH] 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. --- src/ripple/core/impl/JobQueue.cpp | 28 ++++++++++++++++++---------- 1 file changed, 18 insertions(+), 10 deletions(-) diff --git a/src/ripple/core/impl/JobQueue.cpp b/src/ripple/core/impl/JobQueue.cpp index 47767edae1..c418bc67a0 100644 --- a/src/ripple/core/impl/JobQueue.cpp +++ b/src/ripple/core/impl/JobQueue.cpp @@ -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( + 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( 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( + 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(Job::clock_type::now() - start_time)); - perfLog_.jobFinish(type, us, instance); - if (us >= 10ms) - getJobTypeData(type).execute.notify(us); + } {