Derby
  1. Derby
  2. DERBY-5964

Timestamp comparison failure in AutomaticIndexStatisticsTest.testStatisticsCorrectness

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: 10.10.1.1
    • Fix Version/s: 10.8.3.3, 10.9.2.2, 10.10.1.1
    • Component/s: Test
    • Labels:
      None

      Description

      http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.5/testing/testlog/lin/1402814-suitesAll_diff.txt

      1) testStatisticsCorrectness(org.apache.derbyTesting.functionTests.tests.store.AutomaticIndexStatisticsTest)junit.framework.AssertionFailedError
      at org.apache.derbyTesting.functionTests.tests.store.AutomaticIndexStatisticsTest.testStatisticsCorrectness(AutomaticIndexStatisticsTest.java:324)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:117)
      at org.apache.derbyTesting.junit.BaseJDBCTestCase.runBareOverridable(BaseJDBCTestCase.java:424)
      at org.apache.derbyTesting.junit.BaseJDBCTestCase.runBare(BaseJDBCTestCase.java:441)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
      at junit.extensions.TestSetup.run(TestSetup.java:25)
      at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
      at junit.extensions.TestSetup.run(TestSetup.java:25)

      The failure is caused by this assert:

      assertTrue(s.created.before(now));

      It might be a coincidence, but it happened the same night as Europe was switching from DST.

      It may also be related to DERBY-5046, where a similar assert failed because poor clock resolution made the two timestamps equal.

      1. d5964-1a-run-in-gmt.diff
        2 kB
        Knut Anders Hatlen

        Issue Links

          Activity

          Hide
          Knut Anders Hatlen added a comment -

          Saw a very similar stacktrace on another machine the same night (running on a Raspberry Pi with Java SE 7 Embedded):

          junit.framework.AssertionFailedError
          at org.apache.derbyTesting.functionTests.tests.store.AutomaticIndexStatisticsTest.testStatisticsCorrectness(AutomaticIndexStatisticsTest.java:324)
          at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:117)
          at org.apache.derbyTesting.junit.BaseJDBCTestCase.runBareOverridable(BaseJDBCTestCase.java:424)
          at org.apache.derbyTesting.junit.BaseJDBCTestCase.runBare(BaseJDBCTestCase.java:441)
          at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
          at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
          at junit.extensions.TestSetup.run(TestSetup.java:25)
          at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
          at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
          at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
          at junit.extensions.TestSetup.run(TestSetup.java:25)

          Twice the same night and coinciding with the DST switch.

          Show
          Knut Anders Hatlen added a comment - Saw a very similar stacktrace on another machine the same night (running on a Raspberry Pi with Java SE 7 Embedded): junit.framework.AssertionFailedError at org.apache.derbyTesting.functionTests.tests.store.AutomaticIndexStatisticsTest.testStatisticsCorrectness(AutomaticIndexStatisticsTest.java:324) at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:117) at org.apache.derbyTesting.junit.BaseJDBCTestCase.runBareOverridable(BaseJDBCTestCase.java:424) at org.apache.derbyTesting.junit.BaseJDBCTestCase.runBare(BaseJDBCTestCase.java:441) at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24) at junit.extensions.TestSetup$1.protect(TestSetup.java:21) at junit.extensions.TestSetup.run(TestSetup.java:25) at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57) at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24) at junit.extensions.TestSetup$1.protect(TestSetup.java:21) at junit.extensions.TestSetup.run(TestSetup.java:25) Twice the same night and coinciding with the DST switch.
          Show
          Knut Anders Hatlen added a comment - Make that four failures, same night: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.5/testing/testlog/vista-64/1402814-suitesAll_diff.txt http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.5/testing/testlog/vista/1402814-suitesAll_diff.txt
          Hide
          Knut Anders Hatlen added a comment -

          The test checks the value of the CREATIONTIMESTAMP column in SYS.SYSSTATISTICS to find out if the statistics have been updated. The timestamp in that column is stored in the local timezone. However, since Derby doesn't store the timezone offset, timestamps in the hour before the switch from DST to standard time and in the hour after the switch are ambiguous. So when the test fetches a timestamp, say, 2012-10-28 02:30:00 from SYSSTATISTICS, it doesn't know whether that represents 2012-10-28 02:30:00 CEST or 2012-10-28 02:30:00 CET, which both are valid times. The current logic in the Derby engine seems to consistently pick the latter value. This means that if the test runs during the hour before the switch to standard time, it looks as if the statistics are updated one hour into the future, and the test fails.

          Show
          Knut Anders Hatlen added a comment - The test checks the value of the CREATIONTIMESTAMP column in SYS.SYSSTATISTICS to find out if the statistics have been updated. The timestamp in that column is stored in the local timezone. However, since Derby doesn't store the timezone offset, timestamps in the hour before the switch from DST to standard time and in the hour after the switch are ambiguous. So when the test fetches a timestamp, say, 2012-10-28 02:30:00 from SYSSTATISTICS, it doesn't know whether that represents 2012-10-28 02:30:00 CEST or 2012-10-28 02:30:00 CET, which both are valid times. The current logic in the Derby engine seems to consistently pick the latter value. This means that if the test runs during the hour before the switch to standard time, it looks as if the statistics are updated one hour into the future, and the test fails.
          Hide
          Knut Anders Hatlen added a comment -

          One way to make the test handle the ambiguity around the DST switch, is to force it to run in the GMT timezone, which doesn't observe DST. See the attached patch.

          I changed the local time on my computer to one hour before the switch from DST and ran the store test suite with and without the patch. It failed without the patch, and passed when the patch was applied.

          Show
          Knut Anders Hatlen added a comment - One way to make the test handle the ambiguity around the DST switch, is to force it to run in the GMT timezone, which doesn't observe DST. See the attached patch. I changed the local time on my computer to one hour before the switch from DST and ran the store test suite with and without the patch. It failed without the patch, and passed when the patch was applied.
          Hide
          Knut Anders Hatlen added a comment -

          Committed revision 1404886.

          When DERBY-5974 is fixed, the test can probably stop using TimeZoneTestSetup. But for now, run the test in the GMT time zone.

          Show
          Knut Anders Hatlen added a comment - Committed revision 1404886. When DERBY-5974 is fixed, the test can probably stop using TimeZoneTestSetup. But for now, run the test in the GMT time zone.
          Hide
          Knut Anders Hatlen added a comment -

          Back-ported to 10.9 and 10.8 to allow back-porting of DERBY-6193 without conflicts.

          Committed to 10.9 with revision 1404886.
          Committed to 10.8 with revision 1471270.

          Show
          Knut Anders Hatlen added a comment - Back-ported to 10.9 and 10.8 to allow back-porting of DERBY-6193 without conflicts. Committed to 10.9 with revision 1404886. Committed to 10.8 with revision 1471270.

            People

            • Assignee:
              Knut Anders Hatlen
              Reporter:
              Knut Anders Hatlen
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development