Re: Derby 10.5.3.0
On 16.11.10 14:47, Bergquist, Brett wrote: I am using Derby as a database as part of a Glassfish installation. I am processing JMS messages with each one causing access to the Derby database via Eclipselink. After about 80K to 100K messages processed, I have a hung system. I run jstack on the Derby network server and there is no deadlock. Also I run jstack on the Glassfish and there is no deadlock. In the thread stack for Glassfish I see a thread with the following stack trace: Hi Brett, Nothing concrete for this particular problem, but some ideas that might bring something more to the table: a) Can you replace derbyClient.jar in Glassfish with a newer version and reproduce? This should be as simple as shutting down Glassfish and replacing the file (you don't have to upgrade the server). b) If you have a large number of connections this won't do any good, but where is the DRDAConnThread thread in the network server when Derby has hung? c) Run the server with the debug build (there are some extra asserts in there for the session data piggyback mechanism), and for good measure, set derby.stream.error.logSeverityLevel=0. --- Note that DRDA protocol traces are likely to contain user data. Consider this before making them public. d) Spend some time learning how to enable DRDA tracing on the client (see [1]). e) Enable DRDA tracing on the server (see [1]). At first sight this looks like a protocol error, perhaps where both the server and the client are waiting for more data. Note that the DRDA traces aren't necessarily that easy to understand unless you're familiar with the protocol, so if you obtain them you may want to log a Jira issue [2] and attach them there. Hope this helps, -- Kristian [1] http://wiki.apache.org/db-derby/ProtocolDebuggingTips [2] https://issues.apache.org/jira/browse/DERBY p: thread-pool-1; w: 3 daemon prio=6 tid=0x5de34800 nid=0xb94 runnable [0x60abe000..0x60abfd94] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at org.apache.derby.client.net.Reply.fill(Unknown Source) at org.apache.derby.client.net.Reply.ensureALayerDataInBuffer(Unknown Source) at org.apache.derby.client.net.Reply.readDssHeader(Unknown Source) at org.apache.derby.client.net.Reply.startSameIdChainParse(Unknown Source) at org.apache.derby.client.net.NetConnectionReply.readExchangeServerAttributes(Unknown Source) at org.apache.derby.client.net.NetConnection.readServerAttributesAndKeyExchange(Unknown Source) at org.apache.derby.client.net.NetConnection.readAllConnectCommandsChained(Unknown Source) at org.apache.derby.client.net.NetConnection.readDeferredReset(Unknown Source) at org.apache.derby.client.net.NetAgent.readDeferredResetConnection(Unknown Source) at org.apache.derby.client.net.NetAgent.beginReadChain(Unknown Source) at org.apache.derby.client.am.Agent.flow(Unknown Source) at org.apache.derby.client.am.Statement.flowExecute(Unknown Source) at org.apache.derby.client.am.Statement.executeQueryX(Unknown Source) at org.apache.derby.client.am.Statement.executeQuery(Unknown Source) - locked 0x1d90dba0 (a org.apache.derby.client.net.NetConnection40) at org.apache.derby.client.am.Connection.getTransactionIsolation(Unknown Source) at org.apache.derby.client.am.LogicalConnection.getTransactionIsolation(Unknown Source) at com.sun.gjc.spi.ManagedConnectionFactory.resetIsolation(ManagedConnectionFactory.java:463) at com.sun.gjc.spi.ManagedConnection.resetConnectionProperties(ManagedConnection.java:354) at com.sun.gjc.spi.ManagedConnection.getConnection(ManagedConnection.java:328) at com.sun.enterprise.resource.ConnectorAllocator.fillInResourceObjects(ConnectorAllocator.java:155) at com.sun.enterprise.resource.AbstractResourcePool.getResource(AbstractResourcePool.java:514) at com.sun.enterprise.resource.PoolManagerImpl.getResourceFromPool(PoolManagerImpl.java:248) at com.sun.enterprise.resource.PoolManagerImpl.getResource(PoolManagerImpl.java:176) at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:337) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:189) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:165) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:158) This thread is making no progress at all. This is the one hanging my system. The derby log shows: 2010-11-15 23:57:46.593 GMT : Apache Derby Network Server - 10.5.3.0 - (802917)
RE: Derby 10.5.3.0
) - locked 0x22f00c60 (a org.apache.derby.impl.services.daemon.BasicDaemon) at org.apache.derby.impl.services.daemon.BasicDaemon.run(Unknown Source) at java.lang.Thread.run(Thread.java:619) DRDAConnThread_3 prio=6 tid=0x02f5e400 nid=0x2fa8 runnable [0x035ef000..0x035efc14] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at org.apache.derby.impl.drda.DDMReader.fill(Unknown Source) at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(Unknown Source) at org.apache.derby.impl.drda.DDMReader.readDssHeader(Unknown Source) at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown Source) at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source) Timer-0 daemon prio=6 tid=0x0303b400 nid=0x6774 in Object.wait() [0x0353f000..0x0353fd14] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on 0x22ee2388 (a java.util.TaskQueue) at java.lang.Object.wait(Object.java:485) at java.util.TimerThread.mainLoop(Timer.java:483) - locked 0x22ee2388 (a java.util.TaskQueue) at java.util.TimerThread.run(Timer.java:462) derby.antiGC daemon prio=2 tid=0x02e51c00 nid=0x5da4 in Object.wait() [0x034df000..0x034dfd94] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on 0x22ec01e0 (a org.apache.derby.impl.services.monitor.AntiGC) at java.lang.Object.wait(Object.java:485) at org.apache.derby.impl.services.monitor.AntiGC.run(Unknown Source) - locked 0x22ec01e0 (a org.apache.derby.impl.services.monitor.AntiGC) at java.lang.Thread.run(Thread.java:619) Low Memory Detector daemon prio=6 tid=0x02a6d000 nid=0x8b9c runnable [0x..0x] java.lang.Thread.State: RUNNABLE CompilerThread0 daemon prio=10 tid=0x02a68400 nid=0x3258 waiting on condition [0x..0x02d1f798] java.lang.Thread.State: RUNNABLE Attach Listener daemon prio=10 tid=0x02a67000 nid=0x46cc waiting on condition [0x..0x] java.lang.Thread.State: RUNNABLE Signal Dispatcher daemon prio=10 tid=0x02a66400 nid=0x4714 runnable [0x..0x] java.lang.Thread.State: RUNNABLE Finalizer daemon prio=8 tid=0x02a5e800 nid=0x1f24 in Object.wait() [0x02c2f000..0x02c2fc94] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on 0x22e60720 (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116) - locked 0x22e60720 (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159) Reference Handler daemon prio=10 tid=0x02a5d400 nid=0x5fbc in Object.wait() [0x02bdf000..0x02bdfd14] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on 0x22e607b0 (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:485) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) - locked 0x22e607b0 (a java.lang.ref.Reference$Lock) main prio=6 tid=0x002a6800 nid=0x8e90 in Object.wait() [0x0090f000..0x0090fe54] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on 0x22ea2e08 (a java.lang.Object) at java.lang.Object.wait(Object.java:485) at org.apache.derby.impl.drda.NetworkServerControlImpl.blockingStart(Unknown Source) - locked 0x22ea2e08 (a java.lang.Object) at org.apache.derby.impl.drda.NetworkServerControlImpl.executeWork(Unknown Source) at org.apache.derby.drda.NetworkServerControl.main(Unknown Source) VM Thread prio=10 tid=0x02a5c400 nid=0x83c4 runnable VM Periodic Task Thread prio=10 tid=0x02a77000 nid=0x5a64 waiting on condition JNI global references: 688 -Original Message- From: Kristian Waagan [mailto:kristian.waa...@oracle.com] Sent: Tuesday, November 16, 2010 10:22 AM To: derby-dev@db.apache.org Subject: Re: Derby 10.5.3.0 On 16.11.10 14:47, Bergquist, Brett wrote: I am using Derby as a database as part of a Glassfish installation. I am processing JMS messages with each one causing access to the Derby database via Eclipselink. After about 80K to 100K messages processed, I have a hung system. I run jstack on the Derby network server and there is no deadlock. Also I run jstack on the Glassfish and there is no deadlock. In the thread stack for Glassfish I see a thread with the following stack trace: Hi Brett, Nothing concrete for this particular problem, but some ideas that might bring something more to the table: a) Can you
Re: Derby 10.5.3.0
runnable VM Periodic Task Thread prio=10 tid=0x02a77000 nid=0x5a64 waiting on condition JNI global references: 688 -Original Message- From: Kristian Waagan [mailto:kristian.waa...@oracle.com] Sent: Tuesday, November 16, 2010 10:22 AM To: derby-dev@db.apache.org Subject: Re: Derby 10.5.3.0 On 16.11.10 14:47, Bergquist, Brett wrote: I am using Derby as a database as part of a Glassfish installation. I am processing JMS messages with each one causing access to the Derby database via Eclipselink. After about 80K to 100K messages processed, I have a hung system. I run jstack on the Derby network server and there is no deadlock. Also I run jstack on the Glassfish and there is no deadlock. In the thread stack for Glassfish I see a thread with the following stack trace: Hi Brett, Nothing concrete for this particular problem, but some ideas that might bring something more to the table: a) Can you replace derbyClient.jar in Glassfish with a newer version and reproduce? This should be as simple as shutting down Glassfish and replacing the file (you don't have to upgrade the server). b) If you have a large number of connections this won't do any good, but where is the DRDAConnThread thread in the network server when Derby has hung? c) Run the server with the debug build (there are some extra asserts in there for the session data piggyback mechanism), and for good measure, set derby.stream.error.logSeverityLevel=0. --- Note that DRDA protocol traces are likely to contain user data. Consider this before making them public. d) Spend some time learning how to enable DRDA tracing on the client (see [1]). e) Enable DRDA tracing on the server (see [1]). At first sight this looks like a protocol error, perhaps where both the server and the client are waiting for more data. Note that the DRDA traces aren't necessarily that easy to understand unless you're familiar with the protocol, so if you obtain them you may want to log a Jira issue [2] and attach them there. Hope this helps, -- Kristian [1] http://wiki.apache.org/db-derby/ProtocolDebuggingTips [2] https://issues.apache.org/jira/browse/DERBY p: thread-pool-1; w: 3 daemon prio=6 tid=0x5de34800 nid=0xb94 runnable [0x60abe000..0x60abfd94] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at org.apache.derby.client.net.Reply.fill(Unknown Source) at org.apache.derby.client.net.Reply.ensureALayerDataInBuffer(Unknown Source) at org.apache.derby.client.net.Reply.readDssHeader(Unknown Source) at org.apache.derby.client.net.Reply.startSameIdChainParse(Unknown Source) at org.apache.derby.client.net.NetConnectionReply.readExchangeServerAttributes(Unknown Source) at org.apache.derby.client.net.NetConnection.readServerAttributesAndKeyExchange(Unknown Source) at org.apache.derby.client.net.NetConnection.readAllConnectCommandsChained(Unknown Source) at org.apache.derby.client.net.NetConnection.readDeferredReset(Unknown Source) at org.apache.derby.client.net.NetAgent.readDeferredResetConnection(Unknown Source) at org.apache.derby.client.net.NetAgent.beginReadChain(Unknown Source) at org.apache.derby.client.am.Agent.flow(Unknown Source) at org.apache.derby.client.am.Statement.flowExecute(Unknown Source) at org.apache.derby.client.am.Statement.executeQueryX(Unknown Source) at org.apache.derby.client.am.Statement.executeQuery(Unknown Source) - locked0x1d90dba0 (a org.apache.derby.client.net.NetConnection40) at org.apache.derby.client.am.Connection.getTransactionIsolation(Unknown Source) at org.apache.derby.client.am.LogicalConnection.getTransactionIsolation(Unknown Source) at com.sun.gjc.spi.ManagedConnectionFactory.resetIsolation(ManagedConnectionFactory.java:463) at com.sun.gjc.spi.ManagedConnection.resetConnectionProperties(ManagedConnection.java:354) at com.sun.gjc.spi.ManagedConnection.getConnection(ManagedConnection.java:328) at com.sun.enterprise.resource.ConnectorAllocator.fillInResourceObjects(ConnectorAllocator.java:155) at com.sun.enterprise.resource.AbstractResourcePool.getResource(AbstractResourcePool.java:514) at com.sun.enterprise.resource.PoolManagerImpl.getResourceFromPool(PoolManagerImpl.java:248) at com.sun.enterprise.resource.PoolManagerImpl.getResource(PoolManagerImpl.java:176) at com.sun.enterprise.connectors.ConnectionManagerImpl.internalGetConnection(ConnectionManagerImpl.java:337) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:189) at com.sun.enterprise.connectors.ConnectionManagerImpl.allocateConnection(ConnectionManagerImpl.java:165
RE: Derby 10.5.3.0
Thanks again. The network server trace was after I could not connect with any client and I did not look closely at it ;) Before that point, there was a thread that looked like: NetworkServerThread_2 prio=6 tid=0x030fc800 nid=0x121c runnable [0x0357f000..0x0357fa94] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384) - locked 0x22efa880 (a java.net.SocksSocketImpl) at java.net.ServerSocket.implAccept(ServerSocket.java:453) at java.net.ServerSocket.accept(ServerSocket.java:421) at org.apache.derby.impl.drda.ClientThread$1.run(Unknown Source) at java.security.AccessController.doPrivileged(Native Method) at org.apache.derby.impl.drda.ClientThread.run(Unknown Source) That would be the server's connection handling thread, right? So you are correct, it seemed to be gone when the server was completely locked up. Unfortunately I was running within my IDE (Netbeans) and I guess it does not have it appending to the derby.log because whatever error message that might have been there is gone :( I will fix that! Yes, running under Windows as my test/development box. Java 1.6.0_03 is being used as that is what is being run in production at this moment. I don't want to change too much at once to ensure I know what I change has an effect, positive or negative. Not using time slicing, no SSL, no security on this test/development box. All good suggestions. I took a look at the DRDA stuff and will enable tracing on the next test run. Currently running a test and am up to about 60K transactions successful with no problem at this point using the non-XA client driver. If this runs for about 200K worth of transactions, I will put the other driver back in place and see if the problem re-appears to try to isolate it to the driver. Previously it has failed between 80K and 120K transactions each time, so this will be a good test. Again, thank you for help in pointing me to where to try to debug this. Much appreciated. Brett -Original Message- From: Kristian Waagan [mailto:kristian.waa...@oracle.com] Sent: Tuesday, November 16, 2010 10:57 AM To: derby-dev@db.apache.org Subject: Re: Derby 10.5.3.0 On 16.11.10 16:27, Bergquist, Brett wrote: Okay, thanks for the feedback. Just a little more info. I was using the XA client driver. I am now trying try reproduce with just the standard local client driver to see if this makes a difference. I don't actually need the distributed transaction support at this time. Running with the non-XA driver is a good idea, as the XA driver is a bit different from the other(s). Also, here is the jstack trace of the network control server process just in case it might trigger some insight. I don't see anything standing out however. Note that shortly there after, no connection to the database would succeed. I tried connecting with Squirrel SQL client and that also hung. As far as I can see from the stack trace below, there is no thread accepting new connections. Why has it died? Further questions/observations: o the Java version is fairly old. o are you using time slicing, session capping (maxThreads), SSL or a non-default Derby security mechanism? o is seems you are running on Windows. o have you checked that nothing is printed to the console? (where you start the server by running NetworkServerControl) Note that I'm just throwing stuff at you here :) The best way to get this debugged and fixed is to provide a runnable repro, but based on what I've learned so far that may include quite a bit of work... -- Kristian 2010-11-16 09:11:27 Full thread dump Java HotSpot(TM) Client VM (1.6.0_03-b05 mixed mode, sharing): DRDAConnThread_13 prio=6 tid=0x02e8f000 nid=0x66e4 runnable [0x0395f000..0x0395fa94] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at org.apache.derby.impl.drda.DDMReader.fill(Unknown Source) at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(Unknown Source) at org.apache.derby.impl.drda.DDMReader.readDssHeader(Unknown Source) at org.apache.derby.impl.drda.DRDAConnThread.processCommands(Unknown Source) at org.apache.derby.impl.drda.DRDAConnThread.run(Unknown Source) DRDAConnThread_12 prio=6 tid=0x02e8e800 nid=0x11f0 runnable [0x0390f000..0x0390fb14] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at org.apache.derby.impl.drda.DDMReader.fill(Unknown Source) at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(Unknown Source
RE: Derby 10.5.3.0
A follow up. The only change that I made to the system was to replace org.apache.derby.jdbc.ClientXADataSource ass the Datasource Classname and javax.sql.XADataSource to org.apache.derby.jdbc.ClientDataSource and javax.sql.DataSource respectively through the Glassfish Application Server's Admin Console. The hang has not happened through 140K transactions and previously it would hang before this point. So I am going to change back to using the XA data sources and see if the problem occurs again. -Original Message- From: Bergquist, Brett [mailto:br...@canoga.com] Sent: Tuesday, November 16, 2010 11:10 AM To: derby-dev@db.apache.org Subject: RE: Derby 10.5.3.0 Thanks again. The network server trace was after I could not connect with any client and I did not look closely at it ;) Before that point, there was a thread that looked like: NetworkServerThread_2 prio=6 tid=0x030fc800 nid=0x121c runnable [0x0357f000..0x0357fa94] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:384) - locked 0x22efa880 (a java.net.SocksSocketImpl) at java.net.ServerSocket.implAccept(ServerSocket.java:453) at java.net.ServerSocket.accept(ServerSocket.java:421) at org.apache.derby.impl.drda.ClientThread$1.run(Unknown Source) at java.security.AccessController.doPrivileged(Native Method) at org.apache.derby.impl.drda.ClientThread.run(Unknown Source) That would be the server's connection handling thread, right? So you are correct, it seemed to be gone when the server was completely locked up. Unfortunately I was running within my IDE (Netbeans) and I guess it does not have it appending to the derby.log because whatever error message that might have been there is gone :( I will fix that! Yes, running under Windows as my test/development box. Java 1.6.0_03 is being used as that is what is being run in production at this moment. I don't want to change too much at once to ensure I know what I change has an effect, positive or negative. Not using time slicing, no SSL, no security on this test/development box. All good suggestions. I took a look at the DRDA stuff and will enable tracing on the next test run. Currently running a test and am up to about 60K transactions successful with no problem at this point using the non-XA client driver. If this runs for about 200K worth of transactions, I will put the other driver back in place and see if the problem re-appears to try to isolate it to the driver. Previously it has failed between 80K and 120K transactions each time, so this will be a good test. Again, thank you for help in pointing me to where to try to debug this. Much appreciated. Brett -Original Message- From: Kristian Waagan [mailto:kristian.waa...@oracle.com] Sent: Tuesday, November 16, 2010 10:57 AM To: derby-dev@db.apache.org Subject: Re: Derby 10.5.3.0 On 16.11.10 16:27, Bergquist, Brett wrote: Okay, thanks for the feedback. Just a little more info. I was using the XA client driver. I am now trying try reproduce with just the standard local client driver to see if this makes a difference. I don't actually need the distributed transaction support at this time. Running with the non-XA driver is a good idea, as the XA driver is a bit different from the other(s). Also, here is the jstack trace of the network control server process just in case it might trigger some insight. I don't see anything standing out however. Note that shortly there after, no connection to the database would succeed. I tried connecting with Squirrel SQL client and that also hung. As far as I can see from the stack trace below, there is no thread accepting new connections. Why has it died? Further questions/observations: o the Java version is fairly old. o are you using time slicing, session capping (maxThreads), SSL or a non-default Derby security mechanism? o is seems you are running on Windows. o have you checked that nothing is printed to the console? (where you start the server by running NetworkServerControl) Note that I'm just throwing stuff at you here :) The best way to get this debugged and fixed is to provide a runnable repro, but based on what I've learned so far that may include quite a bit of work... -- Kristian 2010-11-16 09:11:27 Full thread dump Java HotSpot(TM) Client VM (1.6.0_03-b05 mixed mode, sharing): DRDAConnThread_13 prio=6 tid=0x02e8f000 nid=0x66e4 runnable [0x0395f000..0x0395fa94] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at org.apache.derby.impl.drda.DDMReader.fill(Unknown Source) at org.apache.derby.impl.drda.DDMReader.ensureALayerDataInBuffer(Unknown Source
Re: derby 10.5.3.0 pom issue
Kurt T Stam kurt.s...@gmail.com writes:
Hi guys,
The pom.xml in the Apache repo:
http://people.apache.org/repo/m2-ibiblio-rsync-repository/org/apache/derby/derby/10.5.3.0/derby-10.5.3.0.pom
shows the following issue:
[...]
When running maven they see the error:
Downloading:
http://download.java.net/maven/2/org/apache/derby/derby-project/${derby.version}/derby-project-${derby.version}.pom
[INFO]
[ERROR] FATAL ERROR
Can this please be fixed?
Hi Kurt,
This problem is being worked on. See
https://issues.apache.org/jira/browse/DERBY-4267 for details.
--
Knut Anders
