Java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction

[tyagiarya]

Hi All,

Recently I have started working on messaging project which is installed on wildfly 8.0.0.CR1, the issue is that sometimes the messages are lost i.e the sender sends the message to the queue but because of some unstable state (not sure) of wildfly the messages are not processed successfully and are also lost from the queue. The behavior is regular but we are not sure when it will happen.This time when it happened I see following error in the server log and application log. Does it seems to be only because of memory reached for GC or some other issue,  Since I am new to messaging any advice will really help or some direction to proceed.

server log

2014-09-21 12:30:32,366 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:33:14,153 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:31:10,040 WARNING (NioEventLoop.java:run:362) Unexpected exception in the selector loop.: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:32:43,187 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:33:02,858 WARNING (NioEventLoop.java:run:362) Unexpected exception in the selector loop.: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:30:25,455 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:31:57,464 WARNING (SingleThreadEventExecutor.java:run:104) Unexpected exception from an event executor: : java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:30:07,375 WARNING (SingleThreadEventExecutor.java:run:104) Unexpected exception from an event executor: : java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-09-21 12:32:08,555 ERROR (AbstractLoggingWriter.java:write:71) Exception in thread "Thread-20919 (HornetQ-client-global-threads-1772173074)" Exception in thread "IdleRemover" java.lang.OutOfMemoryError: GC overhead limit exceeded

Application log

2014-09-21 12:59:57,744 ERROR (POSConnectionManager.java:getConnectionForMDB:128)

java.sql.SQLException: javax.resource.ResourceException: IJ000460: Error checking for a transaction

  at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:162)

  at com.osi.pos.common.util.POSConnectionManager.getConnectionForMDB(POSConnectionManager.java:113)

  at com.osi.pos.ejb.POSStoreInboundMDB.executeQueries(POSStoreInboundMDB.java:130)

  at com.osi.pos.ejb.POSStoreInboundMDB.onMessage(POSStoreInboundMDB.java:82)

  at sun.reflect.GeneratedMethodAccessor25.invoke(Unknown Source)

  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

  at java.lang.reflect.Method.invoke(Method.java:606)

  at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)

  at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53)

  at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:63)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

  at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.pool.PooledInstanceInterceptor.processInvocation(PooledInstanceInterceptor.java:51)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:251)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:342)

  at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:239)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:43)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:95)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:55)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.as.ejb3.component.messagedriven.MessageDrivenComponentDescription$5$1.processInvocation(MessageDrivenComponentDescription.java:211)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:64)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:325)

  at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:437)

  at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:61)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:325)

  at org.jboss.invocation.PrivilegedWithCombinerInterceptor.processInvocation(PrivilegedWithCombinerInterceptor.java:80)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

  at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:185)

  at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182)

  at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:309)

  at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61)

  at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:73)

  at com.osi.pos.ejb.POSStoreInboundMDB$$$view2.onMessage(Unknown Source)

  at sun.reflect.GeneratedMethodAccessor25.invoke(Unknown Source)

  at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)

  at java.lang.reflect.Method.invoke(Method.java:606)

  at org.jboss.as.ejb3.inflow.MessageEndpointInvocationHandler.doInvoke(MessageEndpointInvocationHandler.java:139)

  at org.jboss.as.ejb3.inflow.AbstractInvocationHandler.invoke(AbstractInvocationHandler.java:73)

  at com.osi.pos.ejb.POSStoreInboundMDB$$$endpoint2.onMessage(Unknown Source)

  at org.hornetq.ra.inflow.HornetQMessageHandler.onMessage(HornetQMessageHandler.java:321)

  at org.hornetq.core.client.impl.ClientConsumerImpl.callOnMessage(ClientConsumerImpl.java:1117)

  at org.hornetq.core.client.impl.ClientConsumerImpl.access$500(ClientConsumerImpl.java:57)

  at org.hornetq.core.client.impl.ClientConsumerImpl$Runner.run(ClientConsumerImpl.java:1252)

  at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:107)

  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)

  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)

  at java.lang.Thread.run(Thread.java:744)

Caused by: javax.resource.ResourceException: IJ000460: Error checking for a transaction

  at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:416)

  at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:513)

  at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:154)

  ... 75 more

Caused by: javax.resource.ResourceException: IJ000459: Transaction is not active: tx=TransactionImple < ac, BasicAction: 0:ffff0a87680b:9fee691:5417a8b4:1fabc status: ActionStatus.ABORTED >

  at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:400)

  ... 77 more

Thanks,

[jbertram]

When you say messages are "lost" what exactly do you mean?  Have you looked for messages in your DLQ (assuming you have one configured)?

Can you clarify your use-case a bit?  I assume you have an MDB consuming a message and then doing some database work then sending a message to some other queue.  Is that correct?

If your MDB is configured properly (e.g. it is consuming the messages in a JTA transaction) and you're sending your messages with an XA resource then messages should never be lost.

[tyagiarya]

Thanks Justin for the reply.

Let me try to explain to the best of my knowledge of understanding the application.

Use Case : We have Inbound queue and outbound queue to receive and send messages.Once the message is received/sent in the queue, the MDB(Inbound and Outbound) consumes the message and make n number of attempts to process it (db operation). If it doesn't succeed it makes a failed entry in a table T. A thread picks up that failed entry a regular interval of time and sends it back to queue to process.

We have two different databases and messaging is used to make the data in synch between the two db.Some times JMS just stops processing the message, I am not sure the messages are still in the queue as it's production server (haven't had chance to look that) but they are definitely not in the failed table.
Normally the messaging runs fine but at one stage it just stops working and the only solution left for us is to restart the wildfly server.But by the time we come to know that messaging is not working, its too late and we are loosing messaging during that time and intern data is not in synch. Can you suggest me the way to debug the issue ? I am not sure if this is an issue of memory leak or some wildlfy configuration or something else, I would really appreciate your advice?

Thanks

[jbertram]

It sounds to me like there's a fundamental flaw in your application design, and it seems likely to me that you're hitting this flaw when you observe a "lost" message.  The flaw is this - the insertion of a "failed entry" into the database (to indicate a message wasn't processed correctly) itself can fail.  Database operations can fail for any number of reasons.  In your scenario, if the "failed entry" insertion fails then you will ostensibly have no record of the data.  The whole process seems doomed to fail eventually.  Your MDB consumes a message and when it has trouble performing a DB operation it logs that fact in the DB.  Doesn't that seem a bit odd to you?

The way such a scenario is normally handled is that the MDB would call setRollbackOnly() on its transaction so that the original message would be placed back on the queue (possibly with a redelivery delay depending on the JMS broker's configuration) or sent to a DLQ or special processing at a later time.

[tyagiarya]

The setRollbackOnly() is called in the catch block if something goes wrong like Db operation or any other exception and I think the reason of failed table is to store the message to retry after correcting the error of the message content (e.g content can be any INSERT statement expecting other data before this insertion or something else or some data is not updated because it was not there).

But I am still to understand why Wildfly stops processing the messages, Is there any way to figure that out from the exceptions?

[jbertram]

The setRollbackOnly() is called in the catch block if something goes wrong like Db operation or any other exception and I think the reason of failed table is to store the message to retry after correcting the error of the message content (e.g content can be any INSERT statement expecting other data before this insertion or something else or some data is not updated because it was not there).

If that's the case then the message should be placed back on the original queue for redelivery or it should be sent to a DLQ if one is configured.  If no DLQ is configured then the message will be deleted.  In other words, you should only ever "lose" a message in this scenario if your broker isn't configured correctly.

But I am still to understand why Wildfly stops processing the messages, Is there any way to figure that out from the exceptions?

If message processing stopped altogether then it's likely all your MDB instances were busy.  You'd need to get a thread dump to investigate that possibility.

Other possibilities:

1. There are no more messages on the queue to consume.
2. The OOME could have been essentially fatal to the application or the application server itself.

[tyagiarya]

Thanks Justin for your advice, I really appreciate that.

Since I have limited access of production box, I am working on your suggestions to get thread dump, queue count or if any new OOME when the issue occur again. I will soon be back with more information

Thanks,

[tyagiarya]

Hi Justin,

Since we have the issue still continuing and we are not getting any clue to resolve it, I would need your advice. Recently I have observed the memory usage goes from 8.5% to 12% but that may be because of load or may be because of memory leak. I have taken the heap dump, below is the link.

https://drive.google.com/file/d/0B9R4IRyTiSLQeEUtVUctdjdGTGM/view?usp=sharing

Also I realized one of the queue gets full (we have defined a count of 1200) and we stops sending messages to this queue due to count. The ejb instance for that queue stops picking up the messages and the count never gets reduced.

Few more details of the process are below:

root     13018 24272  0 09:18 pts/1    00:00:00 grep wildfly

root     30015     1  0 Oct01 ?        00:00:00 /bin/sh /etc/init.d/wildfly start

root     30017 30015  0 Oct01 ?        00:00:00 runuser -s /bin/bash wildfly -c ulimit -S -c 0 >/dev/null 2>&1 ; LAUNCH_JBOSS_IN_BACKGROUND=1 JBOSS_PIDFILE=/var/run/wildfly/wildfly.pid /usr/local/wildfly-8.0.0/bin/standalone.sh -c standalone_office.xml

wildfly  30019 30017  0 Oct01 ?        00:00:00 bash -c ulimit -S -c 0 >/dev/null 2>&1 ; LAUNCH_JBOSS_IN_BACKGROUND=1 JBOSS_PIDFILE=/var/run/wildfly/wildfly.pid /usr/local/wildfly-8.0.0/bin/standalone.sh -c standalone_office.xml

wildfly  30020 30019  0 Oct01 ?        00:00:00 /bin/sh /usr/local/wildfly-8.0.0/bin/standalone.sh -c standalone_office.xml

wildfly  30089 30020  0 Oct01 ?        01:37:25 /usr/java/jdk1.7.0_45/bin/java -D[Standalone] -server -XX:+UseCompressedOops -Xms64m -Xmx2048m -XX:MaxPermSize=256m -Djava.net.preferIPv4Stack=true -Djboss.modules.system.pkgs=org.jboss.byteman -Djava.awt.headless=true -Dorg.jboss.boot.log.file=/usr/local/wildfly-8.0.0/standalone/log/server.log -Dlogging.configuration=file:/usr/local/wildfly-8.0.0/standalone/configuration/logging.properties -jar /usr/local/wildfly-8.0.0/jboss-modules.jar -mp /usr/local/wildfly-8.0.0/modules org.jboss.as.standalone -Djboss.home.dir=/usr/local/wildfly-8.0.0 -Djboss.server.base.dir=/usr/local/wildfly-8.0.0/standalone -c standalone_office.xml

I would really appreciate if you can look into the dump and give more insight?

Thanks,

[jbertram]

The ejb instance for that queue stops picking up the messages and the count never gets reduced.

You'd need to get a couple of thread dumps to investigate this issue, I think.  My guess is the message build-up is causing your OOME and the stalled consumer is triggering the message build-up so you need to investigate why the consumer is stalling.

I don't think a heap dump is going to be terribly helpful right now.  In any event, I'm not going to download and analyze a ~500 meg heap dump.  That's up to you.

[tyagiarya]

Thanks, okay but can you look at the configuration file if there is something which is configured wrong. As we are not encountering OOME these days, may be because we are re-starting server on regular basis but the issue of message loss is still there. Attaching...

[jbertram]

If your server starts and runs then your configuration is "correct" from a syntax perspective.  You need to be more specific about what might be wrong with your configuration.  Correct semantic configuration is highly dependent on your use-case.  I can't just look at your configuration and tell you everything is configured optimally or not.

[tyagiarya]

Hi,

It looks the issue we have relates to the Issue/FIX below and we face this when we have internet/connectivity issue, Since we are using wildfly 8.0.0.CR1 with HornetQ version 2.4.0.Final (without this memory leak FIX), we will be upgrading to the latest release of Wildfly by the end of the year.

Justin-

Thank you for your help !!

https://issues.jboss.org/browse/HORNETQ-1313

https://developer.jboss.org/thread/236398

Server log for Ref. to other's if anybody faces the same issue :

2014-11-20 15:19:30,044 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=2b49a30a-7078-11e4-b093-fd12c7ece3e1] [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,044 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=f89b3d9d-7077-11e4-b093-fd12c7ece3e1] [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,044 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=e337797d-7077-11e4-b093-fd12c7ece3e1] [code=CONNECTION_TIMEDOUT]
2014-11-20 15:18:00,485 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded
at java.util.concurrent.CopyOnWriteArrayList.iterator(CopyOnWriteArrayList.java:959)
at org.hornetq.core.protocol.core.impl.ChannelImpl.invokeInterceptors(ChannelImpl.java:414)
at org.hornetq.core.protocol.core.impl.ChannelImpl.send(ChannelImpl.java:212)
at org.hornetq.core.protocol.core.impl.ChannelImpl.send(ChannelImpl.java:196)
at org.hornetq.core.protocol.core.impl.CoreProtocolManager$LocalChannelHandler.handlePacket(CoreProtocolManager.java:210)
at org.hornetq.core.protocol.core.impl.ChannelImpl.handlePacket(ChannelImpl.java:633)
at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.doBufferReceived(RemotingConnectionImpl.java:547)
at org.hornetq.core.protocol.core.impl.RemotingConnectionImpl.bufferReceived(RemotingConnectionImpl.java:523)
at org.hornetq.core.remoting.server.impl.RemotingServiceImpl$DelegatingBufferHandler.bufferReceived(RemotingServiceImpl.java:635)
at org.hornetq.core.remoting.impl.invm.InVMConnection$1.run(InVMConnection.java:160)
at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor$1.run(OrderedExecutorFactory.java:107)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)

2014-11-20 15:19:30,044 ERROR (AbstractLoggingWriter.java:write:71) Exception in thread "hornetq-expiry-reaper-thread" Exception in thread "Periodic Recovery" Exception in thread "Thread-2882 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=6a06f74d-bdf7-11e3-b8d1-0de0281bae06-826707600-255437110)" Exception in thread "Thread-113" Exception in thread "Thread-0 (hornetq-netty-threads-1067386540)" Exception in thread "Thread-2967 (HornetQ-remoting-threads-HornetQServerImpl::serverUUID=6a06f74d-bdf7-11e3-b8d1-0de0281bae06-826707600-255437110)" java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,044 ERROR (AbstractLoggingWriter.java:write:71)  at java.util.concurrent.LinkedBlockingQueue.offer(LinkedBlockingQueue.java:415)

2014-11-20 15:17:27,553 WARNING (NioEventLoop.java:run:362) Unexpected exception in the selector loop.: java.lang.OutOfMemoryError: GC overhead limit exceeded
at java.util.ArrayList.iterator(ArrayList.java:814)
at sun.nio.ch.WindowsSelectorImpl.updateSelectedKeys(WindowsSelectorImpl.java:496)
at sun.nio.ch.WindowsSelectorImpl.doSelect(WindowsSelectorImpl.java:172)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
at io.netty.channel.nio.NioEventLoop.select(NioEventLoop.java:596)
at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:306)
at io.netty.util.concurrent.SingleThreadEventExecutor$2.run(SingleThreadEventExecutor.java:101)
at java.lang.Thread.run(Thread.java:744)

2014-11-20 15:19:30,044 ERROR (AbstractLoggingWriter.java:write:71)  at java.util.concurrent.ThreadPoolExecutor.execute(ThreadPoolExecutor.java:1364)

2014-11-20 15:19:30,044 ERROR (AbstractLoggingWriter.java:write:71)  at org.hornetq.utils.OrderedExecutorFactory$OrderedExecutor.execute(OrderedExecutorFactory.java:136)

2014-11-20 15:18:07,193 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:18:47,924 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:17:45,571 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,044 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=f898f387-7077-11e4-b093-fd12c7ece3e1] [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,075 ERROR (ServletInitialHandler.java:handleFirstRequest:249) UT005023: Exception handling request to /POSWeb/customerSearch.do: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,044 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=f89b3d8f-7077-11e4-b093-fd12c7ece3e1] [code=CONNECTION_TIMEDOUT]
2014-11-20 15:18:43,759 ERROR (OrderedExecutorFactory.java:run:116) HQ214017: Caught unexpected Throwable: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,075 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=f898f38d-7077-11e4-b093-fd12c7ece3e1] [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:21,823 ERROR (ChannelListeners.java:invokeChannelListener:94) XNIO001007: A channel event listener threw an exception: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:18:35,428 WARNING (NioEventLoop.java:run:362) Unexpected exception in the selector loop.: java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,044 WARN  (HornetQXAResourceWrapper.java:connectionFailed:266) HQ122014: Notified of connection failure in xa recovery connectionFactory for provider ClientSessionFactoryImpl [serverLocator=ServerLocatorImpl [initialConnectors=[TransportConfiguration(name=e358960e-7077-11e4-b093-fd12c7ece3e1, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0], discoveryGroupConfiguration=null], connectorConfig=TransportConfiguration(name=e358960e-7077-11e4-b093-fd12c7ece3e1, factory=org-hornetq-core-remoting-impl-invm-InVMConnectorFactory) ?server-id=0, backupConfig=null] will attempt reconnect on next pass: HornetQConnectionTimedOutException[errorType=CONNECTION_TIMEDOUT message=HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=2b49a30a-7078-11e4-b093-fd12c7ece3e1]]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl$PingRunnable.run(ClientSessionFactoryImpl.java:1733)
at org.hornetq.core.client.impl.ClientSessionFactoryImpl$ActualScheduledPinger.run(ClientSessionFactoryImpl.java:1701)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)

2014-11-20 15:19:30,044 ERROR (AbstractLoggingWriter.java:write:71)  at org.hornetq.core.server.impl.QueueImpl.expireReferences(QueueImpl.java:1470)

2014-11-20 15:19:30,044 WARN  (RecoveryDiscovery.java:connectionFailed:186) Notified of connection failure in xa discovery, we will retry on the next recovery: HornetQConnectionTimedOutException[errorType=CONNECTION_TIMEDOUT message=HQ119011: Did not receive data from server for InVMConnection [serverID=0, id=e337797d-7077-11e4-b093-fd12c7ece3e1]]
at org.hornetq.core.client.impl.ClientSessionFactoryImpl$PingRunnable.run(ClientSessionFactoryImpl.java:1733)
at org.hornetq.core.client.impl.ClientSessionFactoryImpl$ActualScheduledPinger.run(ClientSessionFactoryImpl.java:1701)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:744)

2014-11-20 15:19:30,075 WARN  (HornetQPacketHandler.java:handleReattachSession:235) HQ222066: Reattach request from invm:0 failed as there is no confirmationWindowSize configured, which may be ok for your system
2014-11-20 15:19:30,075 ERROR (AbstractLoggingWriter.java:write:71)  at org.hornetq.core.postoffice.impl.PostOfficeImpl$Reaper.run(PostOfficeImpl.java:1361)

2014-11-20 15:19:30,075 WARN  (HornetQPacketHandler.java:handleReattachSession:235) HQ222066: Reattach request from invm:0 failed as there is no confirmationWindowSize configured, which may be ok for your system
2014-11-20 15:19:30,075 WARN  (HornetQPacketHandler.java:handleReattachSession:235) HQ222066: Reattach request from invm:0 failed as there is no confirmationWindowSize configured, which may be ok for your system
2014-11-20 15:19:30,075 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,075 WARN  (HornetQPacketHandler.java:handleReattachSession:235) HQ222066: Reattach request from invm:0 failed as there is no confirmationWindowSize configured, which may be ok for your system
2014-11-20 15:19:30,075 ERROR (AbstractLoggingWriter.java:write:71)  at java.lang.Thread.run(Thread.java:744)

2014-11-20 15:19:30,075 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f898f382-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,075 ERROR (AbstractLoggingWriter.java:write:71) Exception in thread "Thread-2661 (HornetQ-client-global-threads-1148776313)" java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,075 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f898f382-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,075 ERROR (AbstractLoggingWriter.java:write:71) java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,075 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,091 ERROR (AbstractLoggingWriter.java:write:71) java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,091 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f89b3da4-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,091 ERROR (AbstractLoggingWriter.java:write:71) java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,091 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f89b3da4-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,091 ERROR (AbstractLoggingWriter.java:write:71) java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,091 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,091 ERROR (AbstractLoggingWriter.java:write:71) java.lang.OutOfMemoryError: GC overhead limit exceeded

2014-11-20 15:19:30,091 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f898f385-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,091 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f898f385-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,091 INFO  (RemotingServiceImpl.java:removeConnection:477) HQ221021: failed to remove connection
2014-11-20 15:19:30,091 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,091 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f89b3d93-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,091 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f89b3d93-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,091 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f89b3d99-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f89b3d99-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f8968278-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f8968278-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f89b3d81-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f89b3d81-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f8968276-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f8968276-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,106 WARN  (RemotingConnectionImpl.java:fail:338) HQ212037: Connection failure has been detected: HQ119014: Did not receive data from invm:0. It is likely the client has exited or crashed without closing its connection, or the network between the server and client has failed. You also might have configured connection-ttl and client-failure-check-period incorrectly. Please check user manual for more information. The connection will now be closed. [code=CONNECTION_TIMEDOUT]
2014-11-20 15:19:30,106 WARN  (ServerSessionImpl.java:connectionFailed:1552) HQ222061: Client connection failed, clearing up resources for session f877b0d2-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,122 WARN  (ServerSessionImpl.java:connectionFailed:1556) HQ222107: Cleared up resources for session f877b0d2-7077-11e4-b093-fd12c7ece3e1
2014-11-20 15:19:30,122 INFO  (RemotingServiceImpl.java:removeConnection:477) HQ221021: failed to remove connection

[jbertram]

Couple of things...

• The leak described on HORNETQ-1313 should only be a factor for you if your MDB is getting disconnected and reconnecting often as that is when the leak actually happens.  If you aren't seeing your MDB get disconnected and reconnect then I would say HORNETQ-1313 is almost certainly not impacting you.
• The "java.lang.OutOfMemoryError: GC overhead limit exceeded" is very likely causing the connection time-out problems that you're seeing since the GC overhead would be preventing the client/server ping/pong mechanism from functioning properly.  You can adjust the connection-ttl on the server to prevent these kinds of time-outs, but that obviously won't solve the underlying problem of why your running out of memory in the first place.

[tyagiarya]

Can we see MDB getting disconnected and reconnecting in the log or how we get to know that?

[jbertram]

Yes, you would see evidence in the log that the MDB had lost its connection and was reconnecting.