Further improve the delay/overrun Timer warnings when both occur at once

git-svn-id: https://svn.apache.org/repos/asf/qpid/trunk/qpid@801858 13f79535-47bb-0310-9956-ffa450edef68

1 files changed, 14 insertions, 6 deletions

diff --git a/cpp/src/qpid/sys/Timer.cpp b/cpp/src/qpid/sys/Timer.cpp
index 4a3eef3a2d..67e0e688bb 100644
--- a/cpp/src/qpid/sys/Timer.cpp
+++ b/cpp/src/qpid/sys/Timer.cpp
@@ -99,12 +99,12 @@ void Timer::run()
 
             // warn on extreme lateness
             AbsTime start(AbsTime::now());
-            Duration late(t->sortTime, start);
+            Duration delay(t->sortTime, start);
             {
             ScopedLock<Mutex> l(t->callbackLock);
             if (t->cancelled) {
-                if (late > 500 * TIME_MSEC) {
-                    QPID_LOG(debug, "cancelled Timer woken up late by " << late / TIME_MSEC << "ms");
+                if (delay > 500 * TIME_MSEC) {
+                    QPID_LOG(debug, "cancelled Timer woken up " << delay / TIME_MSEC << "ms late");
                 }
                 continue;
             } else if(Duration(t->nextFireTime, start) >= 0) {
@@ -113,9 +113,17 @@ void Timer::run()
                 // Warn on callback overrun
                 AbsTime end(AbsTime::now());
                 Duration overrun(tasks.top()->nextFireTime, end);
-                if (late > 1 * TIME_MSEC) {
-                    QPID_LOG(warning, "Timer woken up late by " << late / TIME_MSEC << "ms");
-                } else if (overrun > 1 * TIME_MSEC) {
+                bool late = delay > 1 * TIME_MSEC;
+                bool overran = overrun > 1 * TIME_MSEC;
+                if (late)
+                if (overran) {
+                    QPID_LOG(warning,
+                        "Timer woken up " << delay / TIME_MSEC << "ms late, "
+                        "overrunning by " << overrun / TIME_MSEC << "ms [taking "
+                        << Duration(start, end) << "]");
+                } else {
+                    QPID_LOG(warning, "Timer woken up " << delay / TIME_MSEC << "ms late");
+                } else if (overran) {
                     QPID_LOG(warning,
                         "Timer callback overran by " << overrun / TIME_MSEC << "ms [taking "
                         << Duration(start, end) << "]");