Uploaded image for project: 'Kudu'
  1. Kudu
  2. KUDU-2550

HybridClockTest.TestRideOverNtpInterruption is flaky

    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Major
    • Resolution: Cannot Reproduce
    • 1.8.0
    • NA
    • test
    • None

    Description

      Seen this fail in precommit (TSAN) from time to time, though it's not in the flaky test dashboard:

      /home/jenkins-slave/workspace/kudu-master/3/src/kudu/clock/hybrid_clock-test.cc:342
      The difference between error_diff and clock_->time_service()->skew_ppm() * phys_diff.ToSeconds() is 14.90199999999993, which exceeds 10, where
      error_diff evaluates to 515,
      clock_->time_service()->skew_ppm() * phys_diff.ToSeconds() evaluates to 500.09800000000007, and
      10 evaluates to 10.
      

      The full log is short enough that I've inlined it:

      [==========] Running 11 tests from 2 test cases.
      [----------] Global test environment set-up.
      [----------] 2 tests from MockHybridClockTest
      [ RUN      ] MockHybridClockTest.TestMockedSystemClock
      [       OK ] MockHybridClockTest.TestMockedSystemClock (2 ms)
      [ RUN      ] MockHybridClockTest.TestClockDealsWithWrapping
      [       OK ] MockHybridClockTest.TestClockDealsWithWrapping (45 ms)
      [----------] 2 tests from MockHybridClockTest (48 ms total)
      
      [----------] 9 tests from HybridClockTest
      [ RUN      ] HybridClockTest.TestNow_ValuesIncreaseMonotonically
      WARNING: Logging before InitGoogleLogging() is written to STDERR
      I0824 00:47:19.490185 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10040us
      [       OK ] HybridClockTest.TestNow_ValuesIncreaseMonotonically (4 ms)
      [ RUN      ] HybridClockTest.TestUpdate_LogicalValueIncreasesByAmount
      I0824 00:47:19.492187 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10040us
      [       OK ] HybridClockTest.TestUpdate_LogicalValueIncreasesByAmount (2 ms)
      [ RUN      ] HybridClockTest.TestWaitUntilAfter_TestCase1
      I0824 00:47:19.494038 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10040us
      [       OK ] HybridClockTest.TestWaitUntilAfter_TestCase1 (1 ms)
      [ RUN      ] HybridClockTest.TestWaitUntilAfter_TestCase2
      I0824 00:47:19.495712 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10040us
      [       OK ] HybridClockTest.TestWaitUntilAfter_TestCase2 (21 ms)
      [ RUN      ] HybridClockTest.TestIsAfter
      I0824 00:47:19.517642 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10040us
      [       OK ] HybridClockTest.TestIsAfter (2 ms)
      [ RUN      ] HybridClockTest.TestClockDoesntGoBackwardsWithUpdates
      I0824 00:47:19.519358 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10040us
      [       OK ] HybridClockTest.TestClockDoesntGoBackwardsWithUpdates (1402 ms)
      [ RUN      ] HybridClockTest.TestGetPhysicalComponentDifference
      I0824 00:47:20.921936 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10540us
      [       OK ] HybridClockTest.TestGetPhysicalComponentDifference (3 ms)
      [ RUN      ] HybridClockTest.TestRideOverNtpInterruption
      I0824 00:47:20.924839 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 10540us
      E0824 00:47:21.925367 11521 hybrid_clock.cc:396] Unable to read clock for last 1.000s: Service unavailable: Error reading clock. Clock considered unsynchronized
      /home/jenkins-slave/workspace/kudu-master/3/src/kudu/clock/hybrid_clock-test.cc:342: Failure
      The difference between error_diff and clock_->time_service()->skew_ppm() * phys_diff.ToSeconds() is 14.90199999999993, which exceeds 10, where
      error_diff evaluates to 515,
      clock_->time_service()->skew_ppm() * phys_diff.ToSeconds() evaluates to 500.09800000000007, and
      10 evaluates to 10.
      I0824 00:47:21.926945 11521 test_util.cc:131] -----------------------------------------------
      I0824 00:47:21.927068 11521 test_util.cc:132] Had fatal failures, leaving test files at /tmp/dist-test-taskfm5ShG/test-tmp/hybrid_clock-test.0.HybridClockTest.TestRideOverNtpInterruption.1535071639431431-11521
      [  FAILED  ] HybridClockTest.TestRideOverNtpInterruption (1003 ms)
      [ RUN      ] HybridClockTest.TestNtpDiagnostics
      I0824 00:47:21.928170 11521 system_ntp.cc:199] NTP initialized. Skew: 500ppm Current error: 11040us
      [       OK ] HybridClockTest.TestNtpDiagnostics (48 ms)
      [----------] 9 tests from HybridClockTest (2488 ms total)
      
      [----------] Global test environment tear-down
      [==========] 11 tests from 2 test cases ran. (2536 ms total)
      [  PASSED  ] 10 tests.
      [  FAILED  ] 1 test, listed below:
      [  FAILED  ] HybridClockTest.TestRideOverNtpInterruption
      
       1 FAILED TEST
      

      Attachments

        Activity

          People

            Unassigned Unassigned
            adar Adar Dembo
            Votes:
            0 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

              Created:
              Updated:
              Resolved: