Derby
  1. Derby
  2. DERBY-5003

NPE in ReplicationRun_Local_3_p5 when stopping slave after purposely crashing master

    Details

    • Type: Bug Bug
    • Status: Open
    • Priority: Major Major
    • Resolution: Unresolved
    • Affects Version/s: 10.8.1.2, 10.10.2.0
    • Fix Version/s: None
    • Component/s: Replication
    • Urgency:
      Normal
    • Bug behavior facts:
      Regression Test Failure

      Description

      Derby.log trace of this: (Daily 1066867/2011-02-03 18:00:24 MET, JVM 1.5, Vista):

      NullPointerException in LogToFile.flush on slave:
      java.lang.NullPointerException
      at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source)
      at org.apache.derby.impl.store.raw.log.LogToFile.flushAll(Unknown Source)
      at org.apache.derby.impl.store.raw.log.LogToFile.stopReplicationSlaveRole(Unknown Source)
      at org.apache.derby.impl.store.replication.slave.SlaveController.stopSlave(Unknown Source)
      at org.apache.derby.impl.store.replication.slave.SlaveController.stopSlave(Unknown Source)
      at org.apache.derby.impl.db.SlaveDatabase.stopReplicationSlave(Unknown Source)
      at org.apache.derby.impl.jdbc.EmbedConnection.handleStopReplicationSlave(Unknown Source)
      at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source)
      at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(Unknown Source)
      at org.apache.derby.jdbc.Driver30.getNewEmbedConnection(Unknown Source)
      at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
      at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source)
      at org.apache.derby.impl.drda.Database.makeConnection(Unknown Source)
      at org.apache.derby.impl.drda.DRDAConnThread.getConnFromDatabaseName(Unknown Source)
      at org.apache.derby.impl.drda.DRDAConnThread.verifyUserIdPassword(Unknown Source)
      at org.apache.derby.impl.drda.DRDAConnThread.parseSECCHK(Unknown Source)
      at org.apache.derby.impl.drda.DRDAConnThread.parseDRDAConnection(Unknown Source)
      at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown Source)
      at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown
      Source)

      The client side stack dump:

      [Error/failure logged at Fri Feb 04 04:46:55 CET 2011]
      java.sql.SQLException: DERBY SQL error: SQLCODE: -1, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerExceptionXJ001.U
      at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(Unknown Source)
      at org.apache.derby.client.am.SqlException.getSQLException(Unknown Source)
      at org.apache.derby.jdbc.ClientDriver.connect(Unknown Source)
      at java.sql.DriverManager.getConnection(DriverManager.java:525)
      at java.sql.DriverManager.getConnection(DriverManager.java:193)
      at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:3445)
      at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:3395)
      at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun_Local_3_p5.testReplication_Local_3_p5_DERBY_3878(ReplicationRun_Local_3_p5.java:93)
      at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
      at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
      at java.lang.reflect.Method.invoke(Method.java:585)
      at junit.framework.TestCase.runTest(TestCase.java:164)
      at junit.framework.TestCase.runBare(TestCase.java:130)
      at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:112)
      at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.runBare(ReplicationRun.java:207)
      at junit.framework.TestResult$1.protect(TestResult.java:106)
      at junit.framework.TestResult.runProtected(TestResult.java:124)
      at junit.framework.TestResult.run(TestResult.java:109)
      at junit.framework.TestCase.run(TestCase.java:120)
      at junit.framework.TestSuite.runTest(TestSuite.java:230)
      at junit.framework.TestSuite.run(TestSuite.java:225)
      at junit.framework.TestSuite.runTest(TestSuite.java:230)
      at junit.framework.TestSuite.run(TestSuite.java:225)
      at junit.extensions.TestDecorator.basicRun(TestDecorator.java:24)
      at junit.extensions.TestSetup$1.protect(TestSetup.java:21)
      at junit.framework.TestResult.runProtected(TestResult.java:124)
      at junit.extensions.TestSetup.run(TestSetup.java:25)
      at junit.framework.TestSuite.runTest(TestSuite.java:230)
      at junit.framework.TestSuite.run(TestSuite.java:225)
      at junit.framework.TestSuite.runTest(TestSuite.java:230)
      at junit.framework.TestSuite.run(TestSuite.java:225)
      at junit.framework.TestSuite.runTest(TestSuite.java:230)
      at junit.framework.TestSuite.run(TestSuite.java:225)
      at junit.textui.TestRunner.doRun(TestRunner.java:121)
      at junit.textui.TestRunner.start(TestRunner.java:185)
      at junit.textui.TestRunner.main(TestRunner.java:143)
      Caused by: org.apache.derby.client.am.SqlException: DERBY SQL error: SQLCODE: -1, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerExceptionXJ001.U
      at org.apache.derby.client.am.Connection.completeSqlca(Unknown Source)
      at org.apache.derby.client.net.NetConnectionReply.parseRdbAccessFailed(Unknown Source)
      at org.apache.derby.client.net.NetConnectionReply.parseAccessRdbError(Unknown Source)
      at org.apache.derby.client.net.NetConnectionReply.parseACCRDBreply(Unknown Source)
      at org.apache.derby.client.net.NetConnectionReply.readAccessDatabase(Unknown Source)
      at org.apache.derby.client.net.NetConnection.readSecurityCheckAndAccessRdb(Unknown Source)
      at org.apache.derby.client.net.NetConnection.flowSecurityCheckAndAccessRdb(Unknown Source)
      at org.apache.derby.client.net.NetConnection.flowUSRIDONLconnect(Unknown Source)
      at org.apache.derby.client.net.NetConnection.flowConnect(Unknown Source)
      at org.apache.derby.client.net.NetConnection.<init>(Unknown Source)
      at org.apache.derby.client.net.ClientJDBCObjectFactoryImpl.newNetConnection(Unknown Source)
      ... 35 more

      1. db_slave-derby.log
        15 kB
        Dag H. Wanvik
      2. db_slave-derby.log.2
        13 kB
        Dag H. Wanvik

        Issue Links

          Activity

          Hide
          Myrna van Lunteren added a comment -
          Show
          Myrna van Lunteren added a comment - Failed again, trunk, windows, ibm 1.6 (SR15), see: http://people.apache.org/~myrnavl/derby_test_results/main/windows/testSummary-1572416.html
          Hide
          Mamta A. Satoor added a comment -
          Show
          Mamta A. Satoor added a comment - Failed again on trunk(1541374) with ibm 1.7 http://people.apache.org/~myrnavl/derby_test_results/main/windows/testSummary-1541374.html
          Hide
          Mike Matrigali added a comment -

          nightly regression test failure, null pointer during replication tests, on windows, 10.10, ibm15 jvm
          http://people.apache.org/~myrnavl/derby_test_results/v10_10/windows/testlog/ibm15/1489275-suites.All_diff.txt
          There was 1 error:
          1) testReplication_Local_3_p5_DERBY_3878(org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun_Local_3_p5)java.sql.SQLException: DERBY SQL error: ERRORCODE: 0, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerExceptionXJ001.U
          at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(Unknown Source)
          at org.apache.derby.client.am.SqlException.getSQLException(Unknown Source)
          at org.apache.derby.jdbc.ClientDriver.connect(Unknown Source)
          at java.sql.DriverManager.getConnection(DriverManager.java:572)
          at java.sql.DriverManager.getConnection(DriverManager.java:218)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2952)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2901)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun_Local_3_p5.testReplication_Local_3_p5_DERBY_3878(ReplicationRun_Local_3_p5.java:93)
          at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
          at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:79)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:117)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.runBare(ReplicationRun.java:247)
          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: DERBY SQL error: ERRORCODE: 0, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerExceptionXJ001.U
          at org.apache.derby.client.am.Connection.completeSqlca(Unknown Source)
          at org.apache.derby.client.net.NetConnectionReply.parseRdbAccessFailed(Unknown Source)
          at org.apache.derby.client.net.NetConnectionReply.parseAccessRdbError(Unknown Source)
          at org.apache.derby.client.net.NetConnectionReply.parseACCRDBreply(Unknown Source)
          at org.apache.derby.client.net.NetConnectionReply.readAccessDatabase(Unknown Source)
          at org.apache.derby.client.net.NetConnection.readSecurityCheckAndAccessRdb(Unknown Source)
          at org.apache.derby.client.net.NetConnection.flowSecurityCheckAndAccessRdb(Unknown Source)
          at org.apache.derby.client.net.NetConnection.flowUSRIDONLconnect(Unknown Source)
          at org.apache.derby.client.net.NetConnection.flowConnect(Unknown Source)
          at org.apache.derby.client.net.NetConnection.<init>(Unknown Source)
          at org.apache.derby.client.net.ClientJDBCObjectFactoryImpl.newNetConnection(Unknown Source)
          ... 35 more

          FAILURES!!!

          Show
          Mike Matrigali added a comment - nightly regression test failure, null pointer during replication tests, on windows, 10.10, ibm15 jvm http://people.apache.org/~myrnavl/derby_test_results/v10_10/windows/testlog/ibm15/1489275-suites.All_diff.txt There was 1 error: 1) testReplication_Local_3_p5_DERBY_3878(org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun_Local_3_p5)java.sql.SQLException: DERBY SQL error: ERRORCODE: 0, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerExceptionXJ001.U at org.apache.derby.client.am.SQLExceptionFactory.getSQLException(Unknown Source) at org.apache.derby.client.am.SqlException.getSQLException(Unknown Source) at org.apache.derby.jdbc.ClientDriver.connect(Unknown Source) at java.sql.DriverManager.getConnection(DriverManager.java:572) at java.sql.DriverManager.getConnection(DriverManager.java:218) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2952) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2901) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun_Local_3_p5.testReplication_Local_3_p5_DERBY_3878(ReplicationRun_Local_3_p5.java:93) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:79) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:117) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.runBare(ReplicationRun.java:247) 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: DERBY SQL error: ERRORCODE: 0, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerExceptionXJ001.U at org.apache.derby.client.am.Connection.completeSqlca(Unknown Source) at org.apache.derby.client.net.NetConnectionReply.parseRdbAccessFailed(Unknown Source) at org.apache.derby.client.net.NetConnectionReply.parseAccessRdbError(Unknown Source) at org.apache.derby.client.net.NetConnectionReply.parseACCRDBreply(Unknown Source) at org.apache.derby.client.net.NetConnectionReply.readAccessDatabase(Unknown Source) at org.apache.derby.client.net.NetConnection.readSecurityCheckAndAccessRdb(Unknown Source) at org.apache.derby.client.net.NetConnection.flowSecurityCheckAndAccessRdb(Unknown Source) at org.apache.derby.client.net.NetConnection.flowUSRIDONLconnect(Unknown Source) at org.apache.derby.client.net.NetConnection.flowConnect(Unknown Source) at org.apache.derby.client.net.NetConnection.<init>(Unknown Source) at org.apache.derby.client.net.ClientJDBCObjectFactoryImpl.newNetConnection(Unknown Source) ... 35 more FAILURES!!!
          Hide
          Knut Anders Hatlen added a comment -
          Show
          Knut Anders Hatlen added a comment - Also seen when testing the 10.8.2.2 release candidate: http://dbtg.foundry.sun.com/derby/test/10.8.2.2_RC/logs/jvm1.6/win7/suitesAll/report.txt
          Show
          Dag H. Wanvik added a comment - Saw this again: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/vista-64/1176935-suitesAll_diff.txt
          Hide
          Dag H. Wanvik added a comment - - edited

          Saw this again, but the slave derby.log file showed an NPE earlier this time, cf this stack from the uploaded file db_slave-derby.log.2:

          [dailies error report: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/vista/1152848-suitesAll_diff.txt]

          Replication slave role was stopped for database 'C:\cludev\jagtmp\autoderbyN_regression\suitesAll_7\log\db_slave\wombat'.
          java.lang.NullPointerException
          at org.apache.derby.impl.db.BasicDatabase.stop(Unknown Source)
          at org.apache.derby.impl.db.SlaveDatabase.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.db.DatabaseContextImpl.cleanupOnError(Unknown Source)
          at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown Source)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(Unknown Source)
          at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedConnection.internalStopReplicationSlave(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(Unknown Source)
          at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source)
          at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source)
          at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
          at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source)
          at org.apache.derby.impl.db.SlaveDatabase.handleShutdown(Unknown Source)
          at org.apache.derby.impl.db.SlaveDatabase.access$200(Unknown Source)
          at org.apache.derby.impl.db.SlaveDatabase$SlaveDatabaseBootThread.run(Unknown Source)
          at java.lang.Thread.run(Thread.java:662)
          ----------------------------------------------------------------
          Mon Aug 01 22:20:48 CEST 2011:
          Shutting down instance 601a400f-0131-8701-514f-000002c3da64 on database directory C:\cludev\jagtmp\autoderbyN_regression\suitesAll_7\log\db_slave\wombat with class loader sun.misc.Launcher$AppClassLoader@1ea2dfe
          Mon Aug 01 22:20:48 CEST 2011 Thread[DRDAConnThread_3,5,main] Cleanup action starting
          java.lang.NullPointerException
          at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source)
          at org.apache.derby.impl.store.raw.log.LogToFile.flushAll(Unknown Source)
          :

          I am not sure the first NPE is related, though, just an observation. The variable "dd" (data dictionary) is null when stopping here, cf. BasicDatabase#stop.
          But it happens as internalStopReplicationSlave shuts down the database after having verified that the slave has stopped, cf. line 1034 in EmbedConnection.

          Show
          Dag H. Wanvik added a comment - - edited Saw this again, but the slave derby.log file showed an NPE earlier this time, cf this stack from the uploaded file db_slave-derby.log.2: [dailies error report: http://dbtg.foundry.sun.com/derby/test/Daily/jvm1.6/testing/testlog/vista/1152848-suitesAll_diff.txt] Replication slave role was stopped for database 'C:\cludev\jagtmp\autoderbyN_regression\suitesAll_7\log\db_slave\wombat'. java.lang.NullPointerException at org.apache.derby.impl.db.BasicDatabase.stop(Unknown Source) at org.apache.derby.impl.db.SlaveDatabase.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.db.DatabaseContextImpl.cleanupOnError(Unknown Source) at org.apache.derby.iapi.services.context.ContextManager.cleanupOnError(Unknown Source) at org.apache.derby.impl.jdbc.TransactionResourceImpl.cleanupOnError(Unknown Source) at org.apache.derby.impl.jdbc.TransactionResourceImpl.handleException(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.handleException(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.internalStopReplicationSlave(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection.<init>(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection30.<init>(Unknown Source) at org.apache.derby.impl.jdbc.EmbedConnection40.<init>(Unknown Source) at org.apache.derby.jdbc.Driver40.getNewEmbedConnection(Unknown Source) at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) at org.apache.derby.jdbc.AutoloadedDriver.connect(Unknown Source) at org.apache.derby.impl.db.SlaveDatabase.handleShutdown(Unknown Source) at org.apache.derby.impl.db.SlaveDatabase.access$200(Unknown Source) at org.apache.derby.impl.db.SlaveDatabase$SlaveDatabaseBootThread.run(Unknown Source) at java.lang.Thread.run(Thread.java:662) ---------------------------------------------------------------- Mon Aug 01 22:20:48 CEST 2011: Shutting down instance 601a400f-0131-8701-514f-000002c3da64 on database directory C:\cludev\jagtmp\autoderbyN_regression\suitesAll_7\log\db_slave\wombat with class loader sun.misc.Launcher$AppClassLoader@1ea2dfe Mon Aug 01 22:20:48 CEST 2011 Thread [DRDAConnThread_3,5,main] Cleanup action starting java.lang.NullPointerException at org.apache.derby.impl.store.raw.log.LogToFile.flush(Unknown Source) at org.apache.derby.impl.store.raw.log.LogToFile.flushAll(Unknown Source) : I am not sure the first NPE is related, though, just an observation. The variable "dd" (data dictionary) is null when stopping here, cf. BasicDatabase#stop. But it happens as internalStopReplicationSlave shuts down the database after having verified that the slave has stopped, cf. line 1034 in EmbedConnection.
          Hide
          Knut Anders Hatlen added a comment -

          Also seen when testing the 10.8.1.0 release candidate on Windows Vista: http://dbtg.foundry.sun.com/derby/test/10.8.1.0_RC-2/logs/jvm1.6-64/vista-64/suitesAll/report.txt

          Show
          Knut Anders Hatlen added a comment - Also seen when testing the 10.8.1.0 release candidate on Windows Vista: http://dbtg.foundry.sun.com/derby/test/10.8.1.0_RC-2/logs/jvm1.6-64/vista-64/suitesAll/report.txt
          Hide
          Dag H. Wanvik added a comment -

          Saw the same exception stack in testReplication_Local_StateTest_part1_1, running trunk on Solaris 11, Java 6, using Knut's parallel test runner, this time with sane build, cf. derby.log from slave uploaded "db_slave-derby.log". NPE in LogToFile.flush when stopping slave.

          Show
          Dag H. Wanvik added a comment - Saw the same exception stack in testReplication_Local_StateTest_part1_1, running trunk on Solaris 11, Java 6, using Knut's parallel test runner, this time with sane build, cf. derby.log from slave uploaded "db_slave-derby.log". NPE in LogToFile.flush when stopping slave.
          Hide
          Dag H. Wanvik added a comment -

          These instabilities in the replication tests are very timing dependent
          in my experience. Not sure what sets this one off.

          Show
          Dag H. Wanvik added a comment - These instabilities in the replication tests are very timing dependent in my experience. Not sure what sets this one off.
          Hide
          Lily Wei added a comment -

          Did not reproduce it on windows 7 trunk svn 1071838

          Show
          Lily Wei added a comment - Did not reproduce it on windows 7 trunk svn 1071838
          Hide
          Dag H. Wanvik added a comment -

          I have saved the database images and log files bundle from this test (2Mb, a bit much to upload, so please contact me if you want to have a look at it).

          Show
          Dag H. Wanvik added a comment - I have saved the database images and log files bundle from this test (2Mb, a bit much to upload, so please contact me if you want to have a look at it).

            People

            • Assignee:
              Unassigned
              Reporter:
              Dag H. Wanvik
            • Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:

                Development