Derby
  1. Derby
  2. DERBY-3258

'Unexpected row count: expected:<0> but was:<3>' in testReleaseCompileLocks

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Fixed
    • Affects Version/s: 10.4.1.3
    • Fix Version/s: 10.7.1.4, 10.8.1.2
    • Component/s: Test
    • Labels:
      None
    • Environment:
      OS: Solaris Nevada snv_27a X86 64 bits - SunOS 5.11 snv_27
      VJM: Sun Microsystems Inc. 1.6.0-b105
    • Bug behavior facts:
      Regression Test Failure

      Description

      Seen in http://dbtg.thresher.com/derby/test/trunk16/jvmAll/testing/Limited/testSummary-601462.html : JDK16Jvm1.6SunOS-5.11 i86pc-i386.

      There was 1 failure:
      1) testReleaseCompileLocks(org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest)junit.framework.AssertionFailedError: Unexpected row count: expected:<0> but was:<3>
      at org.apache.derbyTesting.junit.JDBC.assertDrainResults(JDBC.java:596)
      at org.apache.derbyTesting.junit.JDBC.assertEmpty(JDBC.java:490)
      at org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest.testReleaseCompileLocks(ReleaseCompileLocksTest.java:146)
      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:95)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
      at junit.extensions.TestSetup.run(TestSetup.java:23)
      at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)

      1. d3258.diff
        5 kB
        Knut Anders Hatlen

        Issue Links

          Activity

          Hide
          Myrna van Lunteren added a comment -

          I saw what I take to be a variation on this with 10.5.1.2 built at revision 772042 on windows:
          (org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest)junit.framework.AssertionFailedError: Unexpected row count: expected:<0> but was:<1>
          at org.apache.derbyTesting.junit.JDBC.assertDrainResults(JDBC.java:640)
          at org.apache.derbyTesting.junit.JDBC.assertEmpty(JDBC.java:492)
          at org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest.testReleaseCompileLocks(ReleaseCompileLocksTest.java:120)
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:105)
          at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22)
          at junit.extensions.TestSetup$1.protect(TestSetup.java:19)
          at junit.extensions.TestSetup.run(TestSetup.java:23)
          at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)

          Show
          Myrna van Lunteren added a comment - I saw what I take to be a variation on this with 10.5.1.2 built at revision 772042 on windows: (org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest)junit.framework.AssertionFailedError: Unexpected row count: expected:<0> but was:<1> at org.apache.derbyTesting.junit.JDBC.assertDrainResults(JDBC.java:640) at org.apache.derbyTesting.junit.JDBC.assertEmpty(JDBC.java:492) at org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest.testReleaseCompileLocks(ReleaseCompileLocksTest.java:120) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:64) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:105) at junit.extensions.TestDecorator.basicRun(TestDecorator.java:22) at junit.extensions.TestSetup$1.protect(TestSetup.java:19) at junit.extensions.TestSetup.run(TestSetup.java:23) at org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)
          Hide
          Dag H. Wanvik added a comment -

          I just saw this on trunk on OpenSolaris svn_142, in the variant similar to what Myrna did, but mine failed on the assert on line 146 rather than on line 120. It appeared when I ran the test in Knut's parallel tester using 6 threads on my dual core laptop (Lenovo T61p, 4Gb ram).
          When running th test standalone I do not see the error.

          junit.framework.AssertionFailedError: Unexpected row count: expected:<0> but was:<1>
          at junit.framework.Assert.fail(Assert.java:47)
          at junit.framework.Assert.failNotEquals(Assert.java:280)
          at junit.framework.Assert.assertEquals(Assert.java:64)
          at junit.framework.Assert.assertEquals(Assert.java:198)
          at org.apache.derbyTesting.junit.JDBC.assertDrainResults(JDBC.java:674)
          at org.apache.derbyTesting.junit.JDBC.assertEmpty(JDBC.java:526)
          at org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest.testReleaseCompileLocks(ReleaseCompileLocksTest.java:146)
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          :

          Show
          Dag H. Wanvik added a comment - I just saw this on trunk on OpenSolaris svn_142, in the variant similar to what Myrna did, but mine failed on the assert on line 146 rather than on line 120. It appeared when I ran the test in Knut's parallel tester using 6 threads on my dual core laptop (Lenovo T61p, 4Gb ram). When running th test standalone I do not see the error. junit.framework.AssertionFailedError: Unexpected row count: expected:<0> but was:<1> at junit.framework.Assert.fail(Assert.java:47) at junit.framework.Assert.failNotEquals(Assert.java:280) at junit.framework.Assert.assertEquals(Assert.java:64) at junit.framework.Assert.assertEquals(Assert.java:198) at org.apache.derbyTesting.junit.JDBC.assertDrainResults(JDBC.java:674) at org.apache.derbyTesting.junit.JDBC.assertEmpty(JDBC.java:526) at org.apache.derbyTesting.functionTests.tests.lang.ReleaseCompileLocksTest.testReleaseCompileLocks(ReleaseCompileLocksTest.java:146) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) :
          Hide
          Knut Anders Hatlen added a comment -

          This instability may have the same root cause as DERBY-4211, where the background thread hadn't finished post commit cleanup and locks on committed deleted rows could appear in the lock table dump. The fix in DERBY-4211 was to wait for the post commit work to be completed before querying the lock table.

          Show
          Knut Anders Hatlen added a comment - This instability may have the same root cause as DERBY-4211 , where the background thread hadn't finished post commit cleanup and locks on committed deleted rows could appear in the lock table dump. The fix in DERBY-4211 was to wait for the post commit work to be completed before querying the lock table.
          Hide
          Knut Anders Hatlen added a comment -

          I am able to reproduce this fairly quickly in my environment if I start five threads running this test in a loop. Most of the time it's the assert on line 146 that fails, but sometimes it's the assert on line 140.

          With the attached patch, which makes the test wait for the post commit thread to complete before it queries the lock table, I'm not able to reproduce the failure anymore.

          Show
          Knut Anders Hatlen added a comment - I am able to reproduce this fairly quickly in my environment if I start five threads running this test in a loop. Most of the time it's the assert on line 146 that fails, but sometimes it's the assert on line 140. With the attached patch, which makes the test wait for the post commit thread to complete before it queries the lock table, I'm not able to reproduce the failure anymore.
          Hide
          Dag H. Wanvik added a comment -

          Looks like clean and good solution to me. +1

          Show
          Dag H. Wanvik added a comment - Looks like clean and good solution to me. +1
          Hide
          Knut Anders Hatlen added a comment -

          Thanks, Dag!

          Committed revision 1041338.

          Also backported to 10.7 and committed revision 1041339.

          Show
          Knut Anders Hatlen added a comment - Thanks, Dag! Committed revision 1041338. Also backported to 10.7 and committed revision 1041339.
          Hide
          Knut Anders Hatlen added a comment -

          [bulk update] Close all resolved issues that haven't been updated for more than one year.

          Show
          Knut Anders Hatlen added a comment - [bulk update] Close all resolved issues that haven't been updated for more than one year.

            People

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

              Dates

              • Created:
                Updated:
                Resolved:

                Development