You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@tomcat.apache.org by Jason Britton <jb...@gmail.com> on 2010/10/20 22:37:30 UTC

tomcat 6.0.29 hung

I have a tomcat instance hanging up (and currently still hung up) and would
really appreciate pointers on how to debug further.
A belated thanks to Konstantin for the info on kill -QUIT pid to retrieve
thread dumps But I was only able to pull thread dumps on the hung process
using jvisualvm.  Process failed to respond to kill -QUIT for unknown
reasons.

Environment:
Tomcat 6.0.29 - using native APR, running on 64-bit RHEL 5.5 - 32 GB ram
java version "1.6.0_21"
Java(TM) SE Runtime Environment (build 1.6.0_21-b06)
Java HotSpot(TM) 64-Bit Server VM (build 17.0-b16, mixed mode)

I pulled 4 thread dumps in a 10 minute span on hung tomcat process after it
was reported to be non-responsive.  Unfortunately not any differences
between thread dumps and to my great dismay jstack is unable to retrieve any
stacktraces on any of the threads reporting the following error:

Error occurred during stack walking:
sun.jvm.hotspot.debugger.DebuggerException:
sun.jvm.hotspot.debugger.DebuggerException: get_thread_regs failed for a lwp
        at
sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal$LinuxDebuggerLocalWorkerThread.execute(LinuxDebuggerLocal.java:152)
        at
sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal.getThreadIntegerRegisterSet(LinuxDebuggerLocal.java:466)
        at
sun.jvm.hotspot.debugger.linux.LinuxThread.getContext(LinuxThread.java:65)
        at
sun.jvm.hotspot.runtime.linux_amd64.LinuxAMD64JavaThreadPDAccess.getCurrentFrameGuess(LinuxAMD64JavaThreadPDAccess.java:92)
        ............................................

>From my googling this appears to be an unfixed bug with jstack, I sure would
like to be wrong about that so I could get some stacktrace info on the
threads of my hung process.

Any thoughts on how to possibly get stacktrace info on these threads with
jstack broken(?) on my environment and any ideas on how to proceed with
debugging this situation would be greatly appreciated.  Thanks -  Jason

Thread dump from hung tomcat process
Thread 27817 "catalina-exec-foo-20": (state = BLOCKED)
Thread 27267 "catalina-exec-foo-19": (state = BLOCKED)
Thread 27082 "catalina-exec-foo-18": (state = BLOCKED)
Thread 26591 "catalina-exec-foo-17": (state = BLOCKED)
Thread 25899 "catalina-exec-foo-16": (state = BLOCKED)
Thread 25590 "catalina-exec-foo-15": (state = BLOCKED)
Thread 25589 "catalina-exec-foo-14": (state = BLOCKED)
Thread 25586 "catalina-exec-foo-13": (state = BLOCKED)
Thread 25578 "catalina-exec-foo-12": (state = BLOCKED)
Thread 25565 "catalina-exec-foo-11": (state = BLOCKED)
Thread 17427 "Thread-40": (state = BLOCKED)
Thread 9128 "Thread-39": (state = IN_NATIVE)
Thread 16811 "catalina-exec-foo-10": (state = BLOCKED)
Thread 16810 "catalina-exec-foo-9": (state = BLOCKED)
Thread 16809 "catalina-exec-foo-8": (state = IN_NATIVE)
Thread 16808 "catalina-exec-foo-7": (state = BLOCKED)
Thread 16807 "catalina-exec-foo-6": (state = IN_NATIVE)
Thread 16806 "catalina-exec-foo-5": (state = BLOCKED)
Thread 16805 "Thread-8": (state = BLOCKED)
Thread 16804 "catalina-exec-foo-4": (state = BLOCKED)
Thread 16803 "catalina-exec-foo-3": (state = BLOCKED)
Thread 16802 "catalina-exec-foo-2": (state = IN_NATIVE)
Thread 16801 "catalina-exec-foo-1": (state = IN_NATIVE)
Thread 16791 "ajp-9009-Acceptor-0": (state = IN_NATIVE)
Thread 16790 "ajp-9009-CometPoller-0": (state = BLOCKED)
Thread 16789 "ajp-9009-Poller-0": (state = IN_NATIVE)
Thread 16788 "http-8080-Acceptor-0": (state = IN_NATIVE)
Thread 16787 "http-8080-Sendfile-0": (state = BLOCKED)
Thread 16786 "http-8080-CometPoller-0": (state = BLOCKED)
Thread 16785 "http-8080-Poller-0": (state = BLOCKED)
Thread 16784 "ContainerBackgroundProcessor[StandardEngine[Catalina]]":
(state = BLOCKED)
Thread 16783 "Thread-6": (state = BLOCKED)
Thread 16782 "Thread-5": (state = BLOCKED)
Thread 16781 "Thread-4": (state = BLOCKED)
Thread 16780 "Thread-3": (state = BLOCKED)
Thread 16778 "Thread-2": (state = BLOCKED)
Thread 16777 "GC Daemon": (state = BLOCKED)
VM Thread 16775 "Low Memory Detector": (state = BLOCKED)
VM Thread 16774 "CompilerThread1": (state = BLOCKED)
VM Thread 16773 "CompilerThread0": (state = BLOCKED)
Thread 16772 "Signal Dispatcher": (state = BLOCKED)
Thread 16771 "Finalizer": (state = BLOCKED)
Thread 16770 "Reference Handler": (state = BLOCKED)
Thread 16764 "main": (state = IN_NATIVE)

Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
 I've further traced the root cause of my problems with threads sitting on
socket read, never timing out, never throwing an exception and sometimes
causing application deadlock (depending on where the socket read occurs)
down to the network.  By comparing the output of lsof -i :1521 | grep ....
on the webserver with the lsof -i :1521 | grep .... on the database server I
can see the webserver thinks it has more connections to the database than
the database actually has from the webserver and using the source port#
which shows up in the output of lsof on both machines I can even narrow down
to exactly what processes are missing the connections.  We've made a policy
change on one of our firewalls to hopefully alleviate the problem but only
more testing will tell.

RE: tomcat 6.0.29 hung

Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
> From: Dave Mansfield [mailto:dmansfield@sbcglobal.net] 
> Subject: Re: tomcat 6.0.29 hung

> This might be related, and don't know if you've read it - 
> it's a bit out of date, and depends on versions of stuff 
> you're using, Jason.

> http://forums.sun.com/thread.jspa?threadID=343023&start=15&tstart=0

Unfortunately, the above is pretty much all BS.  It's a jumble of several actually unrelated issues, some of which were caused by a JVM bug, some by silliness in DBCP, and some just pure erroneous conjecture.

None of the symptoms in that thread appear to be related to the OP's issues, which seem to be caused by a combination of bad application design, possible synchronization problems in commons-dbcp, and network errors.

 - Chuck


THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Dave Mansfield <dm...@sbcglobal.net>.
This might be related, and don't know if you've read it - it's a bit out 
of date, and depends on versions of stuff you're using, Jason.

http://forums.sun.com/thread.jspa?threadID=343023&start=15&tstart=0

-- D Mansfield

Jason Britton wrote:
> Thanks for the insight Dave.  I have several threads sitting spinning
> on socket read at the moment and dba reports zero database locks of
> any kind on database they're trying to read from (a qa database).
> Quite baffled as to what's happening to these database connections and
> why every now and then thread sits on socket read while trying to read
> from database.  Situation becomes serious and app completely dead
> locks when the socket read hang happens inside synchronized block.
>
>
>
> On Fri, Oct 22, 2010 at 10:36 AM, Dave Mansfield
> <dm...@sbcglobal.net> wrote:
>   
>> Well, here's an oversight:  The threads below show concurrent execution of a
>> prepared statement.  The fact that a thread own the lock, is buried well
>> into executing that statement, and is waiting for a read from a socket
>> doesn't mean it's an issue with the AJP - it could well be a DB locking
>> problem.
>> You need to examine the Oracle side of things in parallel and start looking
>> at database lock contention.  I don't know the semantics of Oracle's JDBC
>> driver when managing a prepared statement - especially if it's done
>> concurrently, so I can't give you any trails to follow...
>>
>> I'd focus on forcing the thread holding the lock to abort on the Oracle side
>> of things - if it frees up the other threads, you have a new point to start
>> diagnosing...
>>
>> -- D Mansfield
>>     
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>
>
>   

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
Thanks for the insight Dave.  I have several threads sitting spinning
on socket read at the moment and dba reports zero database locks of
any kind on database they're trying to read from (a qa database).
Quite baffled as to what's happening to these database connections and
why every now and then thread sits on socket read while trying to read
from database.  Situation becomes serious and app completely dead
locks when the socket read hang happens inside synchronized block.



On Fri, Oct 22, 2010 at 10:36 AM, Dave Mansfield
<dm...@sbcglobal.net> wrote:
>
>
> Well, here's an oversight:  The threads below show concurrent execution of a
> prepared statement.  The fact that a thread own the lock, is buried well
> into executing that statement, and is waiting for a read from a socket
> doesn't mean it's an issue with the AJP - it could well be a DB locking
> problem.
> You need to examine the Oracle side of things in parallel and start looking
> at database lock contention.  I don't know the semantics of Oracle's JDBC
> driver when managing a prepared statement - especially if it's done
> concurrently, so I can't give you any trails to follow...
>
> I'd focus on forcing the thread holding the lock to abort on the Oracle side
> of things - if it frees up the other threads, you have a new point to start
> diagnosing...
>
> -- D Mansfield
>>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Dave Mansfield <dm...@sbcglobal.net>.

Jason Britton wrote:
> So while working on reproducing tomcat webapp hang as earlier discussed, a
> different tomcat serving up a single webapp on same box also stopped
> responding, jvm for this tomcat is still running but when trying to reach it
> via browser I get error page of unable to connect.
>
> Thread dumps for both problem tomcats seem to exhibit same core problem, at
> least in my analysis.  I would really appreciate your feedback on my
> analysis of the situation and things anyone thinks I may be over looking.
>   
Well, here's an oversight:  The threads below show concurrent execution 
of a prepared statement.  The fact that a thread own the lock, is buried 
well into executing that statement, and is waiting for a read from a 
socket doesn't mean it's an issue with the AJP - it could well be a DB 
locking problem.  

You need to examine the Oracle side of things in parallel and start 
looking at database lock contention.  I don't know the semantics of 
Oracle's JDBC driver when managing a prepared statement - especially if 
it's done concurrently, so I can't give you any trails to follow...

I'd focus on forcing the thread holding the lock to abort on the Oracle 
side of things - if it frees up the other threads, you have a new point 
to start diagnosing...

-- D Mansfield
> On both tomcat jvms when they get to the point of locking up, thread dumps
>
>   

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Pid <pi...@pidster.com>.
On 22/10/2010 16:47, Jason Britton wrote:
> one of two of the hanging applications are doing db connection validation.
> 
> The application using DBCP configures it's SharedPoolDataSource using
> 
>             setValidationQuery("select 'validationQuery' from dual");

That looks weird.  Is that really the query?

>             setTestOnBorrow(true);
> 
> Funny enough, thread stacktrace below shows thread hung when doing
> validation query sitting on socket read.  Other application not using
> DBCP and not using connection validation query hangs on socket read
> just the same.  Web server lives in DMZ crosses firewall to get to
> database, I'm going to start accusing the network guys of crushing my
> connections on firewall.  Not sure why validation query is not saving
> me in this instance.

So the connection during the validation query isn't actually working?
It ought to fail after a period & kill the connection.

If you're configuring it manually, can you give us the full config?



p

> Thread stacktrace showing runnable thread sitting on socket read while
> trying to do connection validation query
> "catalina-exec-company1-2" daemon prio=10 tid=0x000000004bf5b800
> nid=0x41a2 runnable [0x0000000042be1000]
>    java.lang.Thread.State: RUNNABLE
> 	at java.net.SocketInputStream.socketRead0(Native Method)
> 	at java.net.SocketInputStream.read(SocketInputStream.java:129)
> 	at oracle.net.ns.Packet.receive(Packet.java:293)
> 	at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
> 	at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
> 	at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
> 	at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
> 	at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
> 	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
> 	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
> 	at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
> 	at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
> 	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
> 	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:183)
> 	at oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:780)
> 	at oracle.jdbc.driver.T4CStatement.executeMaybeDescribe(T4CStatement.java:855)
> 	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
> 	at oracle.jdbc.driver.OracleStatement.executeQuery(OracleStatement.java:1378)
> 	- locked <0x00002aaad1f64df8> (a oracle.jdbc.driver.T4CConnection)
> 	at oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:387)
> 	at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.validateObject(KeyedCPDSConnectionFactory.java:163)
> 	at org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:837)
> 	- locked <0x00002aaace878d18> (a
> org.apache.commons.pool.impl.GenericKeyedObjectPool)
> 	at org.apache.commons.dbcp.datasources.SharedPoolDataSource.getPooledConnectionAndInfo(SharedPoolDataSource.java:165)
> 	- locked <0x00002aaaced306f8> (a
> org.apache.commons.dbcp.datasources.SharedPoolDataSource)
> 	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:631)
> 	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:615)
> 	at com.mycompany.db.ConnectionHandler.getConnection(ConnectionHandler.java:150)
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
> 


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
one of two of the hanging applications are doing db connection validation.

The application using DBCP configures it's SharedPoolDataSource using

            setValidationQuery("select 'validationQuery' from dual");
            setTestOnBorrow(true);

Funny enough, thread stacktrace below shows thread hung when doing
validation query sitting on socket read.  Other application not using
DBCP and not using connection validation query hangs on socket read
just the same.  Web server lives in DMZ crosses firewall to get to
database, I'm going to start accusing the network guys of crushing my
connections on firewall.  Not sure why validation query is not saving
me in this instance.

Thread stacktrace showing runnable thread sitting on socket read while
trying to do connection validation query
"catalina-exec-company1-2" daemon prio=10 tid=0x000000004bf5b800
nid=0x41a2 runnable [0x0000000042be1000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at oracle.net.ns.Packet.receive(Packet.java:293)
	at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
	at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:183)
	at oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:780)
	at oracle.jdbc.driver.T4CStatement.executeMaybeDescribe(T4CStatement.java:855)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
	at oracle.jdbc.driver.OracleStatement.executeQuery(OracleStatement.java:1378)
	- locked <0x00002aaad1f64df8> (a oracle.jdbc.driver.T4CConnection)
	at oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:387)
	at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.validateObject(KeyedCPDSConnectionFactory.java:163)
	at org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:837)
	- locked <0x00002aaace878d18> (a
org.apache.commons.pool.impl.GenericKeyedObjectPool)
	at org.apache.commons.dbcp.datasources.SharedPoolDataSource.getPooledConnectionAndInfo(SharedPoolDataSource.java:165)
	- locked <0x00002aaaced306f8> (a
org.apache.commons.dbcp.datasources.SharedPoolDataSource)
	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:631)
	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:615)
	at com.mycompany.db.ConnectionHandler.getConnection(ConnectionHandler.java:150)

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Pid <pi...@pidster.com>.
On 22/10/2010 15:42, Jason Britton wrote:
> Hi Chuck -
> How the application is doing its locking is definitely exacerbating
> the problem of the thread just sitting on that socket read to the
> database and never getting to release the lock, this is just one
> particular application out of two different tomcats that are locking
> up with same core issue.

Or maybe all of them with the same app will, under the right conditions.

> The second app also has a runnable thread
> hanging onto a lock with lots of other threads blocking waiting for
> that object.  This time the lock is not being made in our code but in
> DBCP code and it hangs on a socket read to the database as well never
> releasing it's locks.  Thread stacktrace from this thread below.  Our
> DBCP and Pool libs are out of date.  I'm hoping updating those libs
> will allow DBCP to better handle socket read hangups.  Still very
> concerned about why socket reads are hanging up to db bringing these
> locking issues to light.

As Mark said, there's synchronisation issues in older versions of
Commons DBCP.
 
> Almost all other threads are blocked waiting for the lock this thread
> has on SharedPoolDataSource below

A thought occurs: how are you validating the db connections?


p

> "catalina-exec-company1-2" daemon prio=10 tid=0x000000004bf5b800
> nid=0x41a2 runnable [0x0000000042be1000]
>    java.lang.Thread.State: RUNNABLE
> 	at java.net.SocketInputStream.socketRead0(Native Method)
> 	at java.net.SocketInputStream.read(SocketInputStream.java:129)
> 	at oracle.net.ns.Packet.receive(Packet.java:293)
> 	at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
> 	at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
> 	at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
> 	at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
> 	at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
> 	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
> 	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
> 	at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
> 	at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
> 	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
> 	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:183)
> 	at oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:780)
> 	at oracle.jdbc.driver.T4CStatement.executeMaybeDescribe(T4CStatement.java:855)
> 	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
> 	at oracle.jdbc.driver.OracleStatement.executeQuery(OracleStatement.java:1378)
> 	- locked <0x00002aaad1f64df8> (a oracle.jdbc.driver.T4CConnection)
> 	at oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:387)
> 	at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.validateObject(KeyedCPDSConnectionFactory.java:163)
> 	at org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:837)
> 	- locked <0x00002aaace878d18> (a
> org.apache.commons.pool.impl.GenericKeyedObjectPool)
> 	at org.apache.commons.dbcp.datasources.SharedPoolDataSource.getPooledConnectionAndInfo(SharedPoolDataSource.java:165)
> 	- locked <0x00002aaaced306f8> (a
> org.apache.commons.dbcp.datasources.SharedPoolDataSource)
> 	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:631)
> 	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:615)
> 	at com.mycompany.db.ConnectionHandler.getConnection(ConnectionHandler.java:150)
> 	at com.mycompany.community.dataaccess.CustomerDAO.getBasicInfo(CustomerDAO.java:108)
> 	at com.mycompany.community.domain.CommunityUser.loadBasicInfo(CommunityUser.java:207)
> 	at com.mycompany.community.domain.CommunityUser.isRegisteredMember(CommunityUser.java:598)
> 	at org.apache.jsp.templates.home.leftnav_jsp._jspService(leftnav_jsp.java:626)
> 	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
> 	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
> 	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> 	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
> 	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:551)
> 	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:488)
> 	at org.apache.jasper.runtime.JspRuntimeLibrary.include(JspRuntimeLibrary.java:968)
> 	at org.apache.jsp.templates.home.home_005ftemplate_jsp._jspService(home_005ftemplate_jsp.java:149)
> 	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
> 	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
> 	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
> 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
> 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
> 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> 	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
> 	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:551)
> 	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:488)
> 	at com.mycompany.servlet.filters.NavigationFilter.retrieveTemplate(NavigationFilter.java:381)
> 	at com.mycompany.servlet.filters.NavigationFilter.doFilter(NavigationFilter.java:185)
> 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
> 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
> 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
> 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
> 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
> 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
> 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
> 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
> 	at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:427)
> 	at org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProtocol.java:384)
> 	at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2087)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
> 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
> 	at java.lang.Thread.run(Thread.java:619)
> 
> 
> 
> 
> 
> On Fri, Oct 22, 2010 at 6:34 AM, Caldarale, Charles R
> <Ch...@unisys.com> wrote:
>>
>> From: Jason Britton [mailto:jbritton31@gmail.com]
>>> Subject: Re: tomcat 6.0.29 hung
>>
>>
>>> My thoughts are this is the thread causing all the backup
>>> AJP Thread 1 RUNNABLE, sitting on socketRead0, Has locked
>>> <0x00002aaad303cad0> (a com.acompany.model.customer.CustomerData)
>>> which almost all other threads are blocked waiting for lock on
>>
>> Which means you have an extremely poor application design.  The webapp should never set a global lock and then make a database request.  Either the lock must be of much finer granularity, or not set until after the DB request is responded to.
>>
>>  - Chuck
>>
>>
>> THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.
>>
>>
>> ---------------------------------------------------------------------
>> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
>> For additional commands, e-mail: users-help@tomcat.apache.org
>>
> 
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
> 


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
Hi Chuck -
How the application is doing its locking is definitely exacerbating
the problem of the thread just sitting on that socket read to the
database and never getting to release the lock, this is just one
particular application out of two different tomcats that are locking
up with same core issue.  The second app also has a runnable thread
hanging onto a lock with lots of other threads blocking waiting for
that object.  This time the lock is not being made in our code but in
DBCP code and it hangs on a socket read to the database as well never
releasing it's locks.  Thread stacktrace from this thread below.  Our
DBCP and Pool libs are out of date.  I'm hoping updating those libs
will allow DBCP to better handle socket read hangups.  Still very
concerned about why socket reads are hanging up to db bringing these
locking issues to light.

Almost all other threads are blocked waiting for the lock this thread
has on SharedPoolDataSource below

"catalina-exec-company1-2" daemon prio=10 tid=0x000000004bf5b800
nid=0x41a2 runnable [0x0000000042be1000]
   java.lang.Thread.State: RUNNABLE
	at java.net.SocketInputStream.socketRead0(Native Method)
	at java.net.SocketInputStream.read(SocketInputStream.java:129)
	at oracle.net.ns.Packet.receive(Packet.java:293)
	at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
	at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
	at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
	at oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
	at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
	at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
	at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:183)
	at oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:780)
	at oracle.jdbc.driver.T4CStatement.executeMaybeDescribe(T4CStatement.java:855)
	at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
	at oracle.jdbc.driver.OracleStatement.executeQuery(OracleStatement.java:1378)
	- locked <0x00002aaad1f64df8> (a oracle.jdbc.driver.T4CConnection)
	at oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:387)
	at org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.validateObject(KeyedCPDSConnectionFactory.java:163)
	at org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:837)
	- locked <0x00002aaace878d18> (a
org.apache.commons.pool.impl.GenericKeyedObjectPool)
	at org.apache.commons.dbcp.datasources.SharedPoolDataSource.getPooledConnectionAndInfo(SharedPoolDataSource.java:165)
	- locked <0x00002aaaced306f8> (a
org.apache.commons.dbcp.datasources.SharedPoolDataSource)
	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:631)
	at org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:615)
	at com.mycompany.db.ConnectionHandler.getConnection(ConnectionHandler.java:150)
	at com.mycompany.community.dataaccess.CustomerDAO.getBasicInfo(CustomerDAO.java:108)
	at com.mycompany.community.domain.CommunityUser.loadBasicInfo(CommunityUser.java:207)
	at com.mycompany.community.domain.CommunityUser.isRegisteredMember(CommunityUser.java:598)
	at org.apache.jsp.templates.home.leftnav_jsp._jspService(leftnav_jsp.java:626)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:551)
	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:488)
	at org.apache.jasper.runtime.JspRuntimeLibrary.include(JspRuntimeLibrary.java:968)
	at org.apache.jsp.templates.home.home_005ftemplate_jsp._jspService(home_005ftemplate_jsp.java:149)
	at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:377)
	at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:313)
	at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:260)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.ApplicationDispatcher.invoke(ApplicationDispatcher.java:646)
	at org.apache.catalina.core.ApplicationDispatcher.doInclude(ApplicationDispatcher.java:551)
	at org.apache.catalina.core.ApplicationDispatcher.include(ApplicationDispatcher.java:488)
	at com.mycompany.servlet.filters.NavigationFilter.retrieveTemplate(NavigationFilter.java:381)
	at com.mycompany.servlet.filters.NavigationFilter.doFilter(NavigationFilter.java:185)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:235)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:219)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:298)
	at org.apache.coyote.ajp.AjpAprProcessor.process(AjpAprProcessor.java:427)
	at org.apache.coyote.ajp.AjpAprProtocol$AjpConnectionHandler.process(AjpAprProtocol.java:384)
	at org.apache.tomcat.util.net.AprEndpoint$SocketProcessor.run(AprEndpoint.java:2087)
	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
	at java.lang.Thread.run(Thread.java:619)





On Fri, Oct 22, 2010 at 6:34 AM, Caldarale, Charles R
<Ch...@unisys.com> wrote:
>
> From: Jason Britton [mailto:jbritton31@gmail.com]
> > Subject: Re: tomcat 6.0.29 hung
>
>
> > My thoughts are this is the thread causing all the backup
> > AJP Thread 1 RUNNABLE, sitting on socketRead0, Has locked
> > <0x00002aaad303cad0> (a com.acompany.model.customer.CustomerData)
> > which almost all other threads are blocked waiting for lock on
>
> Which means you have an extremely poor application design.  The webapp should never set a global lock and then make a database request.  Either the lock must be of much finer granularity, or not set until after the DB request is responded to.
>
>  - Chuck
>
>
> THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
> For additional commands, e-mail: users-help@tomcat.apache.org
>

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


RE: tomcat 6.0.29 hung

Posted by "Caldarale, Charles R" <Ch...@unisys.com>.
From: Jason Britton [mailto:jbritton31@gmail.com] 
> Subject: Re: tomcat 6.0.29 hung


> My thoughts are this is the thread causing all the backup
> AJP Thread 1 RUNNABLE, sitting on socketRead0, Has locked
> <0x00002aaad303cad0> (a com.acompany.model.customer.CustomerData)
> which almost all other threads are blocked waiting for lock on

Which means you have an extremely poor application design.  The webapp should never set a global lock and then make a database request.  Either the lock must be of much finer granularity, or not set until after the DB request is responded to.

 - Chuck


THIS COMMUNICATION MAY CONTAIN CONFIDENTIAL AND/OR OTHERWISE PROPRIETARY MATERIAL and is thus for use only by the intended recipient. If you received this in error, please contact the sender and delete the e-mail and its attachments from all computers.


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
So while working on reproducing tomcat webapp hang as earlier discussed, a
different tomcat serving up a single webapp on same box also stopped
responding, jvm for this tomcat is still running but when trying to reach it
via browser I get error page of unable to connect.

Thread dumps for both problem tomcats seem to exhibit same core problem, at
least in my analysis.  I would really appreciate your feedback on my
analysis of the situation and things anyone thinks I may be over looking.

On both tomcat jvms when they get to the point of locking up, thread dumps
show that almost all ajp/exec threads are blocked and there are either one
or two ajp/exec threads runnable.  The blocked threads are waiting for locks
on an object held by one of the threads in runnable state.  The commonality
between the two that really has to be the root of the problem, in my
estimation, is that on both tomcats the runnable threads are sitting on
socketRead0 to our database and not budging, just stuck in runnable and
never getting to the point of releasing their locks...  Potential networking
issue with that socket read?  Take a look at the thread dump below, I've
shortened a lot of the stacktraces - Thanks for any thoughts on the matter



AJP Threads 3, 5, 7,12
   java.lang.Thread.State: BLOCKED (on object monitor)
    at
com.acompany.view.backing.cact.product.ProductsView.setCustomerData(ProductsView.java:57)
    - waiting to lock <0x00002aaad303cad0> (a
com.acompany.model.customer.CustomerData)
    at
com.acompany.view.backing.cact.product.Products.<init>(Products.java:101)

AJP Threads 9,10,11
   java.lang.Thread.State: BLOCKED (on object monitor)
    at
com.acompany.view.backing.cact.membership.MembershipsView.setCustomerData(MembershipsView.java:58)
    - waiting to lock <0x00002aaad303cad0> (a
com.acompany.model.customer.CustomerData)
    at
com.acompany.view.backing.cact.membership.Memberships.<init>(Memberships.java:99)

AJP Threads 4, 6, 8
   java.lang.Thread.State: BLOCKED (on object monitor)
    at
com.acompany.view.backing.cact.meeting.MeetingsView.setCustomerData(MeetingsView.java:66)
    - waiting to lock <0x00002aaad303cad0> (a
com.acompany.model.customer.CustomerData)
    at
com.acompany.view.backing.cact.meeting.Meetings.<init>(Meetings.java:135)

AJP threads 13, 14, 15, 16 - WAITING on object monitor - probably what
they're supposed to be doing
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaad34cdbd8> (a
org.apache.tomcat.util.net.AprEndpoint$Worker)
    at java.lang.Object.wait(Object.java:485)
    at
org.apache.tomcat.util.net.AprEndpoint$Worker.await(AprEndpoint.java:1540)
    - locked <0x00002aaad34cdbd8> (a
org.apache.tomcat.util.net.AprEndpoint$Worker)
    at
org.apache.tomcat.util.net.AprEndpoint$Worker.run(AprEndpoint.java:1565)
    at java.lang.Thread.run(Thread.java:619)


AJP thread 2 - RUNNABLE - sitting on socketRead0
"ajp-9011-2" daemon prio=10 tid=0x000000005e342800 nid=0x3f0a runnable
[0x0000000040f07000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at oracle.net.ns.Packet.receive(Packet.java:293)
    at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
    at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
    at
oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
    at
oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
    at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
    at
oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:194)
    at
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:791)
    at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:866)
    at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
    at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3386)
    at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3430)
    - locked <0x00002aaacf0584b0> (a oracle.jdbc.driver.T4CConnection)
    at
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
    at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
    at
org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:120)
    at org.hibernate.loader.Loader.getResultSet(Loader.java:1272)
    at org.hibernate.loader.Loader.doQuery(Loader.java:391)
    at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:218)
    at org.hibernate.loader.Loader.loadEntity(Loader.java:1345)
    at org.hibernate.loader.entity.EntityLoader.load(EntityLoader.java:116)
    at org.hibernate.loader.entity.EntityLoader.load(EntityLoader.java:101)


My thoughts are this is the thread causing all the backup
AJP Thread 1 RUNNABLE, sitting on socketRead0, Has locked
<0x00002aaad303cad0> (a com.acompany.model.customer.CustomerData) which
almost all other threads are blocked waiting for lock on

   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at oracle.net.ns.Packet.receive(Packet.java:293)
    at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
    at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
    at
oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
    at
oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
    at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
    at
oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:194)
    at
oracle.jdbc.driver.T4CPreparedStatement.executeForDescribe(T4CPreparedStatement.java:791)
    at
oracle.jdbc.driver.T4CPreparedStatement.executeMaybeDescribe(T4CPreparedStatement.java:866)
    at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
    at
oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3386)
    at
oracle.jdbc.driver.OraclePreparedStatement.executeQuery(OraclePreparedStatement.java:3430)
    - locked <0x00002aaad0bbd688> (a oracle.jdbc.driver.T4CConnection)
    at
oracle.jdbc.driver.OraclePreparedStatementWrapper.executeQuery(OraclePreparedStatementWrapper.java:1491)
    at
org.apache.commons.dbcp.DelegatingPreparedStatement.executeQuery(DelegatingPreparedStatement.java:92)
    at
org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:120)
    at org.hibernate.loader.Loader.getResultSet(Loader.java:1272)
    at org.hibernate.loader.Loader.doQuery(Loader.java:391)
    at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:218)
    at org.hibernate.loader.Loader.loadCollection(Loader.java:1434)
    at
org.hibernate.loader.collection.OneToManyLoader.initialize(OneToManyLoader.java:111)
    at
org.hibernate.persister.collection.AbstractCollectionPersister.initialize(AbstractCollectionPersister.java:488)
    at
org.hibernate.event.def.DefaultInitializeCollectionEventListener.onInitializeCollection(DefaultInitializeCollectionEventListener.java:60)
    at
org.hibernate.impl.SessionImpl.initializeCollection(SessionImpl.java:1430)
    at
org.hibernate.collection.AbstractPersistentCollection.forceInitialization(AbstractPersistentCollection.java:280)
    at
org.hibernate.engine.PersistenceContext.initializeNonLazyCollections(PersistenceContext.java:796)
    at
org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:223)
    at org.hibernate.loader.Loader.doList(Loader.java:1593)
    at org.hibernate.loader.Loader.list(Loader.java:1577)
    at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:395)
    at
org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:271)
    at org.hibernate.impl.SessionImpl.list(SessionImpl.java:844)
    at org.hibernate.impl.QueryImpl.list(QueryImpl.java:74)
    at
org.springframework.orm.hibernate3.HibernateTemplate$32.doInHibernate(HibernateTemplate.java:815)
    at
org.springframework.orm.hibernate3.HibernateTemplate.execute(HibernateTemplate.java:312)
    at
org.springframework.orm.hibernate3.HibernateTemplate.findByNamedQuery(HibernateTemplate.java:806)
    at
com.acompany.model.dao.hibernateimpl.OrderDAOImpl.loadOrders(OrderDAOImpl.java:46)
    at
com.acompany.model.service.impl.OrderServiceImpl.loadOrders(OrderServiceImpl.java:63)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at
org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:288)
    at
org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:155)
    at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:122)
    at
org.springframework.transaction.interceptor.TransactionInterceptor.invoke(TransactionInterceptor.java:57)
    at
org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:144)
    at
org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:174)
    at $Proxy33.loadOrders(Unknown Source)
    at
com.acompany.model.customer.CustomerOrderData.load(CustomerOrderData.java:254)
    at
com.acompany.model.customer.CustomerOrderData.getCurrentOrders(CustomerOrderData.java:153)
    at
com.acompany.model.customer.CustomerOrderData.getCurrentOrderSize(CustomerOrderData.java:131)
    at
com.acompany.view.backing.cact.product.ProductsView.buildNodeLists(ProductsView.java:411)
    at
com.acompany.view.backing.cact.product.ProductsView.refreshOrders(ProductsView.java:150)
    at
com.acompany.view.backing.cact.product.ProductsView.setCustomerData(ProductsView.java:68)
    - locked <0x00002aaad303cad0> (a
com.acompany.model.customer.CustomerData)
    at
com.acompany.view.backing.cact.product.Products.<init>(Products.java:101)
    at sun.reflect.GeneratedConstructorAccessor180.newInstance(Unknown
Source)
    at
sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:27)
    at java.lang.reflect.Constructor.newInstance(Constructor.java:513)
    at java.lang.Class.newInstance0(Class.java:355)
    at java.lang.Class.newInstance(Class.java:308)
    at java.beans.Beans.instantiate(Beans.java:204)
    at java.beans.Beans.instantiate(Beans.java:48)
    at
com.sun.faces.config.ManagedBeanFactory.newInstance(ManagedBeanFactory.java:223)



"ajp-9011-Acceptor-0" daemon prio=10 tid=0x00002aab344bb800 nid=0x3efb
runnable [0x0000000042c32000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.tomcat.jni.Socket.accept(Native Method)
    at
org.apache.tomcat.util.net.AprEndpoint$Acceptor.run(AprEndpoint.java:1169)
    at java.lang.Thread.run(Thread.java:619)

"ajp-9011-CometPoller-0" daemon prio=10 tid=0x00002aab34ae4000 nid=0x3efa in
Object.wait() [0x0000000042b31000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaad0f5d530> (a
org.apache.tomcat.util.net.AprEndpoint$Poller)
    at java.lang.Object.wait(Object.java:485)
    at
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1336)
    - locked <0x00002aaad0f5d530> (a
org.apache.tomcat.util.net.AprEndpoint$Poller)
    at java.lang.Thread.run(Thread.java:619)

"ajp-9011-Poller-0" daemon prio=10 tid=0x00002aab3426d000 nid=0x3ef9
runnable [0x0000000042a30000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.tomcat.jni.Poll.poll(Native Method)
    at
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1373)
    at java.lang.Thread.run(Thread.java:619)

"http-8082-Acceptor-0" daemon prio=10 tid=0x00002aab3432a000 nid=0x3ef8
runnable [0x000000004292f000]
   java.lang.Thread.State: RUNNABLE
    at org.apache.tomcat.jni.Socket.accept(Native Method)
    at
org.apache.tomcat.util.net.AprEndpoint$Acceptor.run(AprEndpoint.java:1169)
    at java.lang.Thread.run(Thread.java:619)

"http-8082-Sendfile-0" daemon prio=10 tid=0x00002aab343e3800 nid=0x3ef7 in
Object.wait() [0x000000004282e000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaad0f5dc58> (a
org.apache.tomcat.util.net.AprEndpoint$Sendfile)
    at java.lang.Object.wait(Object.java:485)
    at
org.apache.tomcat.util.net.AprEndpoint$Sendfile.run(AprEndpoint.java:1805)
    - locked <0x00002aaad0f5dc58> (a
org.apache.tomcat.util.net.AprEndpoint$Sendfile)
    at java.lang.Thread.run(Thread.java:619)

"http-8082-CometPoller-0" daemon prio=10 tid=0x00002aab3450f800 nid=0x3ef6
in Object.wait() [0x000000004272d000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaad0f5dfb8> (a
org.apache.tomcat.util.net.AprEndpoint$Poller)
    at java.lang.Object.wait(Object.java:485)
    at
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1336)
    - locked <0x00002aaad0f5dfb8> (a
org.apache.tomcat.util.net.AprEndpoint$Poller)
    at java.lang.Thread.run(Thread.java:619)

"http-8082-Poller-0" daemon prio=10 tid=0x00002aab3448e800 nid=0x3ef5 in
Object.wait() [0x000000004262c000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaad0f5e250> (a
org.apache.tomcat.util.net.AprEndpoint$Poller)
    at java.lang.Object.wait(Object.java:485)
    at
org.apache.tomcat.util.net.AprEndpoint$Poller.run(AprEndpoint.java:1336)
    - locked <0x00002aaad0f5e250> (a
org.apache.tomcat.util.net.AprEndpoint$Poller)
    at java.lang.Thread.run(Thread.java:619)

"ContainerBackgroundProcessor[StandardEngine[Catalina]]" daemon prio=10
tid=0x00002aab34b11000 nid=0x3ef4 waiting on condition [0x000000004252b000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
    at java.lang.Thread.sleep(Native Method)
    at
org.apache.catalina.core.ContainerBase$ContainerBackgroundProcessor.run(ContainerBase.java:1579)
    at java.lang.Thread.run(Thread.java:619)

"GC Daemon" daemon prio=10 tid=0x00002aab340fa800 nid=0x3ee2 in
Object.wait() [0x000000004119b000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaace2253a0> (a sun.misc.GC$LatencyLock)
    at sun.misc.GC$Daemon.run(GC.java:100)
    - locked <0x00002aaace2253a0> (a sun.misc.GC$LatencyLock)

"Low Memory Detector" daemon prio=10 tid=0x000000005d1d4800 nid=0x3ee0
runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread1" daemon prio=10 tid=0x000000005d1d2800 nid=0x3edf waiting
on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"CompilerThread0" daemon prio=10 tid=0x000000005d1cc800 nid=0x3ede waiting
on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Signal Dispatcher" daemon prio=10 tid=0x000000005d1ca800 nid=0x3edd waiting
on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

"Finalizer" daemon prio=10 tid=0x000000005d1a6000 nid=0x3edc in
Object.wait() [0x000000004242a000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaace2256f8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
    - locked <0x00002aaace2256f8> (a java.lang.ref.ReferenceQueue$Lock)
    at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
    at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

"Reference Handler" daemon prio=10 tid=0x000000005d1a4000 nid=0x3edb in
Object.wait() [0x0000000042329000]
   java.lang.Thread.State: WAITING (on object monitor)
    at java.lang.Object.wait(Native Method)
    - waiting on <0x00002aaace225390> (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 <0x00002aaace225390> (a java.lang.ref.Reference$Lock)

"main" prio=10 tid=0x000000005d142800 nid=0x3ed5 runnable
[0x0000000041e23000]
   java.lang.Thread.State: RUNNABLE
    at java.net.PlainSocketImpl.socketAccept(Native Method)
    at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390)
    - locked <0x00002aaad08d9170> (a java.net.SocksSocketImpl)
    at java.net.ServerSocket.implAccept(ServerSocket.java:453)
    at java.net.ServerSocket.accept(ServerSocket.java:421)
    at
org.apache.catalina.core.StandardServer.await(StandardServer.java:389)
    at org.apache.catalina.startup.Catalina.await(Catalina.java:662)
    at org.apache.catalina.startup.Catalina.start(Catalina.java:614)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.apache.catalina.startup.Bootstrap.start(Bootstrap.java:289)
    at org.apache.catalina.startup.Bootstrap.main(Bootstrap.java:414)

"VM Thread" prio=10 tid=0x000000005d19f800 nid=0x3eda runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x000000005d155800 nid=0x3ed6
runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x000000005d157800 nid=0x3ed7
runnable

"GC task thread#2 (ParallelGC)" prio=10 tid=0x000000005d159000 nid=0x3ed8
runnable

"GC task thread#3 (ParallelGC)" prio=10 tid=0x000000005d15b000 nid=0x3ed9
runnable

"VM Periodic Task Thread" prio=10 tid=0x000000005d1d7000 nid=0x3ee1 waiting
on condition

JNI global references: 2132

Heap
 PSYoungGen      total 248832K, used 12080K [0x00002aab1e210000,
0x00002aab2e210000, 0x00002aab2e210000)
  eden space 234560K, 5% used
[0x00002aab1e210000,0x00002aab1eddc240,0x00002aab2c720000)
  from space 14272K, 0% used
[0x00002aab2d420000,0x00002aab2d420000,0x00002aab2e210000)
  to   space 13312K, 0% used
[0x00002aab2c720000,0x00002aab2c720000,0x00002aab2d420000)
 PSOldGen        total 1310720K, used 93616K [0x00002aaace210000,
0x00002aab1e210000, 0x00002aab1e210000)
  object space 1310720K, 7% used
[0x00002aaace210000,0x00002aaad3d7c178,0x00002aab1e210000)
 PSPermGen       total 524288K, used 109830K [0x00002aaaae210000,
0x00002aaace210000, 0x00002aaace210000)
  object space 524288K, 20% used
[0x00002aaaae210000,0x00002aaab4d51a20,0x00002aaace210000)




Jason

Re: tomcat 6.0.29 hung

Posted by André Warnier <aw...@ice-sa.com>.
Jason Britton wrote:
> Hi Martin,
> In researching my jstack not working issue I too came across the make sure
> you run jstack as the same user that tomcat is running as.  So I did try
> su'ing to my tomcat user and issuing the jstack -F -l -m <pid> command to no
> avail.  After I reproduce my application deadlock again this morning
> (hopefully) I'll try jstack again without the -F and I'll also try the kill
> -QUIT.  I did not have to enable JMX on this particular tomcat instance in
> order to use jvisualvm.  I don't think jmx comes in to play when using
> jvisualvm.  I just went into our server room and pulled up a terminal window
> right off the server's desktop in order to launch jvisualvm (going to hookup
> cygwin/x instead shortly).
...

This previous thread from a couple of days ago may shed a bit of light on the issue :

Tomcat 6.0.29 - Windows Service - JMX


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
Hi Martin,
In researching my jstack not working issue I too came across the make sure
you run jstack as the same user that tomcat is running as.  So I did try
su'ing to my tomcat user and issuing the jstack -F -l -m <pid> command to no
avail.  After I reproduce my application deadlock again this morning
(hopefully) I'll try jstack again without the -F and I'll also try the kill
-QUIT.  I did not have to enable JMX on this particular tomcat instance in
order to use jvisualvm.  I don't think jmx comes in to play when using
jvisualvm.  I just went into our server room and pulled up a terminal window
right off the server's desktop in order to launch jvisualvm (going to hookup
cygwin/x instead shortly).

Even though jvisualvm was unable to retrieve stacktraces for the threaddumps
and pull them into it's GUI for display ("exception while walking
stacktrace") every time I issued a thread dump command through jvisualvm it
did indeed dump all my thread info + stacktraces into my tomcat logs, it
just couldn't pull it into the GUI for some reason.

Wesley: I now do think my initial kill -QUIT worked as well, I just didn't
check the right log or for some reason was expecting it to dump to the
command line rather than in my tomcat logs where it did go.

Mark: Definitely going to update those dbcp libs.  First step for me is to
try and find a way to reliably reproduce hangup so I'll have a test case to
come back to in order to verify any subsequent fixes actually did the job.

Thanks for the input -   Jason






On Thu, Oct 21, 2010 at 6:02 AM, Martin Kuen <ma...@gmail.com> wrote:

> jason,
>
> Out of personal interest I have a question about the way you use jstack. I
> came across this "jstack cannot take dump of hung process" problem before.
> I
> once witnessed the same exceptions when chasing a deadlock.
>
> This happened to me on ubuntu 10.4.0 (and 10.4.1) 64-bit using sun's jdk
> 1.6.0_21
>
> My mistake was to invoke jstack as a different user, that is, not the user
> which is running the given java application (e.g. root instead of tomcat6).
> Invoking jstack with the -F option as root showed these exceptions, whereas
> kill -QUIT didn't produce anything and jstack without -F failed as well.
>
> As a quick workaround I changed /etc/passwd to allow the user tomcat6 to
> use
> a shell. Issuing a "su tomcat6" as root I was able to get jstack (and kill
> -QUIT) working. Disclaimer: I don't know how tomcat is packaged for Red
> Hat.
>
> I tried to check this with so. who actually claimed that his jvm was hung
> when he tried to get a stack-trace. However, I was told that the problem no
> longer exists (no hung jvm anymore) and the investigation ceased.
>
> This is were you come into play :)
>
> It appears to me that "hung application" alone does not imply that "-F" is
> required. So, if my application enters a infinite loop or gets stuck in a
> deadlock my application is unresponsive and will most likely be referred to
> as "hung", but the vm is actually functioning perfectly. It's just my
> application, that, well, . . . .
>
> In my case I was able to get a stacktrace from an application which was
> stuck in a deadlock (log4j with multiple appenders, multiple threads using
> the same Logger instance) without using "-F" at all.
>
> When you use jvisualvm you most likely do so by enabling (and connecting
> through) jmx (true?). I believe it's correct to claim that this is at least
> a different way of attaching to the vm, than using jstack from the
> comandline. Could be the reason why you were "suddenly" able to get a
> thread
> dump.
>
> Could you give it a shot?
>
>
> Best Regards,
>
> Martin
>

Re: tomcat 6.0.29 hung

Posted by Martin Kuen <ma...@gmail.com>.
jason,

Out of personal interest I have a question about the way you use jstack. I
came across this "jstack cannot take dump of hung process" problem before. I
once witnessed the same exceptions when chasing a deadlock.

This happened to me on ubuntu 10.4.0 (and 10.4.1) 64-bit using sun's jdk
1.6.0_21

My mistake was to invoke jstack as a different user, that is, not the user
which is running the given java application (e.g. root instead of tomcat6).
Invoking jstack with the -F option as root showed these exceptions, whereas
kill -QUIT didn't produce anything and jstack without -F failed as well.

As a quick workaround I changed /etc/passwd to allow the user tomcat6 to use
a shell. Issuing a "su tomcat6" as root I was able to get jstack (and kill
-QUIT) working. Disclaimer: I don't know how tomcat is packaged for Red Hat.

I tried to check this with so. who actually claimed that his jvm was hung
when he tried to get a stack-trace. However, I was told that the problem no
longer exists (no hung jvm anymore) and the investigation ceased.

This is were you come into play :)

It appears to me that "hung application" alone does not imply that "-F" is
required. So, if my application enters a infinite loop or gets stuck in a
deadlock my application is unresponsive and will most likely be referred to
as "hung", but the vm is actually functioning perfectly. It's just my
application, that, well, . . . .

In my case I was able to get a stacktrace from an application which was
stuck in a deadlock (log4j with multiple appenders, multiple threads using
the same Logger instance) without using "-F" at all.

When you use jvisualvm you most likely do so by enabling (and connecting
through) jmx (true?). I believe it's correct to claim that this is at least
a different way of attaching to the vm, than using jstack from the
comandline. Could be the reason why you were "suddenly" able to get a thread
dump.

Could you give it a shot?


Best Regards,

Martin

Re: [OT] VisualVM, (was Re: tomcat 6.0.29 hung)

Posted by Pid <pi...@pidster.com>.
On 21/10/2010 13:49, Jason Britton wrote:
> I'll definitely will take a look at the standalone release.  Thanks for the
> info.  I'm going to throw Cygwin/X on my desktop machine to hopefully be
> able to pull up jvisualvm remotely and/or just use standalone version.
> Perhaps Cygwin/X would also allow you to pull up VisualGC remotely?

If you can fire VisualVM up on the target machine and make an X window
connection, VNC or similar then you're in business.

Check out the Tools > Plugin menu for extra stuff.

VisualGC is now part of VisualVM.  I think it needs to be on the local
machine because it does something which requires direct access to the
process.


p

> On Thu, Oct 21, 2010 at 2:25 AM, Pid <pi...@pidster.com> wrote:
> 
>> On 21/10/2010 00:11, Jason Britton wrote:
>>
>>> Highly recommend trying out jvisualvm (it's in your jdk bin) if you're
>>> running 1.6.
>>
>> There's a standalone release - 1.3.1 - with more plugins & some slightly
>> shinier toys.
>>
>>  https://visualvm.dev.java.net/
>>
>> Even if you can't run it on the same machine as the Tomcat process
>> you're inspecting, it's still pretty handy.  If there was just a way to
>> get VisualGC to work remotely...
>>
>>
>> p
>>
>>
>>
> 


Re: [OT] VisualVM, (was Re: tomcat 6.0.29 hung)

Posted by Jason Britton <jb...@gmail.com>.
I'll definitely will take a look at the standalone release.  Thanks for the
info.  I'm going to throw Cygwin/X on my desktop machine to hopefully be
able to pull up jvisualvm remotely and/or just use standalone version.
Perhaps Cygwin/X would also allow you to pull up VisualGC remotely?



On Thu, Oct 21, 2010 at 2:25 AM, Pid <pi...@pidster.com> wrote:

> On 21/10/2010 00:11, Jason Britton wrote:
>
> > Highly recommend trying out jvisualvm (it's in your jdk bin) if you're
> > running 1.6.
>
> There's a standalone release - 1.3.1 - with more plugins & some slightly
> shinier toys.
>
>  https://visualvm.dev.java.net/
>
> Even if you can't run it on the same machine as the Tomcat process
> you're inspecting, it's still pretty handy.  If there was just a way to
> get VisualGC to work remotely...
>
>
> p
>
>
>

[OT] VisualVM, (was Re: tomcat 6.0.29 hung)

Posted by Pid <pi...@pidster.com>.
On 21/10/2010 00:11, Jason Britton wrote:

> Highly recommend trying out jvisualvm (it's in your jdk bin) if you're
> running 1.6.

There's a standalone release - 1.3.1 - with more plugins & some slightly
shinier toys.

 https://visualvm.dev.java.net/

Even if you can't run it on the same machine as the Tomcat process
you're inspecting, it's still pretty handy.  If there was just a way to
get VisualGC to work remotely...


p



Re: tomcat 6.0.29 hung

Posted by Wesley Acheson <we...@gmail.com>.
On Thu, Oct 21, 2010 at 1:11 AM, Jason Britton <jb...@gmail.com> wrote:
> Thankfully when I pulled up jvisualvm on the server and issued thread dumps,
> even though the stacktraces for the threads did not come up within jvisualvm
> the thread stacktraces were dumped to stdout.

I think this is quite likely to be the result of kill -QUIT you
mentioned earlier.

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Mark Thomas <ma...@apache.org>.
On 20/10/2010 20:20, Jason Britton wrote:
> commons-dbcp-1.2.1.jar
> and
> commons-pool-1.3.jar

Lots of sync related fixes since then. I'd strongly recommend and upgrade.

Mark



---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
commons-dbcp-1.2.1.jar
and
commons-pool-1.3.jar

I have a connection handler class that I wrote around a static instance of
SharedPoolDataSource.  SharedPoolDataSource gets initialized in static
block.  Locking shown in stacktrace is occurring within
aSharedPoolDataSource.getConnection() call.  The lock on
aSharedPoolDataSource is never given up, all other threads back up waiting
to get db connection.  I'll start by updating my those jars, I'm certain
this is self inflicted wound and not a bug in either library.

"catalina-exec-foo1-2" daemon prio=10 tid=0x000000004bf5b800 nid=0x41a2
runnable [0x0000000042be1000]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at oracle.net.ns.Packet.receive(Packet.java:293)
    at oracle.net.ns.DataPacket.receive(DataPacket.java:92)
    at oracle.net.ns.NetInputStream.getNextPacket(NetInputStream.java:174)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:119)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:94)
    at oracle.net.ns.NetInputStream.read(NetInputStream.java:79)
    at
oracle.jdbc.driver.T4CSocketInputStreamWrapper.readNextPacket(T4CSocketInputStreamWrapper.java:112)
    at
oracle.jdbc.driver.T4CSocketInputStreamWrapper.read(T4CSocketInputStreamWrapper.java:73)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalUB1(T4CMAREngine.java:1040)
    at oracle.jdbc.driver.T4CMAREngine.unmarshalSB1(T4CMAREngine.java:1016)
    at oracle.jdbc.driver.T4C8Oall.receive(T4C8Oall.java:588)
    at oracle.jdbc.driver.T4CStatement.doOall8(T4CStatement.java:183)
    at
oracle.jdbc.driver.T4CStatement.executeForDescribe(T4CStatement.java:780)
    at
oracle.jdbc.driver.T4CStatement.executeMaybeDescribe(T4CStatement.java:855)
    at
oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1187)
    at
oracle.jdbc.driver.OracleStatement.executeQuery(OracleStatement.java:1378)
    - locked <0x00002aaad1f64df8> (a oracle.jdbc.driver.T4CConnection)
    at
oracle.jdbc.driver.OracleStatementWrapper.executeQuery(OracleStatementWrapper.java:387)
    at
org.apache.commons.dbcp.datasources.KeyedCPDSConnectionFactory.validateObject(KeyedCPDSConnectionFactory.java:163)
    at
org.apache.commons.pool.impl.GenericKeyedObjectPool.borrowObject(GenericKeyedObjectPool.java:837)
    - locked <0x00002aaace878d18> (a
org.apache.commons.pool.impl.GenericKeyedObjectPool)
    at
org.apache.commons.dbcp.datasources.SharedPoolDataSource.getPooledConnectionAndInfo(SharedPoolDataSource.java:165)
    - locked <0x00002aaaced306f8> (a
org.apache.commons.dbcp.datasources.SharedPoolDataSource)
    at
org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:631)
    at
org.apache.commons.dbcp.datasources.InstanceKeyDataSource.getConnection(InstanceKeyDataSource.java:615)
    at
mycompany.db.ConnectionHandler.getConnection(ConnectionHandler.java:150)

Re: tomcat 6.0.29 hung

Posted by Phil Steitz <ph...@gmail.com>.
On 10/20/10 7:11 PM, Jason Britton wrote:
> Thankfully when I pulled up jvisualvm on the server and issued thread dumps,
> even though the stacktraces for the threads did not come up within jvisualvm
> the thread stacktraces were dumped to stdout.  So I did get thread
> stacktraces in my tomcat log.    I won't post entire stacktraces here but
> almost all blocked threads seem to be stuck blocking here:
>
>      - waiting to lock<0x00002aaaced306f8>  (a
> org.apache.commons.dbcp.datasources.SharedPoolDataSource)
>
> One of my threads in runnable state has that locked
>
>      - locked<0x00002aaaced306f8>  (a
> org.apache.commons.dbcp.datasources.SharedPoolDataSource)

Looks like you are using Commons DBCP directly.  What versions of 
Commons DBCP and Commons Pool are you running?

Phil
>
> So I'm pretty sure I've found the thread hanging everything up.... now to
> take a look at the code and figure out why lock is not being released.
>
> Highly recommend trying out jvisualvm (it's in your jdk bin) if you're
> running 1.6.
>


---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@tomcat.apache.org
For additional commands, e-mail: users-help@tomcat.apache.org


Re: tomcat 6.0.29 hung

Posted by Jason Britton <jb...@gmail.com>.
Thankfully when I pulled up jvisualvm on the server and issued thread dumps,
even though the stacktraces for the threads did not come up within jvisualvm
the thread stacktraces were dumped to stdout.  So I did get thread
stacktraces in my tomcat log.    I won't post entire stacktraces here but
almost all blocked threads seem to be stuck blocking here:

    - waiting to lock <0x00002aaaced306f8> (a
org.apache.commons.dbcp.datasources.SharedPoolDataSource)

One of my threads in runnable state has that locked

    - locked <0x00002aaaced306f8> (a
org.apache.commons.dbcp.datasources.SharedPoolDataSource)

So I'm pretty sure I've found the thread hanging everything up.... now to
take a look at the code and figure out why lock is not being released.

Highly recommend trying out jvisualvm (it's in your jdk bin) if you're
running 1.6.

Re: tomcat 6.0.29 hung

Posted by Pid <pi...@pidster.com>.
On 20/10/2010 21:37, Jason Britton wrote:
> I have a tomcat instance hanging up (and currently still hung up) and would
> really appreciate pointers on how to debug further.
> A belated thanks to Konstantin for the info on kill -QUIT pid to retrieve
> thread dumps But I was only able to pull thread dumps on the hung process
> using jvisualvm.  Process failed to respond to kill -QUIT for unknown
> reasons.
> 
> Environment:
> Tomcat 6.0.29 - using native APR, running on 64-bit RHEL 5.5 - 32 GB ram
> java version "1.6.0_21"
> Java(TM) SE Runtime Environment (build 1.6.0_21-b06)
> Java HotSpot(TM) 64-Bit Server VM (build 17.0-b16, mixed mode)
> 
> I pulled 4 thread dumps in a 10 minute span on hung tomcat process after it
> was reported to be non-responsive.  Unfortunately not any differences
> between thread dumps and to my great dismay jstack is unable to retrieve any
> stacktraces on any of the threads reporting the following error:
> 
> Error occurred during stack walking:
> sun.jvm.hotspot.debugger.DebuggerException:
> sun.jvm.hotspot.debugger.DebuggerException: get_thread_regs failed for a lwp
>         at
> sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal$LinuxDebuggerLocalWorkerThread.execute(LinuxDebuggerLocal.java:152)
>         at
> sun.jvm.hotspot.debugger.linux.LinuxDebuggerLocal.getThreadIntegerRegisterSet(LinuxDebuggerLocal.java:466)
>         at
> sun.jvm.hotspot.debugger.linux.LinuxThread.getContext(LinuxThread.java:65)
>         at
> sun.jvm.hotspot.runtime.linux_amd64.LinuxAMD64JavaThreadPDAccess.getCurrentFrameGuess(LinuxAMD64JavaThreadPDAccess.java:92)
>         ............................................
> 
> From my googling this appears to be an unfixed bug with jstack, I sure would
> like to be wrong about that so I could get some stacktrace info on the
> threads of my hung process.
> 
> Any thoughts on how to possibly get stacktrace info on these threads with
> jstack broken(?) on my environment and any ideas on how to proceed with
> debugging this situation would be greatly appreciated.  Thanks -  Jason
> 
> Thread dump from hung tomcat process
> Thread 27817 "catalina-exec-foo-20": (state = BLOCKED)
> Thread 27267 "catalina-exec-foo-19": (state = BLOCKED)
> Thread 27082 "catalina-exec-foo-18": (state = BLOCKED)
> Thread 26591 "catalina-exec-foo-17": (state = BLOCKED)
> Thread 25899 "catalina-exec-foo-16": (state = BLOCKED)
> Thread 25590 "catalina-exec-foo-15": (state = BLOCKED)
> Thread 25589 "catalina-exec-foo-14": (state = BLOCKED)
> Thread 25586 "catalina-exec-foo-13": (state = BLOCKED)
> Thread 25578 "catalina-exec-foo-12": (state = BLOCKED)
> Thread 25565 "catalina-exec-foo-11": (state = BLOCKED)
> Thread 17427 "Thread-40": (state = BLOCKED)
> Thread 9128 "Thread-39": (state = IN_NATIVE)
> Thread 16811 "catalina-exec-foo-10": (state = BLOCKED)
> Thread 16810 "catalina-exec-foo-9": (state = BLOCKED)
> Thread 16809 "catalina-exec-foo-8": (state = IN_NATIVE)
> Thread 16808 "catalina-exec-foo-7": (state = BLOCKED)
> Thread 16807 "catalina-exec-foo-6": (state = IN_NATIVE)
> Thread 16806 "catalina-exec-foo-5": (state = BLOCKED)
> Thread 16805 "Thread-8": (state = BLOCKED)
> Thread 16804 "catalina-exec-foo-4": (state = BLOCKED)
> Thread 16803 "catalina-exec-foo-3": (state = BLOCKED)
> Thread 16802 "catalina-exec-foo-2": (state = IN_NATIVE)
> Thread 16801 "catalina-exec-foo-1": (state = IN_NATIVE)
> Thread 16791 "ajp-9009-Acceptor-0": (state = IN_NATIVE)
> Thread 16790 "ajp-9009-CometPoller-0": (state = BLOCKED)
> Thread 16789 "ajp-9009-Poller-0": (state = IN_NATIVE)
> Thread 16788 "http-8080-Acceptor-0": (state = IN_NATIVE)
> Thread 16787 "http-8080-Sendfile-0": (state = BLOCKED)
> Thread 16786 "http-8080-CometPoller-0": (state = BLOCKED)
> Thread 16785 "http-8080-Poller-0": (state = BLOCKED)
> Thread 16784 "ContainerBackgroundProcessor[StandardEngine[Catalina]]":
> (state = BLOCKED)
> Thread 16783 "Thread-6": (state = BLOCKED)
> Thread 16782 "Thread-5": (state = BLOCKED)
> Thread 16781 "Thread-4": (state = BLOCKED)
> Thread 16780 "Thread-3": (state = BLOCKED)
> Thread 16778 "Thread-2": (state = BLOCKED)
> Thread 16777 "GC Daemon": (state = BLOCKED)
> VM Thread 16775 "Low Memory Detector": (state = BLOCKED)
> VM Thread 16774 "CompilerThread1": (state = BLOCKED)
> VM Thread 16773 "CompilerThread0": (state = BLOCKED)
> Thread 16772 "Signal Dispatcher": (state = BLOCKED)
> Thread 16771 "Finalizer": (state = BLOCKED)
> Thread 16770 "Reference Handler": (state = BLOCKED)
> Thread 16764 "main": (state = IN_NATIVE)

Lot of stuff blocked there.  What is it blocked on?
Can you get a strack trace for each thread?


p