7 Replies Latest reply on Mar 19, 2009 12:19 PM by reiterweg

    UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA

    gogoasa

      Hello,

      I see the thread leak problem described in http://jira.jboss.org/jira/browse/JBAS-4525 was backported for the 4.0.3 branch in http://jira.jboss.org/jira/browse/ASPATCH-300.

      I am using 4.0.5GA, and still the thread leak behaviour manifests itself. Inspecting the jvm with JConsole, i can see lots of UIL2.SocketManager.ReadTask /WriteTask pairs that accumulate. When the number of started threads reaches a couple of millions, I get OutOfMemoryError. Could anybody confirm that the patch made it to 4.0.5.GA too and not only to 4.0.3sp1. ? Any other advice?

      For illustration, here is the stacktrace of a blocked ReadTask :

      Name: UIL2.SocketManager.ReadTask#1 client=172.20.20.160:8093
      State: RUNNABLE
      Total blocked: 0 Total waited: 0
      
      Stack trace:
      java.net.SocketInputStream.socketRead0(Native Method)
      java.net.SocketInputStream.read(SocketInputStream.java:129)
      java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      java.io.BufferedInputStream.read(BufferedInputStream.java:235)
      org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:79)
      java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2196)
      java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2376)
      java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2443)
      java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2515)
      java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2664)
      java.io.ObjectInputStream.readByte(ObjectInputStream.java:875)
      org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:316)
      java.lang.Thread.run(Thread.java:595)
      


      and of a blocked WriteTask :

      Name: UIL2.SocketManager.WriteTask#3 client=172.20.20.160:3486
      State: WAITING on java.lang.Object@67692e
      Total blocked: 0 Total waited: 69
      
      Stack trace:
      java.lang.Object.wait(Native Method)
      java.lang.Object.wait(Object.java:474)
      EDU.oswego.cs.dl.util.concurrent.LinkedQueue.take(LinkedQueue.java:122)
      org.jboss.mq.il.uil2.SocketManager$WriteTask.run(SocketManager.java:518)
      java.lang.Thread.run(Thread.java:595)
      


      Thank you,
      Adrian.

        • 1. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
          gogoasa

          Ok, I confirm it myself : ASPATCH300 didn't make it in the 4.0.5GA. But, if you look at the svn rep, you can see that it has been eventually merged :

          The history of SocketManager.java in 4.0.5:
          http://viewvc.jboss.org/cgi-bin/viewvc.cgi/jbossas/tags/JBoss_4_0_5_GA_CP11/messaging/src/main/org/jboss/mq/il/uil2/SocketManager.java?view=log

          the 4.0.5.GA_CP11 release contains the fix. So, people having the same problem, svn checkout that release and build it.



          Some further URLs concerning this issue:

          The backport JIRA issue:
          http://jira.jboss.org/jira/browse/ASPATCH-300?page=com.atlassian.jira.plugin.ext.subversion:subversion-commits-tabpanel

          The diff showing what changed :
          http://viewvc.jboss.org/cgi-bin/viewvc.cgi/jbossas/branches/JBoss_4_0_3_SP1_CP/messaging/src/main/org/jboss/mq/il/uil2/SocketManager.java/?revision=66324&r1=66324&r2=66323

          The patched file in 4.0.3SP1 :
          http://viewvc.jboss.org/cgi-bin/viewvc.cgi/jbossas/branches/JBoss_4_0_3_SP1_CP/messaging/src/main/org/jboss/mq/il/uil2/SocketManager.java?revision=67114&view=markup

          • 2. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
            gogoasa

            Ok, the problem was that the jBPM installation I used did not close connections after each and every JMS message send it did.

            In fact, jBPM JMS subsystem keeps one single Connection and Session for the whole life of the server application.

            The JMS specification says that :

            A JMS Connection is a client'™s active connection to its JMS provider. It will
            typically allocate provider resources outside the Java virtual machine.

            Connection objects support concurrent use.


            and

            A JMS Session is a single-threaded context for producing and consuming
            messages. Although it may allocate provider resources outside the Java virtual
            machine, it is considered a lightweight JMS object.


            If I read between the lines correctly, this should mean that it is acceptable to keep a costly Connection for a long time while it is not really acceptable to keep a "lightweight" Session for a long time.

            If I close Sessions but not Connections, the thread blocking still persists. So I modified the code to close both and the thread blocking no longer appears.

            Is it normal that if a Connection is hold for a long time, a thread leak, eventually followed by OutOfMemory, occur ?



            • 3. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
              gogoasa

              I was wrong, the ReadTask/WriteTask pairs still accumulate, my JConsole was not refreshing the thread list which lead me to think the problem was over.

              • 4. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
                gogoasa

                Ok, so here is how I solved the problem.

                It is due effectively to the fact that a connection is not closed. I thought I knew all the points in the application that interacted with JMS, I checked and double checked them, still there was a place that did its own JMS sending without closing connections (and using the non XA /ConnectionFactory).

                What allowed me to realize where the problem was is that by enabling TRACE on org.jboss.mq, every time a message is sent you have a stacktrace of where that call is coming from. So in my case here PublisherToJmsTopic was the class I had completely forgotten about.

                2008-02-15 11:20:51,498 TRACE [JMS SessionPool Worker-1-org.jboss.mq.il.uil2.SocketManager] start called
                java.lang.Exception: Start stack trace
                 at org.jboss.mq.il.uil2.SocketManager.start(SocketManager.java:112)
                 at org.jboss.mq.il.uil2.UILServerIL.createConnection(UILServerIL.java:523)
                 at org.jboss.mq.il.uil2.UILServerIL.getSocketMgr(UILServerIL.java:390)
                 at org.jboss.mq.il.uil2.UILServerIL.authenticate(UILServerIL.java:277)
                 at org.jboss.mq.Connection.authenticate(Connection.java:1067)
                 at org.jboss.mq.Connection.<init>(Connection.java:252)
                 at org.jboss.mq.Connection.<init>(Connection.java:323)
                 at org.jboss.mq.SpyConnection.<init>(SpyConnection.java:116)
                 at org.jboss.mq.SpyConnectionFactory.internalCreateConnection(SpyConnectionFactory.java:137)
                 at org.jboss.mq.SpyConnectionFactory.createTopicConnection(SpyConnectionFactory.java:118)
                 at fr.bnf.entrychain.internalservice.impl.PublisherToJmsTopic.publishEvent(PublisherToJmsTopic.java:31)
                 at fr.bnf.entrychain.internalservice.impl.InternalOrchestrationServiceImpl.publishEvent(InternalOrchestrationServiceImpl.java:59)
                 at fr.bnf.entrychain.internalservice.impl.InternalOrchestrationServiceBean.publishEvent(InternalOrchestrationServiceBean.java:40)
                 at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
                


                The JDBC pool in JBoss has a nice feature that closes unclosed connections showing the stracktrace of the point that opened the connection. Not that developers should use that as connection closing mechanism but it is helpful for debugging.

                • 5. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
                  reiterweg

                  Hi gogoasa, please can you give a more detailed explanation on how you solve this problem? I'm having the same trouble.

                  • 6. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
                    gogoasa

                    There is an incantation you *must* follow when you send/receive your JMS message. If you don't close the connection, the session or whatever, you get this. So make sure in all the points where you use JMS, you properly close things up.

                    And, as I said, enable TRACE in log4j.xml in order to see where your problem comes from.

                    • 7. Re: UIL2 ReadTask / WriteTask thread leak on 4.0.5 GA
                      reiterweg

                      Thank you so much! The problem was that. I was closing QueueSender and QueueSession but not QueueConnection.