Derby
  1. Derby
  2. DERBY-654

unit/T_RawStoreFactory.unit fails with an assert failure in J2ME/CDC/FP

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Minor Minor
    • Resolution: Won't Fix
    • Affects Version/s: 10.2.1.6
    • Fix Version/s: None
    • Component/s: Store
    • Labels:
      None
    • Environment:
      IBM WCTME5.7 j9 foundation VM

      Description

      I am thinking this is a bug and opening a JIRA issue since I did not get any response to my question in derby-dev. One more thing I noticed is this test passes in 10.1 branch. It is failing only in trunk.

      The test unit/T_RawStoreFactory.unit fails with an assert failure in CDC/FP. This failure looks like an intermittent one though it is failing all the time now. I have run this test successfully some time back. I would like to find out if this is a bug (Derby or jvm) or just an intermittent failure. I am using j9 foundation from IBM WCTME5.7.

      ---------------------------------------------------------------------
      diff for the test:
      ---------------------------------------------------------------------
      < – Unit Test T_RawStoreFactory finished
      2 add
      > There should be 0 observers, but we still have 1 observers.
      > Shutting down due to unit test failure.
      ---------------------------------------------------------------------
      stack trace for AssertFailure in derby.log is:
      ---------------------------------------------------------------------
      FAIL - org.apache.derby.iapi.services.sanity.AssertFailure: ASSERT
      FAILED still on observer list
      org.apache.derby.impl.store.raw.data.TruncateOnCommit@f147d525
      org.apache.derby.iapi.services.sanity.AssertFailure: ASSERT FAILED
      still on observer list
      org.apache.derby.impl.store.raw.data.TruncateOnCommit@f147d525
      at org.apache.derby.iapi.services.sanity.SanityManager.THROWASSERT(SanityManager.java:150)
      at org.apache.derby.impl.store.raw.data.TruncateOnCommit.update(TruncateOnCommit.java:69)
      at java.util.Observable.notifyObservers(Observable.java:117)
      at org.apache.derby.iapi.store.raw.xact.RawTransaction.notifyObservers(RawTransaction.java:313)
      at org.apache.derby.impl.store.raw.xact.Xact.doComplete(Xact.java:1927)
      at org.apache.derby.impl.store.raw.xact.Xact.preComplete(Xact.java:1880)
      at org.apache.derby.impl.store.raw.xact.Xact.prepareCommit(Xact.java:726)
      at org.apache.derby.impl.store.raw.xact.Xact.commit(Xact.java:839)
      at org.apache.derby.impl.store.raw.xact.Xact.commit(Xact.java:636)
      at org.apache.derbyTesting.unitTests.store.T_Util.t_commit(T_Util.java:838)
      at org.apache.derbyTesting.unitTests.store.T_RawStoreFactory.TC001(T_RawStoreFactory.java:7435)
      at org.apache.derbyTesting.unitTests.store.T_RawStoreFactory.runTempTests(T_RawStoreFactory.java:420)
      at org.apache.derbyTesting.unitTests.store.T_RawStoreFactory.runTestSet(T_RawStoreFactory.java:247)
      at org.apache.derbyTesting.unitTests.harness.T_MultiIterations.runTests(T_MultiIterations.java:94)
      at org.apache.derbyTesting.unitTests.harness.T_MultiThreadedIterations.runTests(T_MultiThreadedIterations.java:91)
      at org.apache.derbyTesting.unitTests.harness.T_Generic.Execute(T_Generic.java:117)
      at org.apache.derbyTesting.unitTests.harness.BasicUnitTestManager.runATest(BasicUnitTestManager.java:183)
      at org.apache.derbyTesting.unitTests.harness.BasicUnitTestManager.runTests(BasicUnitTestManager.java:245)
      at org.apache.derbyTesting.unitTests.harness.BasicUnitTestManager.boot(BasicUnitTestManager.java:92)
      at org.apache.derby.impl.services.monitor.BaseMonitor.boot(BaseMonitor.java:2008)
      at org.apache.derby.impl.services.monitor.TopService.bootModule(TopService.java:290)
      at org.apache.derby.impl.services.monitor.BaseMonitor.bootService(BaseMonitor.java:1846)
      at org.apache.derby.impl.services.monitor.BaseMonitor.startServices(BaseMonitor.java:966)
      at org.apache.derby.impl.services.monitor.BaseMonitor.runWithState(BaseMonitor.java:398)
      at org.apache.derby.impl.services.monitor.FileMonitor.<init>(FileMonitor.java:59)
      at org.apache.derby.iapi.services.monitor.Monitor.startMonitor(Monitor.java:288)
      at org.apache.derbyTesting.unitTests.harness.UnitTestMain.main(UnitTestMain.java:50)
      ---------------------------------------------------------------------

      On looking at the code, I did not understand how this assert failure can happen. The assert is thrown in following code in TruncateOnCommit:
      public void update(Observable obj, Object arg) {
      if (SanityManager.DEBUG)

      { if (arg == null) SanityManager.THROWASSERT("still on observer list " + this); }

      I am puzzled by how 'arg' can become null in this case. As I understand, 'update' method of each Observer gets called by the notifyObserver method in java.util.Observable class. notifyObserver passes 'arg', which describes the type of change, as the second argument to update. In this code path, 'arg' passed to notifyObserver is RawTransaction.COMMIT (which is not null). However the code has an assert to check for null value which means there is some situation where the 'arg' can become null. I have not understood what causes this situation but it is always being hit when running in this environment.

      1. Derby654.stat.txt
        0.1 kB
        Sunitha Kambhampati
      2. derby654.diff.txt
        0.5 kB
        Sunitha Kambhampati

        Activity

        Deepa Remesh created issue -
        Hide
        Kathey Marsden added a comment -

        In addition to answering Deepa's specific questions, It would be good if someone with some Store knowledge could comment on this assertion and estimate how serious it is. We have not seen it manifested in any functional tests, but it does appear to be a regression from 10.1 so perhaps it should be marked with higher priority.

        Show
        Kathey Marsden added a comment - In addition to answering Deepa's specific questions, It would be good if someone with some Store knowledge could comment on this assertion and estimate how serious it is. We have not seen it manifested in any functional tests, but it does appear to be a regression from 10.1 so perhaps it should be marked with higher priority.
        Hide
        Sunitha Kambhampati added a comment -

        I ran this test on my win2k/T40 laptop with wctme5.7 and this test passed OK. I ran this test about 100 times repeatedly and it worked OK.

        If for someone, this test fails on their machine, can you please post more info - that would help to debug this failure. Thanks.

        Show
        Sunitha Kambhampati added a comment - I ran this test on my win2k/T40 laptop with wctme5.7 and this test passed OK. I ran this test about 100 times repeatedly and it worked OK. If for someone, this test fails on their machine, can you please post more info - that would help to debug this failure. Thanks.
        Hide
        Sunitha Kambhampati added a comment -

        With respect to my earlier comment - Test passed OK with revision: 369993 on trunk (10.2)

        Show
        Sunitha Kambhampati added a comment - With respect to my earlier comment - Test passed OK with revision: 369993 on trunk (10.2)
        Mike Matrigali made changes -
        Field Original Value New Value
        Component/s Regression Test Failure [ 12310664 ]
        Hide
        Sunitha Kambhampati added a comment -

        As I was preparing to disable this test from running in the j9 vms, I ran this test one more time and it failed on my machine (win2k/t40). Looking at the diff, it is similar to the stack trace attached to this jira.

        1)I looked little bit at the code and I think this is the reason that a null arg is passed to the update(Observable obj,Object arg).

        In Xact.doComplete(), notifyObservers is called either with a commit or abort. After this step, in debug block, there is a check to countObservers and if observers!= 0, then another notifyObservers call is made with an arg of null. This notify call is sending an arg of null and hence the update of TruncateOnCommit is getting a null arg and the assert failure.

        2) I put printlns and noticed that the first notifyObserver call in Xact.doComplete is actually making to the TruncateOnCommit and there it calls deleteObserver. I am just not sure why the countObservers does not become 0. My guess is it maybe some timing issue.
        Put checks in Xact.preComplete and verified that none of the corrupt conditions were happening here.

        – I quickly tried if i could run with 10.2 derbyTesting.jar with 10.1 derby.jar but hit a npe in harness stuff. Didnt spend much time looking at it.

        In the meantime, I am attaching a patch (derby654.diff.txt) to disable this test with the wctme5.7 foundation and wsdd5.6.

        I think we should keep this bug open and someone can look at it and investigate whats the cause for this in the j9 vms.

        If this is ok, can someone please review and commit this patch. Thanks.

        Show
        Sunitha Kambhampati added a comment - As I was preparing to disable this test from running in the j9 vms, I ran this test one more time and it failed on my machine (win2k/t40). Looking at the diff, it is similar to the stack trace attached to this jira. 1)I looked little bit at the code and I think this is the reason that a null arg is passed to the update(Observable obj,Object arg). In Xact.doComplete(), notifyObservers is called either with a commit or abort. After this step, in debug block, there is a check to countObservers and if observers!= 0, then another notifyObservers call is made with an arg of null. This notify call is sending an arg of null and hence the update of TruncateOnCommit is getting a null arg and the assert failure. 2) I put printlns and noticed that the first notifyObserver call in Xact.doComplete is actually making to the TruncateOnCommit and there it calls deleteObserver. I am just not sure why the countObservers does not become 0. My guess is it maybe some timing issue. Put checks in Xact.preComplete and verified that none of the corrupt conditions were happening here. – I quickly tried if i could run with 10.2 derbyTesting.jar with 10.1 derby.jar but hit a npe in harness stuff. Didnt spend much time looking at it. In the meantime, I am attaching a patch (derby654.diff.txt) to disable this test with the wctme5.7 foundation and wsdd5.6. I think we should keep this bug open and someone can look at it and investigate whats the cause for this in the j9 vms. If this is ok, can someone please review and commit this patch. Thanks.
        Sunitha Kambhampati made changes -
        Attachment Derby654.stat.txt [ 12323690 ]
        Attachment derby654.diff.txt [ 12323689 ]
        Sunitha Kambhampati made changes -
        Other Info [Patch available]
        Hide
        Mike Matrigali added a comment -

        I have committed this change. Removing it from the regression suite as no one is actively working on fixing this issue. It is removed from the regression tests suite in the failing platform, so I have removed that component.

        m1_142:1>svn commit

        Adding java\testing\org\apache\derbyTesting\functionTests\tests\unit\T_R
        awStoreFactory_app.properties
        Transmitting file data .
        Committed revision 382931.

        Show
        Mike Matrigali added a comment - I have committed this change. Removing it from the regression suite as no one is actively working on fixing this issue. It is removed from the regression tests suite in the failing platform, so I have removed that component. m1_142:1>svn commit Adding java\testing\org\apache\derbyTesting\functionTests\tests\unit\T_R awStoreFactory_app.properties Transmitting file data . Committed revision 382931.
        Mike Matrigali made changes -
        Component/s Regression Test Failure [ 12310664 ]
        Andrew McIntyre made changes -
        Other Info [Patch available]
        Derby Info [Patch Available]
        Myrna van Lunteren made changes -
        Derby Info [Patch Available]
        Hide
        Rick Hillegas added a comment -

        Closing this issue because the test was disabled on the offending platform and no-one has expressed any interest in this issue in 3 years.

        Show
        Rick Hillegas added a comment - Closing this issue because the test was disabled on the offending platform and no-one has expressed any interest in this issue in 3 years.
        Rick Hillegas made changes -
        Status Open [ 1 ] Closed [ 6 ]
        Resolution Won't Fix [ 2 ]
        Gavin made changes -
        Workflow jira [ 12343171 ] Default workflow, editable Closed status [ 12797556 ]

          People

          • Assignee:
            Unassigned
            Reporter:
            Deepa Remesh
          • Votes:
            0 Vote for this issue
            Watchers:
            0 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development