BIND 10 #924: Additional debugging for IntervalTimer test failure

[BIND 10 Development]

#924: Additional debugging for IntervalTimer test failure
-------------------------------------+-------------------------------------
            Reporter:  shane         |                        Owner:  shane
                Type:  task          |                       Status:  new
            Priority:  major         |                    Milestone:
           Component:  Unclassified  |  Sprint-20110517
           Sensitive:  0             |                     Keywords:
         Sub-Project:  DNS           |              Defect Severity:  N/A
Estimated Difficulty:  1             |  Feature Depending on Ticket:
         Total Hours:  0             |          Add Hours to Ticket:  0
                                     |                    Internal?:  0
-------------------------------------+-------------------------------------
 http://bind10.isc.org/~tester/builder//BIND10/20110512185001-NetBSD5-amd64/logs/unittests.out

 This appears to be a "real" timer failure:

 [ RUN      ] IntervalTimerTest.overwriteIntervalTimer
 interval_timer_unittest.cc:295: Failure
 Value of: delta < TIMER_MARGIN_MSEC
   Actual: false
 Expected: true
 [  FAILED  ] IntervalTimerTest.overwriteIntervalTimer (640 ms)

 One thing is that we should change the test from this:

     EXPECT_TRUE(delta < TIMER_MARGIN_MSEC);

 To this:

     EXPECT_LT(delta, TIMER_MARGIN_MSEC);

 I think that would give us more information, like printing out the
 actual delta. Probably we should do this everywhere. Does that make some
 sense?

 Also, we could check for some clock skew, by replacing this:

     boost::posix_time::time_duration delta =
         (boost::posix_time::microsec_clock::universal_time() - start)
          - boost::posix_time::millisec(400 + 100);

 With this:

     boost::posix_time::time_duration test_runtime =
         (boost::posix_time::microsec_clock::universal_time() - start);
     EXPECT_GT(test_runtime, 0);

     boost::posix_time::time_duration delta =
         test_runtime - boost::posix_time::millisec(400 + 100);

 It won't catch cases where the clock jumps forward, but at least we can
 learn if the box has unstable time. (Note this may have nothing to do
 with this particular case... is this a virtual machine?)

-- 
Ticket URL: <http://bind10.isc.org/ticket/924>
BIND 10 Development <http://bind10.isc.org>
BIND 10 Development