Derby
  1. Derby
  2. DERBY-5428

ns test error: ERROR 38000: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920' was thrown while evaluating an expression

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Won't Fix
    • Affects Version/s: 10.8.2.2
    • Fix Version/s: None
    • Component/s: SQL
    • Environment:
    • Urgency:
      Normal
    • Bug behavior facts:
      Regression Test Failure

      Description

      In an attempt to reproduce DERBY-5421/ DERBY-5422/ DERBY-5423 and get more information, I ran the nstest (embedded on another Windows machine, with the same jvm version, but with the following setup:

      • sane jars from the 10.8.2.1 RC2 (rev 1170221)
      • derbyTesting.jar built (sane) at the same level, but with modifications to put ps2.close() in Dbutil after the exception print
      • the following details in a derby.properties file:
        derby.language.logStatementText=true
        derby.stream.error.logSeverityLevel=0
        derby.language.sequence.preallocator=200

      This time, so far, I only see the following unexpected error:
      (in derby.log ERROR 38000: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920' was thrown while evaluating an expression
      This looks like DERBY-5389, but it has a different stack trace and happens with ibm 1.6:
      ------------------------------------------------------------------
      Tue Sep 20 15:04:06 PDT 2011 Thread[Thread 3,5,main] (XID = 58789), (SESSIONID = 22), (DATABASE = nstestdb), (DRDAID = null), Begin compiling prepared statement: update nstesttab set t_double = ? where serialkey = 36027 :End prepared statement

      ERROR 38000: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920' was thrown while evaluating an expression.
      at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:296)
      at org.apache.derby.iapi.error.StandardException.unexpectedUserException(StandardException.java:583)
      at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:164)
      at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:148)
      at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:185)
      at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
      at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:515)
      at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:436)
      at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:317)
      at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1686)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:308)
      at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:201)
      at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148)
      at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
      at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
      Caused by: org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
      at org.apache.derby.impl.sql.catalog.SequenceUpdater.setIdentity(SequenceUpdater.java:272)
      at org.apache.derby.impl.services.cache.ConcurrentCache.find(ConcurrentCache.java:295)
      at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10352)
      at org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementValue(InsertResultSet.java:824)
      at org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java:666)
      at org.apache.derby.exe.ac092d4de3x0132x88d8xfec0x0000000809207.e0(Unknown Source)
      at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:139)
      ... 13 more
      ============= begin nested exception, level (1) ===========
      org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
      at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
      at org.apache.derby.impl.sql.catalog.SequenceUpdater.setIdentity(SequenceUpdater.java:272)
      at org.apache.derby.impl.services.cache.ConcurrentCache.find(ConcurrentCache.java:295)
      at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10352)
      at org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementValue(InsertResultSet.java:824)
      at org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java:666)
      at org.apache.derby.exe.ac092d4de3x0132x88d8xfec0x0000000809207.e0(Unknown Source)
      at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:139)
      at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:148)
      at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:185)
      at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
      at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:515)
      at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:436)
      at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:317)
      at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1686)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:308)
      at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:201)
      at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148)
      at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)

      at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:286)
      at org.apache.derby.iapi.types.SQLDecimal.setWidth(SQLDecimal.java:1063)
      at org.apache.derby.iapi.types.SQLDecimal.normalize(SQLDecimal.java:759)
      at org.apache.derby.iapi.types.DataTypeDescriptor.normalize(DataTypeDescriptor.java:648)
      at org.apache.derby.impl.sql.execute.NormalizeResultSet.normalizeColumn(NormalizeResultSet.java:329)
      at org.apache.derby.impl.sql.execute.NormalizeResultSet.normalizeRow(NormalizeResultSet.java:373)
      at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:188)
      at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
      at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:440)
      at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:264)
      at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:436)
      at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:317)
      at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1686)
      at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:308)
      at org.apache.derbyTesting.system.nstest.utils.DbUtil.update_one_row(DbUtil.java:382)
      at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:162)
      at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
      at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)

        Issue Links

          Activity

          Myrna van Lunteren created issue -
          Myrna van Lunteren made changes -
          Field Original Value New Value
          Summary org.a ns test error: ERROR 38000: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920' was thrown while evaluating an expression
          Bug behavior facts [Regression Test Failure]
          Affects Version/s 10.8.2.1 [ 12317957 ]
          Environment Windows XP, ibm 16 sr 9 fp1, with modified derbyTesting.jar (ps2.close & print exception reversed as suggested in DERBY-5421)
          Description In an attempt to reproduce DERBY-5421/ DERBY-5422/ DERBY-5423 and get more information, I ran the nstest (embedded on another Windows machine, with the same jvm version, but with the following setup:
          - sane jars from the 10.8.2.1 RC2 (rev 1170221)
          - derbyTesting.jar built (sane) at the same level, but with modifications to put ps2.close() in Dbutil after the exception print
          - the following details in a derby.properties file:
            derby.language.logStatementText=true
            derby.stream.error.logSeverityLevel=0
            derby.language.sequence.preallocator=200

          This time, so far, I only see the following unexpected error:
          (in derby.log:) ERROR 38000: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920' was thrown while evaluating an expression
          This looks like DERBY-5389, but it has a different stack trace and happens with ibm 1.6:
          ------------------------------------------------------------------
          Tue Sep 20 15:04:06 PDT 2011 Thread[Thread 3,5,main] (XID = 58789), (SESSIONID = 22), (DATABASE = nstestdb), (DRDAID = null), Begin compiling prepared statement: update nstesttab set t_double = ? where serialkey = 36027 :End prepared statement
          --
          ERROR 38000: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920' was thrown while evaluating an expression.
          at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:296)
          at org.apache.derby.iapi.error.StandardException.unexpectedUserException(StandardException.java:583)
          at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:164)
          at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:148)
          at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:185)
          at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
          at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:515)
          at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:436)
          at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:317)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1686)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:308)
          at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:201)
          at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148)
          at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
          at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
          Caused by: org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920
          at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
          at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
          at org.apache.derby.impl.sql.catalog.SequenceUpdater.setIdentity(SequenceUpdater.java:272)
          at org.apache.derby.impl.services.cache.ConcurrentCache.find(ConcurrentCache.java:295)
          at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10352)
          at org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementValue(InsertResultSet.java:824)
          at org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java:666)
          at org.apache.derby.exe.ac092d4de3x0132x88d8xfec0x0000000809207.e0(Unknown Source)
          at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:139)
          ... 13 more
          ============= begin nested exception, level (1) ===========
          org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0132-88d8-fec0-000000080920
          at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
          at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
          at org.apache.derby.impl.sql.catalog.SequenceUpdater.setIdentity(SequenceUpdater.java:272)
          at org.apache.derby.impl.services.cache.ConcurrentCache.find(ConcurrentCache.java:295)
          at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10352)
          at org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementValue(InsertResultSet.java:824)
          at org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java:666)
          at org.apache.derby.exe.ac092d4de3x0132x88d8xfec0x0000000809207.e0(Unknown Source)
          at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:139)
          at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:148)
          at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:185)
          at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
          at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:515)
          at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:436)
          at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:317)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1686)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:308)
          at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:201)
          at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148)
          at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
          --
          at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:286)
          at org.apache.derby.iapi.types.SQLDecimal.setWidth(SQLDecimal.java:1063)
          at org.apache.derby.iapi.types.SQLDecimal.normalize(SQLDecimal.java:759)
          at org.apache.derby.iapi.types.DataTypeDescriptor.normalize(DataTypeDescriptor.java:648)
          at org.apache.derby.impl.sql.execute.NormalizeResultSet.normalizeColumn(NormalizeResultSet.java:329)
          at org.apache.derby.impl.sql.execute.NormalizeResultSet.normalizeRow(NormalizeResultSet.java:373)
          at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:188)
          at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
          at org.apache.derby.impl.sql.execute.UpdateResultSet.collectAffectedRows(UpdateResultSet.java:440)
          at org.apache.derby.impl.sql.execute.UpdateResultSet.open(UpdateResultSet.java:264)
          at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:436)
          at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:317)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1686)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:308)
          at org.apache.derbyTesting.system.nstest.utils.DbUtil.update_one_row(DbUtil.java:382)
          at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:162)
          at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
          at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)

          Hide
          Rick Hillegas added a comment -

          This may be another example of the harmless, but confused state of the SequenceUpdater which was fixed by the work on DERBY-5389. That work was committed to the 10.8 branch at revision 1172620 after the 10.8.2.1 candidate was built (at revision 1170221). The stack trace is different because SequenceUpdater.setIdentity() is being called to generate an identity rather than a sequence.

          Other than the problem fixed by DERBY-5389, I don't see any other ways that the internal state of the SequenceUpdater could be confused in this fashion. However, I can't promise that there isn't another code path which I'm not clever enough to see.

          It might be useful to see if you can reproduce this problem against the current head of the 10.8 branch. Thanks.

          Show
          Rick Hillegas added a comment - This may be another example of the harmless, but confused state of the SequenceUpdater which was fixed by the work on DERBY-5389 . That work was committed to the 10.8 branch at revision 1172620 after the 10.8.2.1 candidate was built (at revision 1170221). The stack trace is different because SequenceUpdater.setIdentity() is being called to generate an identity rather than a sequence. Other than the problem fixed by DERBY-5389 , I don't see any other ways that the internal state of the SequenceUpdater could be confused in this fashion. However, I can't promise that there isn't another code path which I'm not clever enough to see. It might be useful to see if you can reproduce this problem against the current head of the 10.8 branch. Thanks.
          Rick Hillegas made changes -
          Link This issue relates to DERBY-5389 [ DERBY-5389 ]
          Rick Hillegas made changes -
          Link This issue relates to DERBY-4437 [ DERBY-4437 ]
          Hide
          Rick Hillegas added a comment -

          Are there instructions on how to run NsTest? How are you running it? How long did you have to run it before the error popped? I did not see this error in derby.log after running the test for a bit against 10.8.2.1 as follows. Thanks.

          java org.apache.derbyTesting.system.nstest.NsTest Embedded

          Show
          Rick Hillegas added a comment - Are there instructions on how to run NsTest? How are you running it? How long did you have to run it before the error popped? I did not see this error in derby.log after running the test for a bit against 10.8.2.1 as follows. Thanks. java org.apache.derbyTesting.system.nstest.NsTest Embedded
          Hide
          Myrna van Lunteren added a comment -

          Hi Rick,
          The only instructions I know of are in the README.txt file you can find in the source under ../java/testing/org/apache/derbyTesting/system/nstest.

          You used the same basic command as I was - except I redirect the output to a file, and I had created a derby.properties file with the following:
          derby.language.logStatementText=true
          derby.stream.error.logSeverityLevel=0
          derby.language.sequence.preallocator=200
          I always find this test awkward to analyze/debug, but it does do a good amount of various simple actions to the database. I usually grep for ERROR in the output, and then ignore (usually using | grep -v) errors seen in previous runs, such as XBM06, 22003, 40001 (deadlock!), 40XL1.

          I did use the sane jars from the original 10.8.2.1 candidate.

          This error popped up almost immediately - the nstestdb database has OS time stamp Sep 20 15:03 and the time stamp for this error in derby.log is Sep 20 15:04:06
          Note that this error did not show up in any of my other test runs, with basically the same source code, except they were insane jars.

          So, thank you for looking at the code path and your analysis - your explanation makes sense.

          I will now set up a test run with the head of 10.8. If I don't see this again, we can close it either as cannot reproduce,
          or mark it as a duplicate of DERBY-5389.

          Show
          Myrna van Lunteren added a comment - Hi Rick, The only instructions I know of are in the README.txt file you can find in the source under ../java/testing/org/apache/derbyTesting/system/nstest. You used the same basic command as I was - except I redirect the output to a file, and I had created a derby.properties file with the following: derby.language.logStatementText=true derby.stream.error.logSeverityLevel=0 derby.language.sequence.preallocator=200 I always find this test awkward to analyze/debug, but it does do a good amount of various simple actions to the database. I usually grep for ERROR in the output, and then ignore (usually using | grep -v) errors seen in previous runs, such as XBM06, 22003, 40001 (deadlock!), 40XL1. I did use the sane jars from the original 10.8.2.1 candidate. This error popped up almost immediately - the nstestdb database has OS time stamp Sep 20 15:03 and the time stamp for this error in derby.log is Sep 20 15:04:06 Note that this error did not show up in any of my other test runs, with basically the same source code, except they were insane jars. So, thank you for looking at the code path and your analysis - your explanation makes sense. I will now set up a test run with the head of 10.8. If I don't see this again, we can close it either as cannot reproduce, or mark it as a duplicate of DERBY-5389 .
          Hide
          Rick Hillegas added a comment -

          Thanks, Myrna. I don't seem to be able to reproduce this problem using the debug 10.8.2.1 jars and the instructions you gave. Odd.

          Show
          Rick Hillegas added a comment - Thanks, Myrna. I don't seem to be able to reproduce this problem using the debug 10.8.2.1 jars and the instructions you gave. Odd.
          Hide
          Knut Anders Hatlen added a comment -

          I saw the same assert failure when running NsTest on head of trunk (revision 1183503, embedded, default settings).

          Show
          Knut Anders Hatlen added a comment - I saw the same assert failure when running NsTest on head of trunk (revision 1183503, embedded, default settings).
          Hide
          Knut Anders Hatlen added a comment -

          Full stack trace for the failure:

          java.sql.SQLException: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0' was thrown while evaluating an expression.
          at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:98)
          at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Util.java:142)
          at org.apache.derby.impl.jdbc.Util.seeNextException(Util.java:278)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:431)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:353)
          at org.apache.derby.impl.jdbc.EmbedConnection.handleException(EmbedConnection.java:2290)
          at org.apache.derby.impl.jdbc.ConnectionChild.handleException(ConnectionChild.java:82)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1334)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1692)
          at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:309)
          at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:201)
          at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148)
          at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118)
          at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551)
          Caused by: java.sql.SQLException: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0' was thrown while evaluating an expression.
          at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45)
          at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory40.java:122)
          at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:71)
          ... 13 more
          Caused by: java.sql.SQLException: Java exception: 'ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0: org.apache.derby.shared.common.sanity.AssertFailure'.
          at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45)
          at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory40.java:122)
          at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:71)
          at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Util.java:142)
          at org.apache.derby.impl.jdbc.Util.javaException(Util.java:299)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:436)
          ... 11 more
          Caused by: org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0
          at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162)
          at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147)
          at org.apache.derby.impl.sql.catalog.SequenceUpdater.setIdentity(SequenceUpdater.java:285)
          at org.apache.derby.impl.services.cache.ConcurrentCache.find(ConcurrentCache.java:295)
          at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10335)
          at org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementValue(InsertResultSet.java:827)
          at org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java:666)
          at org.apache.derby.exe.ac1bd20d84x0133x085ex9dc6x0000037b0ee018.e0(Unknown Source)
          at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:139)
          at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:148)
          at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:185)
          at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127)
          at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:518)
          at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:478)
          at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:319)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242)
          ... 6 more

          Show
          Knut Anders Hatlen added a comment - Full stack trace for the failure: java.sql.SQLException: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0' was thrown while evaluating an expression. at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:98) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Util.java:142) at org.apache.derby.impl.jdbc.Util.seeNextException(Util.java:278) at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:431) at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:353) at org.apache.derby.impl.jdbc.EmbedConnection.handleException(EmbedConnection.java:2290) at org.apache.derby.impl.jdbc.ConnectionChild.handleException(ConnectionChild.java:82) at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1334) at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeStatement(EmbedPreparedStatement.java:1692) at org.apache.derby.impl.jdbc.EmbedPreparedStatement.executeUpdate(EmbedPreparedStatement.java:309) at org.apache.derbyTesting.system.nstest.utils.DbUtil.add_one_row(DbUtil.java:201) at org.apache.derbyTesting.system.nstest.tester.TesterObject.doIUDOperation(TesterObject.java:148) at org.apache.derbyTesting.system.nstest.tester.Tester1.startTesting(Tester1.java:118) at org.apache.derbyTesting.system.nstest.NsTest.run(NsTest.java:551) Caused by: java.sql.SQLException: The exception 'org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0' was thrown while evaluating an expression. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45) at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory40.java:122) at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:71) ... 13 more Caused by: java.sql.SQLException: Java exception: 'ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0: org.apache.derby.shared.common.sanity.AssertFailure'. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45) at org.apache.derby.impl.jdbc.SQLExceptionFactory40.wrapArgsForTransportAcrossDRDA(SQLExceptionFactory40.java:122) at org.apache.derby.impl.jdbc.SQLExceptionFactory40.getSQLException(SQLExceptionFactory40.java:71) at org.apache.derby.impl.jdbc.Util.newEmbedSQLException(Util.java:142) at org.apache.derby.impl.jdbc.Util.javaException(Util.java:299) at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:436) ... 11 more Caused by: org.apache.derby.shared.common.sanity.AssertFailure: ASSERT FAILED Identity being changed on a live cacheable. Old uuidString = 846c00a0-0133-085e-9dc6-0000037b0ee0 at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:162) at org.apache.derby.shared.common.sanity.SanityManager.THROWASSERT(SanityManager.java:147) at org.apache.derby.impl.sql.catalog.SequenceUpdater.setIdentity(SequenceUpdater.java:285) at org.apache.derby.impl.services.cache.ConcurrentCache.find(ConcurrentCache.java:295) at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.getCurrentValueAndAdvance(DataDictionaryImpl.java:10335) at org.apache.derby.impl.sql.execute.InsertResultSet.getSetAutoincrementValue(InsertResultSet.java:827) at org.apache.derby.impl.sql.execute.BaseActivation.getSetAutoincrementValue(BaseActivation.java:666) at org.apache.derby.exe.ac1bd20d84x0133x085ex9dc6x0000037b0ee018.e0(Unknown Source) at org.apache.derby.impl.services.reflect.DirectCall.invoke(ReflectGeneratedClass.java:139) at org.apache.derby.impl.sql.execute.RowResultSet.getNextRowCore(RowResultSet.java:148) at org.apache.derby.impl.sql.execute.NormalizeResultSet.getNextRowCore(NormalizeResultSet.java:185) at org.apache.derby.impl.sql.execute.DMLWriteResultSet.getNextRowCore(DMLWriteResultSet.java:127) at org.apache.derby.impl.sql.execute.InsertResultSet.open(InsertResultSet.java:518) at org.apache.derby.impl.sql.GenericPreparedStatement.executeStmt(GenericPreparedStatement.java:478) at org.apache.derby.impl.sql.GenericPreparedStatement.execute(GenericPreparedStatement.java:319) at org.apache.derby.impl.jdbc.EmbedStatement.executeStatement(EmbedStatement.java:1242) ... 6 more
          Myrna van Lunteren made changes -
          Affects Version/s 10.8.2.2 [ 12317968 ]
          Affects Version/s 10.8.2.1 [ 12317957 ]
          Rick Hillegas made changes -
          Link This issue is related to DERBY-5495 [ DERBY-5495 ]
          Mike Matrigali made changes -
          Component/s SQL [ 11408 ]
          Mamta A. Satoor made changes -
          Labels derby_triage10_9
          Urgency Normal [ 10052 ]
          Hide
          Myrna van Lunteren added a comment -

          I can still reproduce this AssertFailure with a recent trunk build. The machine I got this on is fairly old, and so fairly slow, perhaps that matters.
          I will try to make a smaller test case than nstest.

          Show
          Myrna van Lunteren added a comment - I can still reproduce this AssertFailure with a recent trunk build. The machine I got this on is fairly old, and so fairly slow, perhaps that matters. I will try to make a smaller test case than nstest.
          Myrna van Lunteren made changes -
          Link This issue relates to DERBY-5661 [ DERBY-5661 ]
          Hide
          Myrna van Lunteren added a comment -

          I have been trying to make nstest run in a smaller configuration. I've committed a number of changes so the test can now be run as follows:
          java -Dderby.nstest.restoreBackup=false org.apache.derbyTesting.system.nstest.NsTest Embedded small > nstest.out 2>&1

          I've described further runs in a comment for, and attached a number of run results to, DERBY-5661 which seems another manifestation of some underlying issue as this one.

          Show
          Myrna van Lunteren added a comment - I have been trying to make nstest run in a smaller configuration. I've committed a number of changes so the test can now be run as follows: java -Dderby.nstest.restoreBackup=false org.apache.derbyTesting.system.nstest.NsTest Embedded small > nstest.out 2>&1 I've described further runs in a comment for, and attached a number of run results to, DERBY-5661 which seems another manifestation of some underlying issue as this one.
          Hide
          Myrna van Lunteren added a comment -

          I ran the nstest in a smaller configuration against trunk after the backing out of the original fix for DERBY-4437, (see DERBY-5687, revision 1311285) and where before out of 10 runs I would see 5 or so with this message, I did not see this again.

          So I believe this is no longer an issue.
          Resolving as Invalid because this is (likely) a problem in code that no longer exists.

          Show
          Myrna van Lunteren added a comment - I ran the nstest in a smaller configuration against trunk after the backing out of the original fix for DERBY-4437 , (see DERBY-5687 , revision 1311285) and where before out of 10 runs I would see 5 or so with this message, I did not see this again. So I believe this is no longer an issue. Resolving as Invalid because this is (likely) a problem in code that no longer exists.
          Myrna van Lunteren made changes -
          Status Open [ 1 ] Resolved [ 5 ]
          Resolution Won't Fix [ 2 ]
          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.
          Knut Anders Hatlen made changes -
          Status Resolved [ 5 ] Closed [ 6 ]
          Gavin made changes -
          Workflow jira [ 12634935 ] Default workflow, editable Closed status [ 12799011 ]

            People

            • Assignee:
              Unassigned
              Reporter:
              Myrna van Lunteren
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Development