Derby
  1. Derby
  2. DERBY-5398

NullPointerException in storemore/bug3498.sql

    Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 10.9.1.0
    • Fix Version/s: 10.8.2.2, 10.9.1.0
    • Component/s: Services
    • Labels:
      None
    • Issue & fix info:
      Patch Available
    • Bug behavior facts:
      Regression Test Failure

      Description

      The tinderbox failed when testing revision 1164361:

      Failure Details:

                      • Diff file derbyall/storeall/storemore/bug3498.diff
          • Start: bug3498 jdk1.6.0_24 storeall:storemore 2011-09-02 10:04:59 ***
            322 del
            < ij>
            322 add
            > ij> Exception in thread "main" java.lang.NullPointerException
            Test Failed.
          • End: bug3498 jdk1.6.0_24 storeall:storemore 2011-09-02 10:05:02 ***

      Here's the full stack trace:

      Exception in thread "main" java.lang.NullPointerException
      at org.apache.derby.impl.sql.catalog.SequenceUpdater.updateCurrentValueOnDisk(Unknown Source)
      at org.apache.derby.impl.sql.catalog.SequenceUpdater.clean(Unknown Source)
      at org.apache.derby.impl.sql.catalog.SequenceUpdater.clearIdentity(Unknown Source)
      at org.apache.derby.impl.services.cache.ConcurrentCache.removeEntry(Unknown Source)
      at org.apache.derby.impl.services.cache.ConcurrentCache.ageOut(Unknown Source)
      at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.clearSequenceCaches(Unknown Source)
      at org.apache.derby.impl.db.BasicDatabase.stop(Unknown Source)
      at org.apache.derby.impl.services.monitor.TopService.stop(Unknown Source)
      at org.apache.derby.impl.services.monitor.TopService.shutdown(Unknown Source)
      at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(Unknown Source)
      at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(Unknown Source)
      at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
      at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source)
      at java.sql.DriverManager.getConnection(DriverManager.java:582)
      at java.sql.DriverManager.getConnection(DriverManager.java:207)
      at org.apache.derby.impl.tools.ij.utilMain.cleanupGo(Unknown Source)
      at org.apache.derby.impl.tools.ij.utilMain.go(Unknown Source)
      at org.apache.derby.impl.tools.ij.Main.go(Unknown Source)
      at org.apache.derby.impl.tools.ij.Main.mainCore(Unknown Source)
      at org.apache.derby.impl.tools.ij.Main.main(Unknown Source)
      at org.apache.derby.tools.ij.main(Unknown Source)

      1. derby-5398-01-ac-dummyTransaction.diff
        6 kB
        Rick Hillegas
      2. derby-5398-01-aa-dummyTransaction.diff
        2 kB
        Rick Hillegas
      3. derby-5398.sql
        1.0 kB
        Rick Hillegas

        Issue Links

          Activity

          Hide
          Kristian Waagan added a comment -

          Caused by DERBY-5390, but the question is why the code fails with an NPE.
          I haven't been able to reproduce this on my own PC so far, so this seems to be timing dependent.

          Show
          Kristian Waagan added a comment - Caused by DERBY-5390 , but the question is why the code fails with an NPE. I haven't been able to reproduce this on my own PC so far, so this seems to be timing dependent.
          Hide
          Myrna van Lunteren added a comment -

          For the record, I see this with 10.8 also. I can also reproduce it very easily with a recent insane build on that branch or on trunk on my - 4 years old - laptop.

          Show
          Myrna van Lunteren added a comment - For the record, I see this with 10.8 also. I can also reproduce it very easily with a recent insane build on that branch or on trunk on my - 4 years old - laptop.
          Hide
          Kristian Waagan added a comment -

          I backported the change that is causing this NPE (DERBY-5390). The change fixed one NPE and introduced another intermittent one (in a different location of the code)... What happened before was that the NPE was simply swallowed (catch Throwable), but there was no comment describing why Throwable was caught.

          If there is no other option, I can re-introduce the old behavior (swallow NPE) in 10.8. It would be good to understand why the NPE happens in the first place though.

          Show
          Kristian Waagan added a comment - I backported the change that is causing this NPE ( DERBY-5390 ). The change fixed one NPE and introduced another intermittent one (in a different location of the code)... What happened before was that the NPE was simply swallowed (catch Throwable), but there was no comment describing why Throwable was caught. If there is no other option, I can re-introduce the old behavior (swallow NPE) in 10.8. It would be good to understand why the NPE happens in the first place though.
          Hide
          Kristian Waagan added a comment -

          I was able to reproduce it too on my laptop, with the following stack:
          Exception in thread "main" java.lang.NullPointerException
          at org.apache.derby.impl.sql.catalog.SequenceUpdater.updateCurrentValueOnDisk(SequenceUpdater.java:403)
          at org.apache.derby.impl.sql.catalog.SequenceUpdater.clean(SequenceUpdater.java:201)
          at org.apache.derby.impl.sql.catalog.SequenceUpdater.clearIdentity(SequenceUpdater.java:215)
          at org.apache.derby.impl.services.cache.ConcurrentCache.removeEntry(ConcurrentCache.java:167)
          at org.apache.derby.impl.services.cache.ConcurrentCache.ageOut(ConcurrentCache.java:583)
          at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.clearSequenceCaches(DataDictionaryImpl.java:8836)
          at org.apache.derby.impl.db.BasicDatabase.stop(BasicDatabase.java:250)
          at org.apache.derby.impl.services.monitor.TopService.stop(TopService.java:443)
          at org.apache.derby.impl.services.monitor.TopService.shutdown(TopService.java:394)
          at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(BaseMonitor.java:229)
          at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(BaseMonitor.java:199)
          at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:241)

          Seems it fails because the language connection context cannot be obtained.
          Does this imply that the clearing the sequence caches is being done in the wrong place (i.e. too late)?

          Show
          Kristian Waagan added a comment - I was able to reproduce it too on my laptop, with the following stack: Exception in thread "main" java.lang.NullPointerException at org.apache.derby.impl.sql.catalog.SequenceUpdater.updateCurrentValueOnDisk(SequenceUpdater.java:403) at org.apache.derby.impl.sql.catalog.SequenceUpdater.clean(SequenceUpdater.java:201) at org.apache.derby.impl.sql.catalog.SequenceUpdater.clearIdentity(SequenceUpdater.java:215) at org.apache.derby.impl.services.cache.ConcurrentCache.removeEntry(ConcurrentCache.java:167) at org.apache.derby.impl.services.cache.ConcurrentCache.ageOut(ConcurrentCache.java:583) at org.apache.derby.impl.sql.catalog.DataDictionaryImpl.clearSequenceCaches(DataDictionaryImpl.java:8836) at org.apache.derby.impl.db.BasicDatabase.stop(BasicDatabase.java:250) at org.apache.derby.impl.services.monitor.TopService.stop(TopService.java:443) at org.apache.derby.impl.services.monitor.TopService.shutdown(TopService.java:394) at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(BaseMonitor.java:229) at org.apache.derby.impl.services.monitor.BaseMonitor.shutdown(BaseMonitor.java:199) at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:241) Seems it fails because the language connection context cannot be obtained. Does this imply that the clearing the sequence caches is being done in the wrong place (i.e. too late)?
          Hide
          Rick Hillegas added a comment -

          Attaching derby-5398.sql. This script shows the following behaviors related to this problem:

          1) If you shutdown the database in an orderly fashion, then there is enough context when we need it and sequences are able to flush their current positions to disk, reclaiming unused values.

          2) If you shutdown the database in an unorderly fashion, there isn't enough context when we need it and the sequences trip over an NPE when trying to reclaim their unused values.

          I can imagine several ways to fix this problem, listed in rising order of usefulness and complexity:

          i) Re-instate the original exception swallowing.

          ii) Have BasicDatabase check for the presence of enough context before trying to clear the sequence caches. If there isn't enough context then we are somewhere in an unorderly shutdown and the sequences can't reclaim their unused values.

          iii) Find another place in shutdown where DataDictionary.clearSequenceCaches() succeeds in more cases. If you find a place that always succeeds, then you have a solution to DERBY-5151.

          Show
          Rick Hillegas added a comment - Attaching derby-5398.sql. This script shows the following behaviors related to this problem: 1) If you shutdown the database in an orderly fashion, then there is enough context when we need it and sequences are able to flush their current positions to disk, reclaiming unused values. 2) If you shutdown the database in an unorderly fashion, there isn't enough context when we need it and the sequences trip over an NPE when trying to reclaim their unused values. I can imagine several ways to fix this problem, listed in rising order of usefulness and complexity: i) Re-instate the original exception swallowing. ii) Have BasicDatabase check for the presence of enough context before trying to clear the sequence caches. If there isn't enough context then we are somewhere in an unorderly shutdown and the sequences can't reclaim their unused values. iii) Find another place in shutdown where DataDictionary.clearSequenceCaches() succeeds in more cases. If you find a place that always succeeds, then you have a solution to DERBY-5151 .
          Hide
          Bryan Pendleton added a comment -

          I like (ii), depending on how awkward those checks are.

          Do you think there would be enough context left to be able to emit a message to derby.log if you can't flush the caches?

          Show
          Bryan Pendleton added a comment - I like (ii), depending on how awkward those checks are. Do you think there would be enough context left to be able to emit a message to derby.log if you can't flush the caches?
          Hide
          Knut Anders Hatlen added a comment -

          I don't think this is an issue with orderly vs unorderly shutdown, but rather database shutdown vs system shutdown. ij runs a system shutdown on exit, so simply exiting the script, like in the repro, doesn't actually cause an unorderly shutdown. I also see the NPE if I add an explicit system shutdown at the end of the repro script.

          Show
          Knut Anders Hatlen added a comment - I don't think this is an issue with orderly vs unorderly shutdown, but rather database shutdown vs system shutdown. ij runs a system shutdown on exit, so simply exiting the script, like in the repro, doesn't actually cause an unorderly shutdown. I also see the NPE if I add an explicit system shutdown at the end of the repro script.
          Hide
          Rick Hillegas added a comment -

          Thanks for that observation, Knut. It makes some sense that there is no LanguageConnectionContext during engine shutdown: there is no distinguished database, so there is no connection, so there is no LCC.

          The consequence of this bug is that sequences and identities leak values on orderly engine shutdown (but not on orderly database shutdown).

          The SequenceUpdater needs the LCC only in order to get its hands on a transaction for flushing the unused values. I am attaching derby-5398-01-aa-dummyTransaction.diff. This patch causes the SequenceUpdater to create a transient transaction for its work in the event that an LCC does not exist. This solution eliminates the NPE and causes the unused sequence values to be flushed so that the sequence does not leak values after an orderly engine shutdown.

          I have verified that derby-5398.sql passes now and that unused values are not leaked after the orderly engine shutdown. I have also verified that SequenceGeneratorTest continues to run cleanly. I will run a full regression suite now.

          On orderly shutdown, the transient transaction does not wait for the locks it needs in order to update the catalogs. If the transient transaction can't get those locks, then the sequence/identity will leak unused values. This seems better than delaying/hanging the engine shutdown. I would like to further polish this patch by printing a diagnostic to derby.log when the locks can't be obtained and values leak.

          Let me know if this approach sounds reasonable. Thanks.

          Touches the following file:

          M java/engine/org/apache/derby/impl/sql/catalog/SequenceUpdater.java

          Show
          Rick Hillegas added a comment - Thanks for that observation, Knut. It makes some sense that there is no LanguageConnectionContext during engine shutdown: there is no distinguished database, so there is no connection, so there is no LCC. The consequence of this bug is that sequences and identities leak values on orderly engine shutdown (but not on orderly database shutdown). The SequenceUpdater needs the LCC only in order to get its hands on a transaction for flushing the unused values. I am attaching derby-5398-01-aa-dummyTransaction.diff. This patch causes the SequenceUpdater to create a transient transaction for its work in the event that an LCC does not exist. This solution eliminates the NPE and causes the unused sequence values to be flushed so that the sequence does not leak values after an orderly engine shutdown. I have verified that derby-5398.sql passes now and that unused values are not leaked after the orderly engine shutdown. I have also verified that SequenceGeneratorTest continues to run cleanly. I will run a full regression suite now. On orderly shutdown, the transient transaction does not wait for the locks it needs in order to update the catalogs. If the transient transaction can't get those locks, then the sequence/identity will leak unused values. This seems better than delaying/hanging the engine shutdown. I would like to further polish this patch by printing a diagnostic to derby.log when the locks can't be obtained and values leak. Let me know if this approach sounds reasonable. Thanks. Touches the following file: M java/engine/org/apache/derby/impl/sql/catalog/SequenceUpdater.java
          Hide
          Knut Anders Hatlen added a comment -

          The explanation sounds reasonable, and so does the proposed fix. What I don't understand is why the bug is intermittent. Is the LCC sometimes available during engine shutdown and sometimes not?

          Show
          Knut Anders Hatlen added a comment - The explanation sounds reasonable, and so does the proposed fix. What I don't understand is why the bug is intermittent. Is the LCC sometimes available during engine shutdown and sometimes not?
          Hide
          Rick Hillegas added a comment -

          Tests passed cleanly for me on this patch except for the following issues:

          A) A trigger-related error in AlterTableTest which also occurs in a clean subversion client without the patch.

          B) Heisenbugs in NetworkServerControlClientCommandTest and InvalidLDAPServerAuthenticationTest which do not seem related to these changes and which do not recur when I run the tests standalone.

          The errors were:

          There were 2 errors:
          1) testDropColumn(org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest)java.sql.SQLException: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object.
          at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45)
          at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:256)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:400)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:348)
          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.EmbedStatement.execute(EmbedStatement.java:630)
          at org.apache.derby.impl.jdbc.EmbedStatement.executeUpdate(EmbedStatement.java:179)
          at org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest.testDropColumn(AlterTableTest.java:2492)
          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:113)
          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)
          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)
          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)
          Caused by: ERROR X0Y25: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object.
          at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:365)
          at org.apache.derby.impl.sql.execute.AlterTableConstantAction.columnDroppedAndTriggerDependencies(AlterTableConstantAction.java:1901)
          at org.apache.derby.impl.sql.execute.AlterTableConstantAction.dropColumnFromTable(AlterTableConstantAction.java:1748)
          at org.apache.derby.impl.sql.execute.AlterTableConstantAction.executeConstantActionBody(AlterTableConstantAction.java:507)
          at org.apache.derby.impl.sql.execute.AlterTableConstantAction.executeConstantAction(AlterTableConstantAction.java:276)
          at org.apache.derby.impl.sql.execute.MiscResultSet.open(MiscResultSet.java:61)
          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)
          ... 47 more
          2) testDropColumn(org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest)java.sql.SQLException: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object.
          at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:46)
          at org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:358)
          at org.apache.derby.client.am.Statement.executeUpdate(Statement.java:512)
          at org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest.testDropColumn(AlterTableTest.java:2492)
          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:113)
          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)
          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)
          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)
          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)
          Caused by: org.apache.derby.client.am.SqlException: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object.
          at org.apache.derby.client.am.Statement.completeSqlca(Statement.java:1836)
          at org.apache.derby.client.am.Statement.completeExecuteImmediate(Statement.java:1424)
          at org.apache.derby.client.net.NetStatementReply.parseEXCSQLIMMreply(NetStatementReply.java:208)
          at org.apache.derby.client.net.NetStatementReply.readExecuteImmediate(NetStatementReply.java:59)
          at org.apache.derby.client.net.StatementReply.readExecuteImmediate(StatementReply.java:45)
          at org.apache.derby.client.net.NetStatement.readExecuteImmediate_(NetStatement.java:124)
          at org.apache.derby.client.am.Statement.readExecuteImmediate(Statement.java:1420)
          at org.apache.derby.client.am.Statement.flowExecute(Statement.java:2144)
          at org.apache.derby.client.am.Statement.executeUpdateX(Statement.java:517)
          at org.apache.derby.client.am.Statement.executeUpdate(Statement.java:503)
          ... 54 more
          There were 2 failures:
          1) testPingWithWrongHost(org.apache.derbyTesting.functionTests.tests.derbynet.NetworkServerControlClientCommandTest)junit.framework.AssertionFailedError: Could not find expectedString:Unable to find host in output:<STDOUT> Wed Sep 07 17:37:57 PDT 2011 : Could not connect to Derby Network Server on host nothere, port 1527: Operation timed out
          <END STDOUT>
          <STDERR><END STDERR>

          at org.apache.derbyTesting.junit.BaseTestCase.assertExecJavaCmdAsExpected(BaseTestCase.java:520)
          at org.apache.derbyTesting.functionTests.tests.derbynet.NetworkServerControlClientCommandTest.assertFailedPing(NetworkServerControlClientCommandTest.java:147)
          at org.apache.derbyTesting.functionTests.tests.derbynet.NetworkServerControlClientCommandTest.testPingWithWrongHost(NetworkServerControlClientCommandTest.java:112)
          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:113)
          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)
          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)
          2) testInvalidLDAPServerConnectionError(org.apache.derbyTesting.functionTests.tests.jdbcapi.InvalidLDAPServerAuthenticationTest)junit.framework.AssertionFailedError
          at org.apache.derbyTesting.functionTests.tests.jdbcapi.InvalidLDAPServerAuthenticationTest.testInvalidLDAPServerConnectionError(InvalidLDAPServerAuthenticationTest.java:122)
          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:113)
          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)
          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)

          FAILURES!!!
          Tests run: 9776, Failures: 2, Errors: 2

          Show
          Rick Hillegas added a comment - Tests passed cleanly for me on this patch except for the following issues: A) A trigger-related error in AlterTableTest which also occurs in a clean subversion client without the patch. B) Heisenbugs in NetworkServerControlClientCommandTest and InvalidLDAPServerAuthenticationTest which do not seem related to these changes and which do not recur when I run the tests standalone. The errors were: There were 2 errors: 1) testDropColumn(org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest)java.sql.SQLException: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object. at org.apache.derby.impl.jdbc.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:45) at org.apache.derby.impl.jdbc.Util.generateCsSQLException(Util.java:256) at org.apache.derby.impl.jdbc.TransactionResourceImpl.wrapInSQLException(TransactionResourceImpl.java:400) at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(TransactionResourceImpl.java:348) 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.EmbedStatement.execute(EmbedStatement.java:630) at org.apache.derby.impl.jdbc.EmbedStatement.executeUpdate(EmbedStatement.java:179) at org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest.testDropColumn(AlterTableTest.java:2492) 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:113) 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) 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) 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) Caused by: ERROR X0Y25: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object. at org.apache.derby.iapi.error.StandardException.newException(StandardException.java:365) at org.apache.derby.impl.sql.execute.AlterTableConstantAction.columnDroppedAndTriggerDependencies(AlterTableConstantAction.java:1901) at org.apache.derby.impl.sql.execute.AlterTableConstantAction.dropColumnFromTable(AlterTableConstantAction.java:1748) at org.apache.derby.impl.sql.execute.AlterTableConstantAction.executeConstantActionBody(AlterTableConstantAction.java:507) at org.apache.derby.impl.sql.execute.AlterTableConstantAction.executeConstantAction(AlterTableConstantAction.java:276) at org.apache.derby.impl.sql.execute.MiscResultSet.open(MiscResultSet.java:61) 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) ... 47 more 2) testDropColumn(org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest)java.sql.SQLException: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object. at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(SQLExceptionFactory.java:46) at org.apache.derby.client.am.SqlException.getSQLException(SqlException.java:358) at org.apache.derby.client.am.Statement.executeUpdate(Statement.java:512) at org.apache.derbyTesting.functionTests.tests.lang.AlterTableTest.testDropColumn(AlterTableTest.java:2492) 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:113) 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) 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) 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) 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) Caused by: org.apache.derby.client.am.SqlException: Operation 'DROP COLUMN' cannot be performed on object 'A2' because TRIGGER 'ATDC_14_TRIGGER_1' is dependent on that object. at org.apache.derby.client.am.Statement.completeSqlca(Statement.java:1836) at org.apache.derby.client.am.Statement.completeExecuteImmediate(Statement.java:1424) at org.apache.derby.client.net.NetStatementReply.parseEXCSQLIMMreply(NetStatementReply.java:208) at org.apache.derby.client.net.NetStatementReply.readExecuteImmediate(NetStatementReply.java:59) at org.apache.derby.client.net.StatementReply.readExecuteImmediate(StatementReply.java:45) at org.apache.derby.client.net.NetStatement.readExecuteImmediate_(NetStatement.java:124) at org.apache.derby.client.am.Statement.readExecuteImmediate(Statement.java:1420) at org.apache.derby.client.am.Statement.flowExecute(Statement.java:2144) at org.apache.derby.client.am.Statement.executeUpdateX(Statement.java:517) at org.apache.derby.client.am.Statement.executeUpdate(Statement.java:503) ... 54 more There were 2 failures: 1) testPingWithWrongHost(org.apache.derbyTesting.functionTests.tests.derbynet.NetworkServerControlClientCommandTest)junit.framework.AssertionFailedError: Could not find expectedString:Unable to find host in output:<STDOUT> Wed Sep 07 17:37:57 PDT 2011 : Could not connect to Derby Network Server on host nothere, port 1527: Operation timed out <END STDOUT> <STDERR><END STDERR> at org.apache.derbyTesting.junit.BaseTestCase.assertExecJavaCmdAsExpected(BaseTestCase.java:520) at org.apache.derbyTesting.functionTests.tests.derbynet.NetworkServerControlClientCommandTest.assertFailedPing(NetworkServerControlClientCommandTest.java:147) at org.apache.derbyTesting.functionTests.tests.derbynet.NetworkServerControlClientCommandTest.testPingWithWrongHost(NetworkServerControlClientCommandTest.java:112) 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:113) 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) 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) 2) testInvalidLDAPServerConnectionError(org.apache.derbyTesting.functionTests.tests.jdbcapi.InvalidLDAPServerAuthenticationTest)junit.framework.AssertionFailedError at org.apache.derbyTesting.functionTests.tests.jdbcapi.InvalidLDAPServerAuthenticationTest.testInvalidLDAPServerConnectionError(InvalidLDAPServerAuthenticationTest.java:122) 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:113) 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) 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) FAILURES!!! Tests run: 9776, Failures: 2, Errors: 2
          Hide
          Rick Hillegas added a comment -

          Thanks for the vote of confidence, Knut. I don't know why the original problem in the storemore tests is intermittent.

          Show
          Rick Hillegas added a comment - Thanks for the vote of confidence, Knut. I don't know why the original problem in the storemore tests is intermittent.
          Hide
          Rick Hillegas added a comment -

          Attaching derby-5398-01-ac-dummyTransaction.diff. I am running regression tests now. This version makes two improvements to the previous version of the patch:

          1) Logs a diagnostic message to derby.log if we can't get the locks needed to flush the unused, preallocated sequence values.

          2) Adds a regression test to make sure that we don't leak sequence values after orderly engine shutdown.

          Touches the following files:

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

          M java/engine/org/apache/derby/impl/sql/catalog/SequenceUpdater.java

          The original change plus the new logging of a diagnostic message if we can't flush the values.

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

          M java/engine/org/apache/derby/loc/messages.xml
          M java/shared/org/apache/derby/shared/common/reference/SQLState.java

          The new diagnostic message.

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

          M java/testing/org/apache/derbyTesting/functionTests/tests/lang/SequenceGeneratorTest.java

          The new regression test.

          Show
          Rick Hillegas added a comment - Attaching derby-5398-01-ac-dummyTransaction.diff. I am running regression tests now. This version makes two improvements to the previous version of the patch: 1) Logs a diagnostic message to derby.log if we can't get the locks needed to flush the unused, preallocated sequence values. 2) Adds a regression test to make sure that we don't leak sequence values after orderly engine shutdown. Touches the following files: --------------- M java/engine/org/apache/derby/impl/sql/catalog/SequenceUpdater.java The original change plus the new logging of a diagnostic message if we can't flush the values. --------------- M java/engine/org/apache/derby/loc/messages.xml M java/shared/org/apache/derby/shared/common/reference/SQLState.java The new diagnostic message. --------------- M java/testing/org/apache/derbyTesting/functionTests/tests/lang/SequenceGeneratorTest.java The new regression test.
          Hide
          Mamta A. Satoor added a comment -

          Rick, the trigger test failure you noticed is related to my checkin yesterday for DERBY-5044. I am working on fixing the existing tests for DERBY-5044 which now should work because of yesterday's fix. Hope to have the tests checked in by later today or early tomorrow.

          Show
          Mamta A. Satoor added a comment - Rick, the trigger test failure you noticed is related to my checkin yesterday for DERBY-5044 . I am working on fixing the existing tests for DERBY-5044 which now should work because of yesterday's fix. Hope to have the tests checked in by later today or early tomorrow.
          Hide
          Rick Hillegas added a comment -

          Thanks for that information, Mamta. Except for that failure, tests ran cleanly on derby-5398-01-ac-dummyTransaction.diff. Committed to trunk at subversion revision 1166859.

          Show
          Rick Hillegas added a comment - Thanks for that information, Mamta. Except for that failure, tests ran cleanly on derby-5398-01-ac-dummyTransaction.diff. Committed to trunk at subversion revision 1166859.
          Hide
          Rick Hillegas added a comment -

          Ported 1166859 from trunk to 10.8 branch at subversion revision 1166868. Leaving the issue unresolved because the original issue was a heisenbug and we don't know yet whether the problem has just moved some place else in the storemore tests.

          Show
          Rick Hillegas added a comment - Ported 1166859 from trunk to 10.8 branch at subversion revision 1166868. Leaving the issue unresolved because the original issue was a heisenbug and we don't know yet whether the problem has just moved some place else in the storemore tests.
          Hide
          Myrna van Lunteren added a comment - - edited

          Somehow my comment was lost when I resolved this issue. Here it is:
          I superficially checked nightly results, and there are a number of failures in replication tests since this fix (some of which actually look like other issues, e.g. I saw DERBY-4269), but no more storemore test failures or NPEs.
          I am resolving this issue and suggest opening new one(s) for further replication issues if appropriate, so it can be properly marked as fixed in 10.8.2.

          Show
          Myrna van Lunteren added a comment - - edited Somehow my comment was lost when I resolved this issue. Here it is: I superficially checked nightly results, and there are a number of failures in replication tests since this fix (some of which actually look like other issues, e.g. I saw DERBY-4269 ), but no more storemore test failures or NPEs. I am resolving this issue and suggest opening new one(s) for further replication issues if appropriate, so it can be properly marked as fixed in 10.8.2.

            People

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

              Dates

              • Created:
                Updated:
                Resolved:

                Development