3 Replies Latest reply on Oct 30, 2003 6:11 AM by vladimir_l

    JBoss hangs up for exactly 60 sec.

      I'm fairly new to JBoss so may be the problem I have is not a problem at all.

      Background.

      There is a project that consists of about 60 business objects placed in 70 tables of Oracle database. To simplify the development and reduce the time middlegen (http://boss.bekk.no/boss/middlegen/) was used to generate the local entity EJB's with CMP and CMR. The struts templates generated by middlegen are used to access and manage business objects that are represented by EJB's.

      After some script modifications and small changes to the generated deployment descriptor I managed to deploy enterprise archive under JBoss (with truly much less problems then under BEA WebLogic).

      But life isn't only a barrel of honey!

      Problem.

      Trying to display a web page with information about 20 entities of a certain business object (regardless how big the table in database is - 40 or 2,000,000 entries) I have experienced the following problem: JBoss indefinably hangs from time to time, while displaying those 20 entries.

      Going through the server.log file and JBoss output didn't come to me with an explanation of the problem - there is no one error in both log files.

      Deeper analysis of server.log file revealed to me a very interesting fact: place where local EJB entities are requested and created is passed very fast (it happens in one of the struts action class) then references to retrieved EJB's are propagated to the jsp-pages to generate HTML output for the client.

      And here while parsing (or maybe preparing jsp) JBoss suddenly at undetermined moment hangs up for exactly one minute (60 + 1 seconds). Any activity of JBoss is stopped and it doesn't write anything to a log file. After 61 seconds JBoss wakes up and continues. If I'm lucky enough it happens only once or twice per page and I'm able to see the results on the client, if it is more then 4 times the page is never displayed in the browser, until I repeat my request.

      Questions and assumptions.

      It seems to me that it's some kind of internal timeout of JBoss. I've tried JBoss 3.2.2RC1, JBoss 3.2.2RC4 with Tomcat, JBoss 3.2.2 RC4 with Jetty the same problem remains with all of these versions of JBoss. Could anybody please explain what kind of JBoss timeout (default timeout) is set to 60 sec. and what is the reason for JBoss to wait?

      During that time the processor isn't use, the traffic between server and database is zero, JBoss is obviously waiting for something, but what it is waiting for?

      I'm looking forward to any help, ideas, and assumptions about this weird problem.

      Thank you in advance!
      Vladimir

        • 1. Re: JBoss hangs up for exactly 60 sec.
          jonlee

          This looks to be a performance related issue although the exact cause for your problem does not seem apparent at this stage. The following give some possible threads to explore that may provide some hints.
          http://www.jboss.org/modules/bb/index.html?module=bb&op=viewtopic&t= itself does not have any specific timing events. I would check things like the GC cycle as discussed in the thread. It doesn't seem like you have a JMS related issue either but that might give some hints on things to check.

          I would put some System.out.println() around some critical areas in your execution chain - say perhaps between starting a method, calling another EJB, returning from the call and leaving a method. I would also trap around the database connection area (get connection, query, close connection) if at all possible (perhaps not possible with the CMP/CMR). This would identify specific problems and also whether the JVM is doing anything strange. This would help folks determine a solution.

          • 2. Re: JBoss hangs up for exactly 60 sec.

            Press ctrl-break on windows
            ctrl-\ on unix
            to obtain a threadump

            This should show where it is hanging.

            A common cause of such random timeouts is a faulty dns,
            but it doesn't normally take 60 seconds for that to timeout.

            Regards,
            Adrian

            • 3. Re: JBoss hangs up for exactly 60 sec.

              Thank you guys!

              I didn't expect that somebody would answer my question with such patience. Special thanks to Adrian for his keen tip about Ctrl+Break. I didn't know about this feature and it really helped me to track out the problem.

              The problem was hiding behind connection to Oracle database. While I was waiting for the response from JBoss it was always reporting about opening or closing statement or query of Oracle databes.

              Like that:
              -------------------------------------
              "PoolThread-9" prio=5 tid=0x032c1d48 nid=0x9bc runnable [392e000..392fd8c]
              at java.net.SocketInputStream.socketRead0(Native Method)
              at java.net.SocketInputStream.read(SocketInputStream.java:129)
              at oracle.net.ns.Packet.receive(Unknown Source)
              at oracle.net.ns.NetInputStream.getNextPacket(Unknown Source)
              at oracle.net.ns.NetInputStream.read(Unknown Source)
              at oracle.net.ns.NetInputStream.read(Unknown Source)
              at oracle.net.ns.NetInputStream.read(Unknown Source)
              at oracle.jdbc.ttc7.MAREngine.unmarshalUB1(MAREngine.java:726)
              at oracle.jdbc.ttc7.MAREngine.unmarshalSB1(MAREngine.java:698)
              at oracle.jdbc.ttc7.Oopen.receive(Oopen.java:103)
              at oracle.jdbc.ttc7.TTC7Protocol.open(TTC7Protocol.java:466)
              - locked <0x12218c38> (a oracle.jdbc.ttc7.TTC7Protocol)
              at oracle.jdbc.driver.OracleStatement.(OracleStatement.java:441)
              at oracle.jdbc.driver.OracleStatement.(OracleStatement.java:460)
              at oracle.jdbc.driver.OraclePreparedStatement.(OraclePreparedStatement.java:185)
              at oracle.jdbc.driver.OraclePreparedStatement.(OraclePreparedStatement.java:168)
              at oracle.jdbc.driver.OracleConnection.privatePrepareStatement(OracleConnection.java:614)
              at oracle.jdbc.driver.OracleConnection.prepareStatement(OracleConnection.java:492)
              - locked <0x121fe370> (a oracle.jdbc.driver.OracleConnection)
              at org.jboss.resource.adapter.jdbc.WrappedConnection.prepareStatement(WrappedConnection.java:221)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.execute(JDBCLoadEntityCommand.java:149)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.execute(JDBCLoadEntityCommand.java:83)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.loadEntity(JDBCStoreManager.java:632)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.loadEntity(JDBCStoreManager.java:614)
              at org.jboss.ejb.plugins.CMPPersistenceManager.loadEntity(CMPPersistenceManager.java:386)
              at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.loadEntity(CachedConnectionInterceptor.java:353)
              at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:232)
              at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
              at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:82)
              at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:174)
              at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:89)
              at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:53)
              at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
              at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:243)
              at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:104)
              at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:117)
              at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
              at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
              at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:484)
              at org.jboss.ejb.Container.invoke(Container.java:673)
              at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:353)
              at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:38)
              at $Proxy165.getImagename(Unknown Source)
              at com.claritycontrol.model.web.struts.GetAllIpsymbolAction.execute(GetAllIpsymbolAction.java:88)
              at org.apache.struts.action.RequestProcessor.processActionPerform(RequestProcessor.java:484)
              at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:274)
              at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
              at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:507)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:360)
              at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:294)
              at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:558)
              at org.mortbay.http.HttpContext.handle(HttpContext.java:1714)
              at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:505)
              at org.mortbay.http.HttpContext.handle(HttpContext.java:1664)
              at org.mortbay.http.HttpServer.service(HttpServer.java:879)
              at org.jboss.jetty.Jetty.service(Jetty.java:460)
              at org.mortbay.http.HttpConnection.service(HttpConnection.java:770)
              at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:932)
              at org.mortbay.http.HttpConnection.handle(HttpConnection.java:787)
              at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:201)
              at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:289)
              at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:454)
              ====================

              Or like that:
              -------------------------------------
              "PoolThread-9" prio=5 tid=0x03285bb8 nid=0xe04 runnable [392e000..392fd8c]
              at java.net.SocketInputStream.socketRead0(Native Method)
              at java.net.SocketInputStream.read(SocketInputStream.java:129)
              at oracle.net.ns.Packet.receive(Unknown Source)
              at oracle.net.ns.DataPacket.receive(Unknown Source)
              at oracle.net.ns.NetInputStream.getNextPacket(Unknown Source)
              at oracle.net.ns.NetInputStream.read(Unknown Source)
              at oracle.net.ns.NetInputStream.read(Unknown Source)
              at oracle.net.ns.NetInputStream.read(Unknown Source)
              at oracle.jdbc.ttc7.MAREngine.unmarshalUB1(MAREngine.java:931)
              at oracle.jdbc.ttc7.MAREngine.unmarshalSB1(MAREngine.java:893)
              at oracle.jdbc.ttc7.Oclose.receive(Oclose.java:101)
              at oracle.jdbc.ttc7.TTC7Protocol.closeQuery(TTC7Protocol.java:634)
              - locked <0x122f1428> (a oracle.jdbc.ttc7.TTC7Protocol)
              at oracle.jdbc.driver.OracleResultSetImpl.internal_close(OracleResultSetImpl.java:1492)
              at oracle.jdbc.driver.OracleResultSetImpl.next(OracleResultSetImpl.java:267)
              - locked <0x10147938> (a oracle.jdbc.driver.OracleResultSetImpl)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.execute(JDBCLoadEntityCommand.java:170)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCLoadEntityCommand.execute(JDBCLoadEntityCommand.java:83)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.loadEntity(JDBCStoreManager.java:632)
              at org.jboss.ejb.plugins.cmp.jdbc.JDBCStoreManager.loadEntity(JDBCStoreManager.java:614)
              at org.jboss.ejb.plugins.CMPPersistenceManager.loadEntity(CMPPersistenceManager.java:386)
              at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.loadEntity(CachedConnectionInterceptor.java:353)
              at org.jboss.ejb.plugins.EntitySynchronizationInterceptor.invoke(EntitySynchronizationInterceptor.java:232)
              at org.jboss.resource.connectionmanager.CachedConnectionInterceptor.invoke(CachedConnectionInterceptor.java:186)
              at org.jboss.ejb.plugins.EntityReentranceInterceptor.invoke(EntityReentranceInterceptor.java:82)
              at org.jboss.ejb.plugins.EntityInstanceInterceptor.invoke(EntityInstanceInterceptor.java:174)
              at org.jboss.ejb.plugins.EntityLockInterceptor.invoke(EntityLockInterceptor.java:89)
              at org.jboss.ejb.plugins.EntityCreationInterceptor.invoke(EntityCreationInterceptor.java:53)
              at org.jboss.ejb.plugins.AbstractTxInterceptor.invokeNext(AbstractTxInterceptor.java:84)
              at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:243)
              at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:104)
              at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:117)
              at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:191)
              at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
              at org.jboss.ejb.EntityContainer.internalInvoke(EntityContainer.java:484)
              at org.jboss.ejb.Container.invoke(Container.java:673)
              at org.jboss.ejb.plugins.local.BaseLocalProxyFactory.invoke(BaseLocalProxyFactory.java:353)
              at org.jboss.ejb.plugins.local.EntityProxy.invoke(EntityProxy.java:38)
              at $Proxy165.getImagename(Unknown Source)
              at sun.reflect.GeneratedMethodAccessor58.invoke(Unknown Source)
              at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              at java.lang.reflect.Method.invoke(Method.java:324)
              at org.apache.commons.beanutils.PropertyUtils.getSimpleProperty(PropertyUtils.java:1185)
              at org.apache.commons.beanutils.PropertyUtils.getNestedProperty(PropertyUtils.java:772)
              at org.apache.commons.beanutils.PropertyUtils.getProperty(PropertyUtils.java:801)
              at org.apache.struts.util.RequestUtils.lookup(RequestUtils.java:952)
              at org.apache.struts.taglib.bean.WriteTag.doStartTag(WriteTag.java:286)
              at org.apache.jsp.allIpsymbol_jsp._jspx_meth_bean_write_3(allIpsymbol_jsp.java:1380)
              at org.apache.jsp.allIpsymbol_jsp._jspService(allIpsymbol_jsp.java:238)
              at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:137)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              at org.apache.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:210)
              at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:295)
              at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:241)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:360)
              at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:294)
              at org.mortbay.jetty.servlet.Dispatcher.dispatch(Dispatcher.java:206)
              at org.mortbay.jetty.servlet.Dispatcher.forward(Dispatcher.java:133)
              at org.apache.struts.action.RequestProcessor.doForward(RequestProcessor.java:1069)
              at org.apache.struts.tiles.TilesRequestProcessor.doForward(TilesRequestProcessor.java:274)
              at org.apache.struts.action.RequestProcessor.processForwardConfig(RequestProcessor.java:455)
              at org.apache.struts.tiles.TilesRequestProcessor.processForwardConfig(TilesRequestProcessor.java:320)
              at org.apache.struts.action.RequestProcessor.process(RequestProcessor.java:279)
              at org.apache.struts.action.ActionServlet.process(ActionServlet.java:1482)
              at org.apache.struts.action.ActionServlet.doGet(ActionServlet.java:507)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:740)
              at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
              at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:360)
              at org.mortbay.jetty.servlet.WebApplicationHandler.dispatch(WebApplicationHandler.java:294)
              at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:558)
              at org.mortbay.http.HttpContext.handle(HttpContext.java:1714)
              at org.mortbay.jetty.servlet.WebApplicationContext.handle(WebApplicationContext.java:505)
              at org.mortbay.http.HttpContext.handle(HttpContext.java:1664)
              at org.mortbay.http.HttpServer.service(HttpServer.java:879)
              at org.jboss.jetty.Jetty.service(Jetty.java:460)
              at org.mortbay.http.HttpConnection.service(HttpConnection.java:770)
              at org.mortbay.http.HttpConnection.handleNext(HttpConnection.java:932)
              at org.mortbay.http.HttpConnection.handle(HttpConnection.java:787)
              at org.mortbay.http.SocketListener.handleConnection(SocketListener.java:201)
              at org.mortbay.util.ThreadedServer.handle(ThreadedServer.java:289)
              at org.mortbay.util.ThreadPool$PoolThread.run(ThreadPool.java:454)
              ====================

              Regardless where it happens either in action that tries to retrieve entity EJB or during processing JSP page it seems to be always stuck with Oracle problem.

              So I switched from development Oracle server to the stage server to check whether the problem is still remaining. And... oh miracle! I didn't note any problem with hanging up for 60 sec.

              It looks like we got some problems with our development Oracle server installation.

              Once again, thank you very much!

              Yours sincerely,
              Vladimir