Derby
  1. Derby
  2. DERBY-5003

NPE in ReplicationRun_Local_3_p5 when stopping slave after purposefully 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. D5003_080714.jar
        7 kB
        Myrna van Lunteren
      2. derby-5003-diagnostics.diff
        6 kB
        Dag H. Wanvik
      3. db_slave-derby.log.2
        13 kB
        Dag H. Wanvik
      4. db_slave-derby.log
        15 kB
        Dag H. Wanvik

        Issue Links

          Activity

          Hide
          Dag H. Wanvik added a comment - - edited

          The NPE seems to stem from this code:

          //add active buffers to dirty buffer list
          //to flush to the disk.
          logOut.switchLogBuffer();
           

          so the variable "logOut" must be null.

          Show
          Dag H. Wanvik added a comment - - edited The NPE seems to stem from this code: //add active buffers to dirty buffer list //to flush to the disk. logOut.switchLogBuffer(); so the variable "logOut" must be null.
          Hide
          Dag H. Wanvik added a comment - - edited

          Saw this last night: http://javadb.se.oracle.com/javadb-testing/request_5595282/
          Here is the stack trace on derby.log:

          java.lang.NullPointerException
          at org.apache.derby.impl.store.raw.log.LogToFile.flush(LogToFile.java:4077)
          at org.apache.derby.impl.store.raw.log.LogToFile.flushAll(LogToFile.java:1862)
          at org.apache.derby.impl.store.raw.log.LogToFile.stopReplicationSlaveRole(LogToFile.java:5250)
          at org.apache.derby.impl.store.replication.slave.SlaveController.stopSlave(SlaveController.java:266)
          at org.apache.derby.impl.store.replication.slave.SlaveController.stopSlave(SlaveController.java:280)
          at org.apache.derby.impl.db.SlaveDatabase.stopReplicationSlave(SlaveDatabase.java:255)
          at org.apache.derby.impl.jdbc.EmbedConnection.handleStopReplicationSlave(EmbedConnection.java:1026)
          at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:371)
          at org.apache.derby.jdbc.InternalDriver.getNewEmbedConnection(InternalDriver.java:647)
          at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:301)
          at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:932)
          at org.apache.derby.jdbc.EmbeddedDriver.connect(EmbeddedDriver.java:125)
          at org.apache.derby.impl.drda.Database.makeConnection(Database.java:253)
          at org.apache.derby.impl.drda.DRDAConnThread.getConnFromDatabaseName(DRDAConnThread.java:1472)
          at org.apache.derby.impl.drda.DRDAConnThread.verifyUserIdPassword(DRDAConnThread.java:1422)
          at org.apache.derby.impl.drda.DRDAConnThread.parseSECCHK(DRDAConnThread.java:3376)
          at org.apache.derby.impl.drda.DRDAConnThread.parseDRDAConnection(DRDAConnThread.java:1206)
          at org.apache.derby.impl.drda.DRDAConnThread.processCommands(DRDAConnThread.java:1006)
          at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:296)
          
          Show
          Dag H. Wanvik added a comment - - edited Saw this last night: http://javadb.se.oracle.com/javadb-testing/request_5595282/ Here is the stack trace on derby.log: java.lang.NullPointerException at org.apache.derby.impl.store.raw.log.LogToFile.flush(LogToFile.java:4077) at org.apache.derby.impl.store.raw.log.LogToFile.flushAll(LogToFile.java:1862) at org.apache.derby.impl.store.raw.log.LogToFile.stopReplicationSlaveRole(LogToFile.java:5250) at org.apache.derby.impl.store.replication.slave.SlaveController.stopSlave(SlaveController.java:266) at org.apache.derby.impl.store.replication.slave.SlaveController.stopSlave(SlaveController.java:280) at org.apache.derby.impl.db.SlaveDatabase.stopReplicationSlave(SlaveDatabase.java:255) at org.apache.derby.impl.jdbc.EmbedConnection.handleStopReplicationSlave(EmbedConnection.java:1026) at org.apache.derby.impl.jdbc.EmbedConnection.<init>(EmbedConnection.java:371) at org.apache.derby.jdbc.InternalDriver.getNewEmbedConnection(InternalDriver.java:647) at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:301) at org.apache.derby.jdbc.InternalDriver.connect(InternalDriver.java:932) at org.apache.derby.jdbc.EmbeddedDriver.connect(EmbeddedDriver.java:125) at org.apache.derby.impl.drda.Database.makeConnection(Database.java:253) at org.apache.derby.impl.drda.DRDAConnThread.getConnFromDatabaseName(DRDAConnThread.java:1472) at org.apache.derby.impl.drda.DRDAConnThread.verifyUserIdPassword(DRDAConnThread.java:1422) at org.apache.derby.impl.drda.DRDAConnThread.parseSECCHK(DRDAConnThread.java:3376) at org.apache.derby.impl.drda.DRDAConnThread.parseDRDAConnection(DRDAConnThread.java:1206) at org.apache.derby.impl.drda.DRDAConnThread.processCommands(DRDAConnThread.java:1006) at org.apache.derby.impl.drda.DRDAConnThread.run(DRDAConnThread.java:296)
          Hide
          Myrna van Lunteren added a comment -

          Unfortunately I don't usually run with sane jars.
          I ran the test 100x with (trunk) sane jars on the same machine where I saw the problem, but it didn't show...

          Show
          Myrna van Lunteren added a comment - Unfortunately I don't usually run with sane jars. I ran the test 100x with (trunk) sane jars on the same machine where I saw the problem, but it didn't show...
          Hide
          Dag H. Wanvik added a comment -

          Thanks, Myrna. Unfortunately that jar contains logs from an insane derby jar, so it doesn't show the line numbers. This is the segment I am interested in (from the slave's derby.log):

          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)
          

          I guess we'll just have to wait till it hits again.

          Show
          Dag H. Wanvik added a comment - Thanks, Myrna. Unfortunately that jar contains logs from an insane derby jar, so it doesn't show the line numbers. This is the segment I am interested in (from the slave's derby.log): 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) I guess we'll just have to wait till it hits again.
          Hide
          Myrna van Lunteren added a comment -

          I jarred up the following files from the fail directory from the 10.11.1.1 RC2 (build 1616546) run for Embedded (i.e. from subdir Embedded_40/ReplicationRun_Local_3_p5/testReplication_Local_3_p5_DERBY_3878):
          db_master-derby.log
          db_slave-derby.log
          derby.log
          error-stacktrace.out
          Note that this was on a Windows 2008 machine (on VMWare), and the failure was with Oracle Hotspot jdk 1.8 (b132)

          Show
          Myrna van Lunteren added a comment - I jarred up the following files from the fail directory from the 10.11.1.1 RC2 (build 1616546) run for Embedded (i.e. from subdir Embedded_40/ReplicationRun_Local_3_p5/testReplication_Local_3_p5_DERBY_3878): db_master-derby.log db_slave-derby.log derby.log error-stacktrace.out Note that this was on a Windows 2008 machine (on VMWare), and the failure was with Oracle Hotspot jdk 1.8 (b132)
          Hide
          ASF subversion and git services added a comment -

          Commit 1617484 from Dag H. Wanvik in branch 'code/trunk'
          [ https://svn.apache.org/r1617484 ]

          DERBY-5003 NPE in ReplicationRun_Local_3_p5 when stopping slave after purposefully crashing master

          Patch to collect diagnostics (sane jars only): derby-5003-diagnostics.diff

          Show
          ASF subversion and git services added a comment - Commit 1617484 from Dag H. Wanvik in branch 'code/trunk' [ https://svn.apache.org/r1617484 ] DERBY-5003 NPE in ReplicationRun_Local_3_p5 when stopping slave after purposefully crashing master Patch to collect diagnostics (sane jars only): derby-5003-diagnostics.diff
          Hide
          Dag H. Wanvik added a comment -

          Myrna, you had two tests on trunk that saw this error. Do you have derby.log for any of those (so we can see the exact line of the NPE)?

          Show
          Dag H. Wanvik added a comment - Myrna, you had two tests on trunk that saw this error. Do you have derby.log for any of those (so we can see the exact line of the NPE)?
          Hide
          Dag H. Wanvik added a comment - - edited

          I can't reproduce this, so I am uploading a patch to print the state of LogToFile to derby.log at the moment we see this NPE derby-5003-diagnostics.diff (with sane jars only).

          Show
          Dag H. Wanvik added a comment - - edited I can't reproduce this, so I am uploading a patch to print the state of LogToFile to derby.log at the moment we see this NPE derby-5003-diagnostics.diff (with sane jars only).
          Hide
          Dag H. Wanvik added a comment -

          Hmm, no it seems the slave will try to reconnect to the master forever, unless it gets closed down, cf. SlaveController#handleDisconnect.

          Show
          Dag H. Wanvik added a comment - Hmm, no it seems the slave will try to reconnect to the master forever, unless it gets closed down, cf. SlaveController#handleDisconnect.
          Hide
          Dag H. Wanvik added a comment -

          I suspect the NPE comes from FileToLog#logOut being null, but I don't yet have a theory how that can happen in this scenario. When the slave detects that the master is gone, could there be some kind of race which thread stops the slave? [the test does a) kill the master, b) stop slave], cf. line 91 in ReplicationRun_Local_3_p5.

          Show
          Dag H. Wanvik added a comment - I suspect the NPE comes from FileToLog#logOut being null, but I don't yet have a theory how that can happen in this scenario. When the slave detects that the master is gone, could there be some kind of race which thread stops the slave? [the test does a) kill the master, b) stop slave] , cf. line 91 in ReplicationRun_Local_3_p5.
          Hide
          Myrna van Lunteren added a comment -

          This also failed during testing of the 10.11.1.1 RC2 (built at revision 1616546), with a somewhat different error stack trace:

          ---------------------------------------------------------
          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.NullPointerException XJ001.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:664)
          at java.sql.DriverManager.getConnection(DriverManager.java:270)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2948)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2897)
          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:62)
          at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
          at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:118)
          at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.runBare(ReplicationRun.java:243)
          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 XJ001: DERBY SQL error: ERRORCODE: 0, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerException XJ001.U
          at org.apache.derby.client.am.ClientConnection.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)
          ... 33 more
          ---------------------------------------------------------
          The NPE in the db_slave-derby.log
          ---------------------------------------------------------
          Thu Aug 07 21:10:27 PDT 2014 Thread[DRDAConnThread_2,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)
          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.jdbc.InternalDriver.getNewEmbedConnection(Unknown Source)
          at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
          at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source)
          at org.apache.derby.jdbc.EmbeddedDriver.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)
          Cleanup action completed
          ---------------------------------------------------------

          Show
          Myrna van Lunteren added a comment - This also failed during testing of the 10.11.1.1 RC2 (built at revision 1616546), with a somewhat different error stack trace: --------------------------------------------------------- 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.NullPointerException XJ001.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:664) at java.sql.DriverManager.getConnection(DriverManager.java:270) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2948) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.stopSlave(ReplicationRun.java:2897) 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:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at org.apache.derbyTesting.junit.BaseTestCase.runBare(BaseTestCase.java:118) at org.apache.derbyTesting.functionTests.tests.replicationTests.ReplicationRun.runBare(ReplicationRun.java:243) 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 XJ001: DERBY SQL error: ERRORCODE: 0, SQLSTATE: XJ001, SQLERRMC: java.lang.NullPointerException XJ001.U at org.apache.derby.client.am.ClientConnection.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) ... 33 more --------------------------------------------------------- The NPE in the db_slave-derby.log --------------------------------------------------------- Thu Aug 07 21:10:27 PDT 2014 Thread [DRDAConnThread_2,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) 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.jdbc.InternalDriver.getNewEmbedConnection(Unknown Source) at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) at org.apache.derby.jdbc.InternalDriver.connect(Unknown Source) at org.apache.derby.jdbc.EmbeddedDriver.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) Cleanup action completed ---------------------------------------------------------
          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:
              5 Start watching this issue

              Dates

              • Created:
                Updated:

                Development