users@glassfish.java.net

Re: Debugging Glassfish CPU usage

From: Jeanfrancois Arcand <Jeanfrancois.Arcand_at_Sun.COM>
Date: Tue, 24 Mar 2009 11:46:48 +0100

Salut,

glassfish_at_javadesktop.org wrote:
> Hi Jeanfrancois,
>
> Could you clarify what you mean by "any web related call?"? In case it helps, we have anywhere from 500 - 900 users using the site during the "off-peak" times I mentioned before, compared to our "peak" times which range can reach 1600 concurrent users.
>
> The Java version on the server is 1.6.0_07-b06. Though, it should be noted that our team runs Apple computers, so the development environment Java version is 1.5.0_16-b06-284. Even though the server is 64-bit, we are running the 32-bit jvm in mixed mode on the recommendation of Scott Oaks, who advised me when configuring glassfish last fall.
>
> For thread dumps, see my reply to Kedar, above. I attached two jstack dumps, one from yesterday and one that just occurred. I have another from 2 days ago, but it was too large a file size to attach.
>

I've missed those. The issue might be

> "httpWorkerThread-80-197" daemon prio=10 tid=0x1d0a5000 nid=0xe0e waiting for monitor entry [0x04f72000..0x04f72dc0]
> java.lang.Thread.State: BLOCKED (on object monitor)
> at com.sun.enterprise.resource.AbstractResourcePool.transactionCompleted(AbstractResourcePool.java:1176)
> - waiting to lock <0x3bf7c598> (a com.sun.enterprise.resource.SJSASResourcePool)
> at com.sun.enterprise.resource.PoolManagerImpl.transactionCompleted(PoolManagerImpl.java:393)
> at com.sun.enterprise.resource.PoolManagerImpl$SynchronizationListener.afterCompletion(PoolManagerImpl.java:540)
> at com.sun.enterprise.distributedtx.J2EETransaction.commit(J2EETransaction.java:491)
> at com.sun.enterprise.distributedtx.J2EETransactionManagerOpt.commit(J2EETransactionManagerOpt.java:371)
> at com.sun.enterprise.distributedtx.UserTransactionImpl.commit(UserTransactionImpl.java:197)
> at org.j2free.jpa.Controller.endTransaction(Controller.java:158)
> at org.j2free.servlet.filter.InvokerFilter.doFilter(InvokerFilter.java:151)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:198)
> at org.j2free.servlet.filter.ErrorLogFilter.doFilter(ErrorLogFilter.java:103)
> at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:230)
> at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:198)
> at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:288)
> at org.apache.catalina.core.StandardContextValve.invokeInternal(StandardContextValve.java:271)
> at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:202)
> at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:632)
> at org.apache.catalina.core.StandardPipeline.doInvoke(StandardPipeline.java:577)
> at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:94)

but I also see in the second log:

> "httpWorkerThread-80-229" daemon prio=10 tid=0x08eccc00 nid=0x5833 runnable [0x35b59000..0x35b5b140]
> java.lang.Thread.State: RUNNABLE
> at java.net.SocketInputStream.socketRead0(Native Method)
> at java.net.SocketInputStream.read(SocketInputStream.java:129)
> at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
> at java.io.BufferedInputStream.read1(BufferedInputStream.java:258)
> at java.io.BufferedInputStream.read(BufferedInputStream.java:317)
> - locked <0xbad6e370> (a java.io.BufferedInputStream)
> at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:2452)
> at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2906)
> at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:2895)
> at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3438)
> at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:1951)
> at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2101)
> at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2554)
> - locked <0xbad6c648> (a java.lang.Object)
> at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:1761)
> at com.mysql.jdbc.PreparedStatement.executeQuery(PreparedStatement.java:1912)
> - locked <0xbad6c648> (a java.lang.Object)
> at org.hibernate.jdbc.AbstractBatcher.getResultSet(AbstractBatcher.java:186)
> at org.hibernate.loader.Loader.getResultSet(Loader.java:1787)
> at org.hibernate.loader.Loader.doQuery(Loader.java:674)
> at org.hibernate.loader.Loader.doQueryAndInitializeNonLazyCollections(Loader.java:236)
> at org.hibernate.loader.Loader.doList(Loader.java:2213)
> at org.hibernate.loader.Loader.listIgnoreQueryCache(Loader.java:2104)
> at org.hibernate.loader.Loader.list(Loader.java:2099)
> at org.hibernate.loader.hql.QueryLoader.list(QueryLoader.java:378)
> at org.hibernate.hql.ast.QueryTranslatorImpl.list(QueryTranslatorImpl.java:338)
> at org.hibernate.engine.query.HQLQueryPlan.performList(HQLQueryPlan.java:172)
> at org.hibernate.impl.SessionImpl.list(SessionImpl.java:1121)
> at org.hibernate.impl.QueryImpl.list(QueryImpl.java:79)
> at org.hibernate.ejb.QueryImpl.getSingleResult(QueryImpl.java:81)
> at org.j2free.jpa.Controller.query(Controller.java:653)
> at org.j2free.jpa.Controller.query(Controller.java:661)
> at com.tuneshero.servlet.ajax.FlexRequests.doGet(FlexRequests.java:309)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:718)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:831)

Jagadish, do you know if this could be the issue or not? But for sure
all Grizzly WorkerThread may gets locked by such call.

A+

-- Jeanfrancois


> Thanks!
> [Message sent by forum member 'rwillie6' (rwillie6)]
>
> http://forums.java.net/jive/thread.jspa?messageID=338656
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe_at_glassfish.dev.java.net
> For additional commands, e-mail: users-help_at_glassfish.dev.java.net
>