You are viewing a plain text version of this content. The canonical link for it is here.
Posted to derby-dev@db.apache.org by "Bergquist, Brett" <Br...@canoga.com> on 2010/11/16 14:47:51 UTC
Derby 10.5.3.0
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:
"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) started and ready to accept connections on port 1527
----------------------------------------------------------------
2010-11-16 00:00:20.078 GMT:
Booting Derby version The Apache Software Foundation - Apache Derby - 10.5.3.0 - (802917): instance a816c00e-012c-51f9-12b2-0000376d74d3
on database directory C:\Documents and Settings\Brett Bergquist\.netbeans-derby\csemdb
Database Class Loader started - derby.database.classpath='CSEM.csemderby'
(END)
The rest of Glassfish is up and running as well as other parts of my application. This one thread, however, is causing my JMS processing to be hung.
This is the second time in two days of testing that this has occurred. The previous lockup has exactly the same thread stack traceback in a few other threads, all from different database queries, all stuck at the same point. Restarting the derby network server, caused the condition to clear up as far as the application server is concerned, so I am pretty confident it is related to derby.
Any help on where to look to find this problem will be greatly appreciated.
Brett
RE: Derby 10.5.3.0
Posted by "Bergquist, Brett" <Br...@canoga.com>.
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:Brett@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.waagan@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)
> 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_10" prio=6 tid=0x03136c00 nid=0x2098 runnable [0x0386f000..0x0386fc14]
> 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_8" prio=6 tid=0x02b29000 nid=0x3094 runnable [0x037cf000..0x037cfd14]
> 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_6" prio=6 tid=0x03119400 nid=0x2a7c runnable [0x0372f000..0x0372fa14]
> 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_4" prio=6 tid=0x02a41800 nid=0x83f4 runnable [0x0368f000..0x0368fb14]
> 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)
>
> "derby.rawStoreDaemon" daemon prio=6 tid=0x030aa000 nid=0x2c44 in Object.wait() [0x0363f000..0x0363fb94]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on<0x22f00c60> (a org.apache.derby.impl.services.daemon.BasicDaemon)
> at org.apache.derby.impl.services.daemon.BasicDaemon.rest(Unknown Source)
> - 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 [0x00000000..0x00000000]
> java.lang.Thread.State: RUNNABLE
>
> "CompilerThread0" daemon prio=10 tid=0x02a68400 nid=0x3258 waiting on condition [0x00000000..0x02d1f798]
> java.lang.Thread.State: RUNNABLE
>
> "Attach Listener" daemon prio=10 tid=0x02a67000 nid=0x46cc waiting on condition [0x00000000..0x00000000]
> java.lang.Thread.State: RUNNABLE
>
> "Signal Dispatcher" daemon prio=10 tid=0x02a66400 nid=0x4714 runnable [0x00000000..0x00000000]
> 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.waagan@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)
>>
>> - 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) started and ready to accept connections on port 1527
>>
>> ----------------------------------------------------------------
>>
>> 2010-11-16 00:00:20.078 GMT:
>>
>> Booting Derby version The Apache Software Foundation - Apache Derby -
>> 10.5.3.0 - (802917): instance a816c00e-012c-51f9-12b2-0000376d74d3
>>
>> on database directory C:\Documents and Settings\Brett
>> Bergquist\.netbeans-derby\csemdb
>>
>> Database Class Loader started - derby.database.classpath='CSEM.csemderby'
>>
>> (END)
>>
>> The rest of Glassfish is up and running as well as other parts of my
>> application. This one thread, however, is causing my JMS processing
>> to be hung.
>>
>> This is the second time in two days of testing that this has
>> occurred. The previous lockup has exactly the same thread stack
>> traceback in a few other threads, all from different database queries,
>> all stuck at the same point. Restarting the derby network server,
>> caused the condition to clear up as far as the application server is
>> concerned, so I am pretty confident it is related to derby.
>>
>> Any help on where to look to find this problem will be greatly
>> appreciated.
>>
>> Brett
>>
>
>
RE: Derby 10.5.3.0
Posted by "Bergquist, Brett" <Br...@canoga.com>.
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.waagan@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)
> 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_10" prio=6 tid=0x03136c00 nid=0x2098 runnable [0x0386f000..0x0386fc14]
> 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_8" prio=6 tid=0x02b29000 nid=0x3094 runnable [0x037cf000..0x037cfd14]
> 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_6" prio=6 tid=0x03119400 nid=0x2a7c runnable [0x0372f000..0x0372fa14]
> 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_4" prio=6 tid=0x02a41800 nid=0x83f4 runnable [0x0368f000..0x0368fb14]
> 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)
>
> "derby.rawStoreDaemon" daemon prio=6 tid=0x030aa000 nid=0x2c44 in Object.wait() [0x0363f000..0x0363fb94]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on<0x22f00c60> (a org.apache.derby.impl.services.daemon.BasicDaemon)
> at org.apache.derby.impl.services.daemon.BasicDaemon.rest(Unknown Source)
> - 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 [0x00000000..0x00000000]
> java.lang.Thread.State: RUNNABLE
>
> "CompilerThread0" daemon prio=10 tid=0x02a68400 nid=0x3258 waiting on condition [0x00000000..0x02d1f798]
> java.lang.Thread.State: RUNNABLE
>
> "Attach Listener" daemon prio=10 tid=0x02a67000 nid=0x46cc waiting on condition [0x00000000..0x00000000]
> java.lang.Thread.State: RUNNABLE
>
> "Signal Dispatcher" daemon prio=10 tid=0x02a66400 nid=0x4714 runnable [0x00000000..0x00000000]
> 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.waagan@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)
>>
>> - 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) started and ready to accept connections on port 1527
>>
>> ----------------------------------------------------------------
>>
>> 2010-11-16 00:00:20.078 GMT:
>>
>> Booting Derby version The Apache Software Foundation - Apache Derby -
>> 10.5.3.0 - (802917): instance a816c00e-012c-51f9-12b2-0000376d74d3
>>
>> on database directory C:\Documents and Settings\Brett
>> Bergquist\.netbeans-derby\csemdb
>>
>> Database Class Loader started - derby.database.classpath='CSEM.csemderby'
>>
>> (END)
>>
>> The rest of Glassfish is up and running as well as other parts of my
>> application. This one thread, however, is causing my JMS processing
>> to be hung.
>>
>> This is the second time in two days of testing that this has
>> occurred. The previous lockup has exactly the same thread stack
>> traceback in a few other threads, all from different database queries,
>> all stuck at the same point. Restarting the derby network server,
>> caused the condition to clear up as far as the application server is
>> concerned, so I am pretty confident it is related to derby.
>>
>> Any help on where to look to find this problem will be greatly
>> appreciated.
>>
>> Brett
>>
>
>
Re: Derby 10.5.3.0
Posted by Kristian Waagan <kr...@oracle.com>.
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)
> 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_10" prio=6 tid=0x03136c00 nid=0x2098 runnable [0x0386f000..0x0386fc14]
> 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_8" prio=6 tid=0x02b29000 nid=0x3094 runnable [0x037cf000..0x037cfd14]
> 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_6" prio=6 tid=0x03119400 nid=0x2a7c runnable [0x0372f000..0x0372fa14]
> 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_4" prio=6 tid=0x02a41800 nid=0x83f4 runnable [0x0368f000..0x0368fb14]
> 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)
>
> "derby.rawStoreDaemon" daemon prio=6 tid=0x030aa000 nid=0x2c44 in Object.wait() [0x0363f000..0x0363fb94]
> java.lang.Thread.State: TIMED_WAITING (on object monitor)
> at java.lang.Object.wait(Native Method)
> - waiting on<0x22f00c60> (a org.apache.derby.impl.services.daemon.BasicDaemon)
> at org.apache.derby.impl.services.daemon.BasicDaemon.rest(Unknown Source)
> - 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 [0x00000000..0x00000000]
> java.lang.Thread.State: RUNNABLE
>
> "CompilerThread0" daemon prio=10 tid=0x02a68400 nid=0x3258 waiting on condition [0x00000000..0x02d1f798]
> java.lang.Thread.State: RUNNABLE
>
> "Attach Listener" daemon prio=10 tid=0x02a67000 nid=0x46cc waiting on condition [0x00000000..0x00000000]
> java.lang.Thread.State: RUNNABLE
>
> "Signal Dispatcher" daemon prio=10 tid=0x02a66400 nid=0x4714 runnable [0x00000000..0x00000000]
> 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.waagan@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)
>>
>> - 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) started and ready to accept connections on port 1527
>>
>> ----------------------------------------------------------------
>>
>> 2010-11-16 00:00:20.078 GMT:
>>
>> Booting Derby version The Apache Software Foundation - Apache Derby -
>> 10.5.3.0 - (802917): instance a816c00e-012c-51f9-12b2-0000376d74d3
>>
>> on database directory C:\Documents and Settings\Brett
>> Bergquist\.netbeans-derby\csemdb
>>
>> Database Class Loader started - derby.database.classpath='CSEM.csemderby'
>>
>> (END)
>>
>> The rest of Glassfish is up and running as well as other parts of my
>> application. This one thread, however, is causing my JMS processing
>> to be hung.
>>
>> This is the second time in two days of testing that this has
>> occurred. The previous lockup has exactly the same thread stack
>> traceback in a few other threads, all from different database queries,
>> all stuck at the same point. Restarting the derby network server,
>> caused the condition to clear up as far as the application server is
>> concerned, so I am pretty confident it is related to derby.
>>
>> Any help on where to look to find this problem will be greatly
>> appreciated.
>>
>> Brett
>>
>
>
RE: Derby 10.5.3.0
Posted by "Bergquist, Brett" <Br...@canoga.com>.
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.
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.
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)
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_10" prio=6 tid=0x03136c00 nid=0x2098 runnable [0x0386f000..0x0386fc14]
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_8" prio=6 tid=0x02b29000 nid=0x3094 runnable [0x037cf000..0x037cfd14]
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_6" prio=6 tid=0x03119400 nid=0x2a7c runnable [0x0372f000..0x0372fa14]
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_4" prio=6 tid=0x02a41800 nid=0x83f4 runnable [0x0368f000..0x0368fb14]
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)
"derby.rawStoreDaemon" daemon prio=6 tid=0x030aa000 nid=0x2c44 in Object.wait() [0x0363f000..0x0363fb94]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x22f00c60> (a org.apache.derby.impl.services.daemon.BasicDaemon)
at org.apache.derby.impl.services.daemon.BasicDaemon.rest(Unknown Source)
- 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 [0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE
"CompilerThread0" daemon prio=10 tid=0x02a68400 nid=0x3258 waiting on condition [0x00000000..0x02d1f798]
java.lang.Thread.State: RUNNABLE
"Attach Listener" daemon prio=10 tid=0x02a67000 nid=0x46cc waiting on condition [0x00000000..0x00000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=10 tid=0x02a66400 nid=0x4714 runnable [0x00000000..0x00000000]
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.waagan@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)
>
> - 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) started and ready to accept connections on port 1527
>
> ----------------------------------------------------------------
>
> 2010-11-16 00:00:20.078 GMT:
>
> Booting Derby version The Apache Software Foundation - Apache Derby -
> 10.5.3.0 - (802917): instance a816c00e-012c-51f9-12b2-0000376d74d3
>
> on database directory C:\Documents and Settings\Brett
> Bergquist\.netbeans-derby\csemdb
>
> Database Class Loader started - derby.database.classpath='CSEM.csemderby'
>
> (END)
>
> The rest of Glassfish is up and running as well as other parts of my
> application. This one thread, however, is causing my JMS processing
> to be hung.
>
> This is the second time in two days of testing that this has
> occurred. The previous lockup has exactly the same thread stack
> traceback in a few other threads, all from different database queries,
> all stuck at the same point. Restarting the derby network server,
> caused the condition to clear up as far as the application server is
> concerned, so I am pretty confident it is related to derby.
>
> Any help on where to look to find this problem will be greatly
> appreciated.
>
> Brett
>
Re: Derby 10.5.3.0
Posted by Kristian Waagan <kr...@oracle.com>.
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) started and ready to accept connections on port 1527
>
> ----------------------------------------------------------------
>
> 2010-11-16 00:00:20.078 GMT:
>
> Booting Derby version The Apache Software Foundation - Apache Derby -
> 10.5.3.0 - (802917): instance a816c00e-012c-51f9-12b2-0000376d74d3
>
> on database directory C:\Documents and Settings\Brett
> Bergquist\.netbeans-derby\csemdb
>
> Database Class Loader started - derby.database.classpath='CSEM.csemderby'
>
> (END)
>
> The rest of Glassfish is up and running as well as other parts of my
> application. This one thread, however, is causing my JMS processing
> to be hung.
>
> This is the second time in two days of testing that this has
> occurred. The previous lockup has exactly the same thread stack
> traceback in a few other threads, all from different database queries,
> all stuck at the same point. Restarting the derby network server,
> caused the condition to clear up as far as the application server is
> concerned, so I am pretty confident it is related to derby.
>
> Any help on where to look to find this problem will be greatly
> appreciated.
>
> Brett
>