5 Replies Latest reply on May 17, 2005 6:05 AM by armorris007

    Worker thread count

    armorris007
    armorris007 May 9, 2005 5:57 AM

      We are having problems with our JBoss 2.4.3 based application which is resulting in nullpointer exceptions when trying to obtain a database connection from the pool - after the application has been running for a number of days.

      Whilst there seems to be no apparent reason for this happening, there is an issue which is puzzling me. The worker threads used to service user requests - named "Thread-4", etc ... seem to have reached very high numbers - for example "Thread-439" ..... given that the load on the service is relatively low - typically 1 users per minute, does this implicate a problem with threads that are not timing it?

      My question being, should JBoss be reusing worker threads? Such that a high thread number implies that there is a definate worker thread deadlock problem?

      Any help would be greatly appreciated.

      Many thanks,

      Andy

      • 4830 Views
      • Tags:
        • 1. Re: Worker thread count
          armorris007
          armorris007 May 9, 2005 6:32 AM (in response to armorris007)

          For example:


          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - TRANSACTION ROLLBACK EXCEPTION:null
          Embedded Exception
          null; nested exception is:
          javax.ejb.EJBException: null
          Embedded Exception
          null
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - java.lang.NullPointerException
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.pool.jdbc.xa.XAPoolDataSource.getConnection(XAPoolDataSource.java:178)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.common.CResourceFetcher.getEJBConnection(CResourceFetcher.java:70)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.associatesolutionp.CAssociateSolutionPDA.getConnection(CAssociateSolutionPDA.java:51)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.associatesolutionp.CAssociateSolutionPBL.createNewPattern(CAssociateSolutionPBL.java:519)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.associatesolutionp.CAssociateSolutionPBL.makeAssociation(CAssociateSolutionPBL.java:68)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.associatesolutionp.CAssociateSolutionPBean.makeAssociation(CAssociateSolutionPBean.java:65)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at sun.reflect.GeneratedMethodAccessor159.invoke(Unknown Source)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at java.lang.reflect.Method.invoke(Method.java:324)
          2005-02-18 14:21:53,375 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.StatelessSessionContainer$ContainerInterceptor.invoke(StatelessSessionContainer.java:543)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.StatelessSessionInstanceInterceptor.invoke(StatelessSessionInstanceInterceptor.java:87)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.TxInterceptorCMT.invokeNext(TxInterceptorCMT.java:133)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.TxInterceptorCMT.runWithTransactions(TxInterceptorCMT.java:307)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.TxInterceptorCMT.invoke(TxInterceptorCMT.java:99)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.SecurityInterceptor.invoke(SecurityInterceptor.java:128)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:195)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.StatelessSessionContainer.invoke(StatelessSessionContainer.java:286)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.jrmp.server.JRMPContainerInvoker.invoke(JRMPContainerInvoker.java:489)
          2005-02-18 14:21:53,390 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.jrmp.interfaces.GenericProxy.invokeContainer(GenericProxy.java:335)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.jboss.ejb.plugins.jrmp.interfaces.StatelessSessionProxy.invoke(StatelessSessionProxy.java:123)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at $Proxy12.makeAssociation(Unknown Source)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.associatesolutionp.CAssociateSolutionPEJB.makeAssociation(CAssociateSolutionPEJB.java:68)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.tag.search.AssociateSolutionButtonTagB.associateCommunityResult(AssociateSolutionButtonTagB.java:104)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.tag.search.AssociateSolutionButtonTagB.performAction(AssociateSolutionButtonTagB.java:54)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at com.mysoftware.tag.common.CActionTag.doStartTag(CActionTag.java:98)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at search._0002fsearch_0002fsearchcontrol_0002ejspsearchcontrol_jsp_0._jspService(_0002fsearch_0002fsearchcontrol_0002ejspsearchcontrol_jsp_0.java:204)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.jasper.runtime.HttpJspBase.service(HttpJspBase.java:119)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.jasper.servlet.JspServlet$JspCountedServlet.service(JspServlet.java:130)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.jasper.servlet.JspServlet$JspServletWrapper.service(JspServlet.java:282)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.jasper.servlet.JspServlet.serviceJspFile(JspServlet.java:429)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.jasper.servlet.JspServlet.service(JspServlet.java:500)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at javax.servlet.http.HttpServlet.service(HttpServlet.java:853)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.core.ServletWrapper.doService(ServletWrapper.java:405)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.core.Handler.service(Handler.java:287)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.core.ServletWrapper.service(ServletWrapper.java:372)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.core.ContextManager.internalService(ContextManager.java:812)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.core.ContextManager.service(ContextManager.java:758)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.service.http.HttpConnectionHandler.processConnection(HttpConnectionHandler.java:213)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.service.TcpWorkerThread.runIt(PoolTcpEndpoint.java:416)
          2005-02-18 14:21:53,406 [Thread-359] ERROR AssociateSolutionP AssociateSolutionP - at org.apache.tomcat.util.ThreadPool$ControlRunnable.run(ThreadPool.java:501)


            • Actions
          • 2. Re: Worker thread count
            jamesstrachan
            jamesstrachan May 9, 2005 9:54 AM (in response to armorris007)

            Andy,

            This feels like (but may not be) the problem of not properly releasing a connection after use. I assume that you are using BMP.

            Your code should look like :-

             public void ejbLoad() {

 Connection conn = null;
 PreparedStatement statement = null;
 InitialContext context = null;
 DataSource dataSource;
 ResultSet rs;

 String sqlStatement = "SELECT this, that from targetTable where groupkey = ?";

 groupKey = (String) ctx.getPrimaryKey();

 logger.info( "Load called : " + groupKey );

 try {

 // Get a database connection.
 context = new InitialContext();
 dataSource = (DataSource) context.lookup( DATASTORE_ADDRESS );
 conn = dataSource.getConnection();

 // Code to do the work omitted.
 // Lookup failed ?
 catch( NamingException ne ) {
 logger.error( ne.getMessage(), ne );
 throw new RemoteException( ne.getMessage() );
 }
 // Something nasty in the woodshed ?
 catch( SQLException sqe ) {
 logger.error( sqe.getMessage(), sqe );
 throw new RemoteException( sqe.getMessage() );
 }
 finally {
 try {
 if ( statement != null ) {
 statement.close();
 }
 if ( conn != null ) {
 conn.close();
 }
 }
 catch ( SQLException e1 ) {}
 }

 }

            where the code within the finally tatement releases the resources that you claimed earlier.

            I am guessing - you may have a far more exotic problem.

            James


              • Actions
            • 3. Re: Worker thread count
              armorris007
              armorris007 May 9, 2005 12:14 PM (in response to armorris007)

              Hi James,

              Thank you very much for your reply.
              We are indeed using BMP.

              I take your point regarding the possibility of there being an unreleased resource issue, however, all of our bean code is cut using the same templates and this does most definately includes the necessary close calls for the connection and statements. I'll be sure to manually confirm this though - cheers.

              The recurring issue that we are seeing is that the Thread number (as seen in the stack trace) JUMPS to very high numbers just prior to the reporting of failures to obtain database connections.

              If I understand correctly, this Thread number is tied to http request worker threads as started by the embedded Tomcat service.

              This in itself is very puzzling:
              1. It has no direct bearing on EJB threads and therefore in turn database connection usage - yet there seems to be this correlation between high worker thread numbers and a database connection dropout. Yet we have 100 connections in the db pool and yet presumably 300+ concurrent http worker threads.
              2. There is no logging for the missing 300+ Threads! Did they ever get created? What event occured that triggered them off? What are they doing? Why are they tieing up my database connections.

              As a point of note, having checked the tomcat.properties in our version of JBoss I've noted that there is a setting to turn the Tomcat ThreadPool on or off. This is set to the default of OFF - so it's not likely to be the purported buggy Tomcat ThreadPool code.

              Exotic is certainly one way of describing it. The test lifecycle for creating this problem can be days of normal application usage, therefore debugging is very difficult.

              Any thoughts on the possible causes for a jump in tomcat worker Thread numbers?

              I'm guessing somewhere along the line HTTP requests must be being made - which are not terminating with a response - yet they can't be being tied up by unclosed database connections - as there simply aren't enough of them in the pool to hold open the HTTP threads????

              Cheers,

              Andy

                • Actions
              • 4. Re: Worker thread count
                jamesstrachan
                jamesstrachan May 10, 2005 12:03 PM (in response to armorris007)

                Andy,

                This sort of problem is always a real hassle.

                I don't know the Tomcat internals at all. You may be able to switch on Log4J logging for some of the Tomcat internal classes to get a clue.

                The timing of the problem - after days of application usage - strongly suggests a problem somewhere with resources being allocated and not freed.

                Is there any way in which input parameters to methods near the point of failure can be set to null rather than the intended value ?

                I guess that the only way forward is to produce more debug output until you get a clue.

                You could upgrade to JBoss 3 in the hope that the problem will go away, but that upgrade is so fiddly and time consuming that it's better to persevere with your current version.

                James

                  • Actions
                • 5. Re: Worker thread count
                  armorris007
                  armorris007 May 17, 2005 6:05 AM (in response to armorris007)

                  Hi James,

                  Thanks for the reply again!

                  We've made some progress on the bug in that there was definately a connection that wasn't being closed - in one part of the code. This most certainly accounts for the pool connection problem.

                  However, we still have an ongoing problem whereby these Tomcat thread numbers continue to grow!!!! And eventually the system grinds to a halt. Sometimes described as a "freeze".

                  The strangest thing is - is that there are missing log entries for about 400+ threads (if I am to believe that Thread numbers are allocated in a sequential manner - as appears to be the case in the Tomcat code).

                  I will investigate turning on more debugging within Tomcat.

                  As for your migration idea, we are currently in the process of moving a new version of the code to JBoss 4.0.1.

                  Thanks again James for the sanity check,

                  Cheers,

                  Andy

                    • Actions