4 Replies Latest reply on Dec 4, 2006 9:09 AM by alchemista

    JBossMQ Fails under load - Exiting on IOE

    alchemista

      In a production environment, I've had several cases where my JBossMQ has failed under load. The problem is described below. I was wondering if someone else has solved this problem before, or has any ideas?

      The setup is that I have a JBoss application server (1) on Windows sending logs over log4j JMS appender to JBoss application server (2) on Linux.

      The server (2) is configured to use the HSQLDB persistence manager, is set to use 1GB ram for the JVM and has the high/max memory set to 80% and 90% of the JVM ram.

      The source of the logging data server (1) can send very large amounts of logs over JMS to the logging server (2). This load is fairly high during the day, and occasionally causes the JBossMQ on server (2) to completely fail.

      The first errors are of the format below. In some cases reconnection occurs, but in other cases the logging server (2) will continuously refuse connections. When this failure happens, I have to stop the logging server (2), often delete the HSQLDB data directory and then restart logging server (2).

      org.jboss.mq.SpyJMSException: Exiting on IOE; - nested throwable: (java.net.SocketException: Connection reset)
      at org.jboss.mq.SpyJMSException.getAsJMSException(SpyJMSException.java:66)
      at org.jboss.mq.Connection.asynchFailure(Connection.java:437)
      at org.jboss.mq.il.uil2.UILClientILService.asynchFailure(UILClientILService.java:156)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.handleStop(SocketManager.java:413)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:345)
      at java.lang.Thread.run(Thread.java:595)
      Caused by: java.net.SocketException: Connection reset
      at java.net.SocketInputStream.read(SocketInputStream.java:168)
      at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
      at java.io.BufferedInputStream.read(BufferedInputStream.java:235)
      at org.jboss.util.stream.NotifyingBufferedInputStream.read(NotifyingBufferedInputStream.java:67)
      at java.io.ObjectInputStream$PeekInputStream.peek(ObjectInputStream.java:2200)
      at java.io.ObjectInputStream$BlockDataInputStream.readBlockHeader(ObjectInputStream.java:2380)
      at java.io.ObjectInputStream$BlockDataInputStream.refill(ObjectInputStream.java:2447)
      at java.io.ObjectInputStream$BlockDataInputStream.read(ObjectInputStream.java:2519)
      at java.io.ObjectInputStream$BlockDataInputStream.readByte(ObjectInputStream.java:2668)
      at java.io.ObjectInputStream.readByte(ObjectInputStream.java:864)
      at org.jboss.mq.il.uil2.SocketManager$ReadTask.run(SocketManager.java:290)





      Hardcore failure can give continuous messages:

      javax.naming.CommunicationException [Root exception is java.rmi.UnmarshalException: Error unmarshaling return; nested exception is:
      java.io.EOFException]
      at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:707)
      at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:572)
      at javax.naming.InitialContext.lookup(InitialContext.java:351)
      at com.lmco.lits.james.core.cdf.ReconnectingJMSAppender.initializeConnection(ReconnectingJMSAppender.java:166)
      at com.lmco.lits.james.core.cdf.ReconnectingJMSAppender.onException(ReconnectingJMSAppender.java:319)
      at org.jboss.mq.Connection$ExceptionListenerRunnable.run(Connection.java:1366)
      at java.lang.Thread.run(Thread.java:595)
      Caused by: java.rmi.UnmarshalException: Error unmarshaling return; nested exception is:
      java.io.EOFException
      at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:217)
      at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:126)
      at org.jnp.server.NamingServer_Stub.lookup(Unknown Source)
      at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:610)
      ... 6 more
      Caused by: java.io.EOFException
      at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2502)
      at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1267)
      at java.io.ObjectInputStream.readArray(ObjectInputStream.java:1628)
      at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1293)
      at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1912)
      at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1836)
      at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1713)
      at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1299)
      at java.io.ObjectInputStream.readObject(ObjectInputStream.java:339)
      at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:215)
      ... 9 more

        • 1. Re: JBossMQ Fails under load - Exiting on IOE
          jgaracci

          Did you ever resolve this issue? I'm experiencing similar problems. I see the hsqldb data file growing to +400MB and a periodic action occurring in hsqldb that seems to gobble up the resources so nothing happens. Everything then times-out.

          Is this a known issue with hsqldb under load? At this point I'm considering replacing it. Have also found some posts stating it is a good idea to replace.

          Thanks

          • 2. Re: JBossMQ Fails under load - Exiting on IOE
            shantanu

            I have similar problem in which hypersonic database as queue.
            Initially the messages shall be dequeued at good speed. However with time the dequeue process become extremely slow and finally come to a halt.

            Lots of time I got to see the "Exiting on IOE" error on my server.log.

            However I was told that we can safely ignore this error.
            Is this true?

            regards
            Shantanu Chauhan

            • 3. Re: JBossMQ Fails under load - Exiting on IOE
              alchemista

              I'm still having the same problem. If there is an ERROR in the log, I would not ignore it, if it's just a DEBUG or INFO maybe. My connection will hard-die (i.e. never come back to life) after this error occurs too often.

              On the server-side, the server.log throws the following error around the time the client gives the error posted earlier.

              2006-11-30 16:31:34,159 ERROR [org.jboss.ejb.plugins.LogInterceptor] Unexpected
              Error in method: public abstract void javax.jms.MessageListener.onMessage(javax.jms.Message)
              java.lang.OutOfMemoryError: Java heap space
              2006-11-30 16:31:34,160 ERROR [org.jboss.ejb.plugins.jms.JMSContainerInvoker] Exception in JMSCI message listener
              javax.ejb.EJBException: Unexpected Error
              java.lang.OutOfMemoryError: Java heap space
              at org.jboss.ejb.plugins.LogInterceptor.handleException(LogInterceptor.java:395)
              at org.jboss.ejb.plugins.LogInterceptor.invoke(LogInterceptor.java:196)
              at org.jboss.ejb.plugins.ProxyFactoryFinderInterceptor.invoke(ProxyFactoryFinderInterceptor.java:122)
              at org.jboss.ejb.MessageDrivenContainer.internalInvoke(MessageDrivenContainer.java:389)
              at org.jboss.ejb.Container.invoke(Container.java:873)
              at org.jboss.ejb.plugins.jms.JMSContainerInvoker.invoke(JMSContainerInvoker.java:1090)
              at org.jboss.ejb.plugins.jms.JMSContainerInvoker$MessageListenerImpl.onMessage(JMSContainerInvoker.java:1392)
              at org.jboss.jms.asf.StdServerSession.onMessage(StdServerSession.java:256)
              at org.jboss.mq.SpyMessageConsumer.sessionConsumerProcessMessage(SpyMessageConsumer.java:904)
              at org.jboss.mq.SpyMessageConsumer.addMessage(SpyMessageConsumer.java:160)
              at org.jboss.mq.SpySession.run(SpySession.java:333)
              at org.jboss.jms.asf.StdServerSession.run(StdServerSession.java:180)
              at EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run(PooledExecutor.java:748)
              at java.lang.Thread.run(Thread.java:595)

              2006-11-30 16:33:32,663 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin ReadTask.run
              2006-11-30 16:33:32,663 DEBUG [org.jboss.mq.il.uil2.SocketManager] Begin WriteTask.run
              2006-11-30 16:33:32,663 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectInputStream
              2006-11-30 16:33:32,663 DEBUG [org.jboss.mq.il.uil2.SocketManager] Created ObjectOutputStream
              2006-11-30 16:33:32,667 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler]
              Setting up the UILClientIL Connection
              2006-11-30 16:33:32,667 DEBUG [org.jboss.mq.il.uil2.ServerSocketManagerHandler]
              The UILClientIL Connection is set up
              2006-11-30 16:34:59,549 ERROR [org.jboss.mq.il.uil2.SocketManager] Failed to handle: org.jboss.mq.il.uil2.msgs.AddMsg20684031[msgType: m_addMessage, msgID: -2147473491, error: null]
              java.lang.OutOfMemoryError: Java heap space

              • 4. Re: JBossMQ Fails under load - Exiting on IOE
                alchemista

                Also, if I try to do a Twiddle thread-dump while in the failed state I get the following errors:

                [root@box bin]# sh twiddle.sh invoke "jboss.system:type=ServerInfo" listThreadDump
                08:58:12,403 ERROR [Twiddle] Exec failed
                org.jboss.util.NestedRuntimeException: - nested throwable: (javax.naming.CommunicationException [Root exception is java.rmi.UnmarshalException: Error unmarshaling return header; nested exception is:
                java.io.EOFException])
                at org.jboss.console.twiddle.Twiddle$1.getServer(Twiddle.java:137)
                at org.jboss.console.twiddle.command.MBeanServerCommand.getMBeanServer(MBeanServerCommand.java:47)
                at org.jboss.console.twiddle.command.MBeanServerCommand.queryMBeans(MBeanServerCommand.java:54)
                at org.jboss.console.twiddle.command.InvokeCommand.execute(InvokeCommand.java:262)
                at org.jboss.console.twiddle.Twiddle.main(Twiddle.java:293)
                Caused by: javax.naming.CommunicationException [Root exception is java.rmi.UnmarshalException: Error unmarshaling return header; nested exception is: java.io.EOFException]
                at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:707)
                at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:572)
                at javax.naming.InitialContext.lookup(InitialContext.java:351)
                at org.jboss.console.twiddle.Twiddle.createMBeanServerConnection(Twiddle.java:244)
                at org.jboss.console.twiddle.Twiddle.connect(Twiddle.java:262)
                at org.jboss.console.twiddle.Twiddle.access$300(Twiddle.java:56)
                at org.jboss.console.twiddle.Twiddle$1.getServer(Twiddle.java:133)
                ... 4 more
                Caused by: java.rmi.UnmarshalException: Error unmarshaling return header; nested exception is:
                java.io.EOFException
                at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:203)
                at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:126)
                at org.jnp.server.NamingServer_Stub.lookup(Unknown Source)
                at org.jnp.interfaces.NamingContext.lookup(NamingContext.java:610)
                ... 10 more
                Caused by: java.io.EOFException
                at java.io.DataInputStream.readByte(DataInputStream.java:243)
                at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:189)
                ... 13 more