[DERBY-3844] ASSERT failure in BasePage.unlatch() when running LobStreamsTest

• Type: Bug
• Status: Closed
• Priority: Major
• Resolution: Fixed
• Affects Version/s: 10.5.1.1, 10.6.1.0
• Fix Version/s: 10.5.3.1, 10.6.1.0
• Component/s: Store
• Environment: Solaris 10, AMD Opteron with 2 CPUs, Java(TM) SE Runtime Environment (build 1.6.0_06-b02), Derby trunk revision 686755
• Urgency: Normal
• Issue & fix info: Release Note Needed, Repro attached
• Assignee: Kristian Waagan
• Reporter: Knut Anders Hatlen
• Created: 21/Aug/08 12:50
• Updated: 12/Jul/10 22:47
• Resolved: 12/Jul/10 22:47

Description

I saw this failure when running suites.All to test the patch nested_transaction_v2.diff which is posted on DERBY-3693. The failure did not occur when I reran the test, and I don't believe the patch should have any effect on the code that failed. The ASSERT that is triggered is this one (which indicates that we're trying to unlatch a page that's not latched):

if (SanityManager.DEBUG)

{ SanityManager.ASSERT(isLatched()); }

Here's the full stack trace and thread dump:

1) testBlobWrite3Param(org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest)org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED
at org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:98)
at org.apache.derby.impl.store.raw.data.BasePage.unlatch(BasePage.java:1319)
at org.apache.derby.impl.store.raw.data.OverflowInputStream.fillByteHolder(OverflowInputStream.java:152)
at org.apache.derby.impl.store.raw.data.BufferedByteHolderInputStream.read(BufferedByteHolderInputStream.java:44)
at java.io.DataInputStream.read(DataInputStream.java:132)
at org.apache.derby.impl.jdbc.PositionedStoreStream.read(PositionedStoreStream.java:106)
at org.apache.derby.impl.jdbc.AutoPositioningStream.read(AutoPositioningStream.java:113)
at org.apache.derby.impl.jdbc.UpdatableBlobStream.read(UpdatableBlobStream.java:194)
at org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest.readBytesFromStream(LobStreamsTest.java:463)
at org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest.compareLob2File(LobStreamsTest.java:488)
at org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest.testBlobWrite3Param(LobStreamsTest.java:130)
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:104)
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)
---------------
Stack traces for all live threads:
Thread name=derby.antiGC id=280 priority=1 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
org.apache.derby.impl.services.monitor.AntiGC.run(BaseMonitor.java:2217)
java.lang.Thread.run(Thread.java:619)

Thread name=Signal Dispatcher id=4 priority=9 state=RUNNABLE isdaemon=true

Thread name=main id=1 priority=5 state=RUNNABLE isdaemon=false
java.lang.Thread.dumpThreads(Native Method)
java.lang.Thread.getAllStackTraces(Thread.java:1477)
org.apache.derby.shared.common.sanity.ThreadDump.getStackDumpString(ThreadDump.java:34)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
org.apache.derby.shared.common.sanity.AssertFailure$1.run(AssertFailure.java:165)
java.security.AccessController.doPrivileged(Native Method)
org.apache.derby.shared.common.sanity.AssertFailure.dumpThreads(AssertFailure.java:159)
org.apache.derby.shared.common.sanity.AssertFailure.<init>(AssertFailure.java:82)
org.apache.derby.shared.common.sanity.SanityManager.ASSERT(SanityManager.java:98)
org.apache.derby.impl.store.raw.data.BasePage.unlatch(BasePage.java:1319)
org.apache.derby.impl.store.raw.data.OverflowInputStream.fillByteHolder(OverflowInputStream.java:152)
org.apache.derby.impl.store.raw.data.BufferedByteHolderInputStream.read(BufferedByteHolderInputStream.java:44)
java.io.DataInputStream.read(DataInputStream.java:132)
org.apache.derby.impl.jdbc.PositionedStoreStream.read(PositionedStoreStream.java:106)
org.apache.derby.impl.jdbc.AutoPositioningStream.read(AutoPositioningStream.java:113)
org.apache.derby.impl.jdbc.UpdatableBlobStream.read(UpdatableBlobStream.java:194)
org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest.readBytesFromStream(LobStreamsTest.java:463)
org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest.compareLob2File(LobStreamsTest.java:488)
org.apache.derbyTesting.functionTests.tests.jdbcapi.LobStreamsTest.testBlobWrite3Param(LobStreamsTest.java:130)
sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:104)
junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
junit.extensions.TestSetup$1.protect(TestSetup.java:21)
junit.extensions.TestSetup.run(TestSetup.java:25)
org.apache.derbyTesting.junit.BaseTestSetup.run(BaseTestSetup.java:57)

Thread name=derby.rawStoreDaemon id=941 priority=5 state=TIMED_WAITING isdaemon=true
java.lang.Object.wait(Native Method)
org.apache.derby.impl.services.daemon.BasicDaemon.rest(BasicDaemon.java:571)
org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:388)
java.lang.Thread.run(Thread.java:619)

Thread name=Timer-3 id=281 priority=5 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
java.util.TimerThread.mainLoop(Timer.java:483)
java.util.TimerThread.run(Timer.java:462)

Thread name=Finalizer id=3 priority=8 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)
java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)
java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

Thread name=Reference Handler id=2 priority=10 state=WAITING isdaemon=true
java.lang.Object.wait(Native Method)
java.lang.Object.wait(Object.java:485)
java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)

Thread name=derby.rawStoreDaemon id=933 priority=5 state=TIMED_WAITING isdaemon=true
java.lang.Object.wait(Native Method)
org.apache.derby.impl.services.daemon.BasicDaemon.rest(BasicDaemon.java:571)
org.apache.derby.impl.services.daemon.BasicDaemon.run(BasicDaemon.java:388)
java.lang.Thread.run(Thread.java:619)

---------------

Issue Links

• is duplicated by: DERBY-4440 Intermittent Java deadlock when running LobStreamsTest with insane jars
• is related to: DERBY-4102 Assert failure or ClassCastException in EmbedBlob when retrieving BLOB >= 32K
• is required by: DERBY-4728 10.5 backport effort tracking issue