java.nio.channels.ClosedByInterruptException when sending messages to JMS
java.nio.channels.ClosedByInterruptException when sending messages to JMS
October 9, 2011 - 20:43
Hello,
In one of our projects we use JMS to break up processing of received messages. Messages are posted to a servlet. The servlet passes the data to an EJB which persists it in the database and posts a message into the JMS queue. Then a message driven bean is triggered which starts some processing. However, sometimes a ClosedByInterruptException is thrown on sending a message to the queue. After this has happened all messages posted to this queue are rejected. The EJB which handles this get the connection factory injected.
The deployment runs on Glassfish 3.0.1 with an embedded JMS host (the default implementation) on Linux CentOS.
Here is the stack trace:
[08/Oct/2011:21:29:43 CEST] ERROR [B4004]: Failed to persist message 127032-127.0.0.1(8c:39:df:52:f7:99)-1-1318102183310:
java.nio.channels.ClosedByInterruptException
[08/Oct/2011:21:29:43 CEST] ERROR sendMessage: Sending message failed. Connection ID: 8436423961112646912:
com.sun.messaging.jmq.jmsserver.util.BrokerException: java.nio.channels.ClosedByInterruptException
at com.sun.messaging.jmq.jmsserver.core.PacketReference.store(PacketReference.java:1224)
at com.sun.messaging.jmq.jmsserver.core.Queue.routeNewMessage(Queue.java:542)
at com.sun.messaging.jmq.jmsserver.data.handlers.DataHandler.routeMessage(DataHandler.java:462)
at com.sun.messaging.jmq.jmsserver.data.protocol.ProtocolImpl.processMessage(ProtocolImpl.java:912)
at com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.sendMessage(IMQDirectService.java:1939)
at com.sun.messaging.jms.ra.DirectSession._sendMessage(DirectSession.java:1837)
at com.sun.messaging.jms.ra.DirectProducer._send(DirectProducer.java:1083)
at com.sun.messaging.jms.ra.DirectProducer.send(DirectProducer.java:451)
at my.company.jms.MessageLogicBean.sendToProcessingQueue(MessageLogicBean.java:1248)
at my.company.jms.MessageLogicBean$1.afterCompletion(MessageLogicBean.java:178)
at com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:508)
at com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:837)
at com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5040)
at com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4805)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2004)
at com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1955)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:198)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:84)
at $Proxy408.receiveMessages(Unknown Source)
at my.company.jms.MessageReceiverBean.receiveMessages(MessageReceiverBean.java:64)
at sun.reflect.GeneratedMethodAccessor627.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1056)
at org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1128)
at com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:5292)
at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:615)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:797)
at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:567)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doAround(SystemInterceptorProxy.java:157)
at com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:139)
at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:858)
at com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:797)
at com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:367)
at com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:5264)
at com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:5252)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:190)
at com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:84)
at $Proxy409.receiveMessages(Unknown Source)
at my.company.jms.MyServlet.doPost(MyServlet.java:157)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:754)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:847)
at org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1523)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:279)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:188)
at org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:641)
at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97)
at com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185)
at org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:325)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226)
at com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:239)
at com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791)
at com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693)
at com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954)
at com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
at com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
at com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
at com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
at com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
at com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
at com.sun.grizzly.ContextTask.run(ContextTask.java:69)
at com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
at com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
at java.lang.Thread.run(Thread.java:662)
Caused by: java.nio.channels.ClosedByInterruptException
at java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:643)
at com.sun.messaging.jmq.io.VRFileRAF.writeByteBuffer(VRFileRAF.java:732)
at com.sun.messaging.jmq.io.VRecordRAF.write(VRecordRAF.java:277)
at com.sun.messaging.jmq.jmsserver.persist.file.MessageInfo.storeStates(MessageInfo.java:751)
at com.sun.messaging.jmq.jmsserver.persist.file.MessageInfo.<init>(MessageInfo.java:213)
at com.sun.messaging.jmq.jmsserver.persist.file.DstMsgStore.storeMessage(DstMsgStore.java:304)
at com.sun.messaging.jmq.jmsserver.persist.file.MsgStore.storeMessage(MsgStore.java:315)
at com.sun.messaging.jmq.jmsserver.persist.file.FileStore.storeMessage(FileStore.java:728)
at com.sun.messaging.jmq.jmsserver.core.PacketReference.store(PacketReference.java:1216)
... 68 moreWhen the instance is restarted everything seems to be okay, but the message returns after some time. This can be a week, but also 3 weeks. The last time this happened the load wasn't much more as usual.
Any ideas?
Regards,
Chris
Re: java.nio.channels.ClosedByInterruptException when sending me
November 7, 2011 - 01:21
Hello,
the pool size was set to min of 5 and max of 5 but the described error above happened again. The server was not shutting down at the time. Are there other known situations in which this error can occur?
Chris
Re: java.nio.channels.ClosedByInterruptException when sending me
November 7, 2011 - 03:28
Hi,
it may come from servlet container if servlet call takes long time (by
default longer than 15mins).
You can disable this timeout by tuning request-timeout-seconds for
specific http-listener you're calling servlet on.
For example for http-listener-1 the command looks like:
asadmin set
configs.config.server-config.network-config.protocols.protocol.http-listener-1.http.request-timeout-seconds=-1
(request-timeout-seconds should work since Glassfish 3.0.1+)
WBR,
Alexey.
Re: java.nio.channels.ClosedByInterruptException when sending me
November 21, 2011 - 07:23
Hi,
It happened again, now I found this in the log file:
[#|2011-11-18T21:29:28.965+0100|WARNING|glassfish3.0.1|com.sun.grizzly.config.GrizzlyServiceListener|_ThreadID=18;_ThreadName=Thread-2;|Interrupting idle Thread: http-thread-pool-22006-(4)|#]Seems like this is interrupting the IO and causing the error. I also found this is an old bug in glassfish 3.0 and should be fixed in 3.1. But before I do this upgrade I would like to reproduce that grizzly interrupts so I can very the working on GF 3.1.
Chris
Re: java.nio.channels.ClosedByInterruptException when sending me
November 21, 2011 - 07:30
Well, it's not really a bug. The problem w/ GF 3.0 was that timeout configuration didn't work properly, but the actual behaviour is expected.
As I mentioned on the prev. email you can change the default request timeout value, or completely disable it by setting -1.
Re: java.nio.channels.ClosedByInterruptException when sending me
November 21, 2011 - 07:35
And what are the drawbacks on setting the request timeout to -1? Can it cause holding resources/threads/memory? Will the thread handling the connection/request be put back into the pool sometime?
Re: java.nio.channels.ClosedByInterruptException when sending me
November 21, 2011 - 07:48
Setting request timeout to -1 means that Glassfish/Grizzly will *never* interrupt the thread, which is processing request, no matter how much time it takes. So potentially such a thread will never get returned to the Glassfish thread pool.
Normally Glassfish/Grizzly has a thread-pool of limited size, which processes incoming requests, so if your application blocks threads for a long time (even if it's supposed to do so) - it may impact other applications. And potentially it may lead to situtation when all the threads get blocked and server stops responding.
Re: java.nio.channels.ClosedByInterruptException when sending me
November 22, 2011 - 00:43
That's what I thought... I will do some testing with it.
For now, thanks for you help.
Chris
Re: java.nio.channels.ClosedByInterruptException when sending me
October 10, 2011 - 19:26
Hello,
The instance is not shutting down when this happens, it is in operation mode. I will try to set the thread pool to a limited size to prevent it.
However, shouldn't Glassfish/OpenMQ catch this exception, handle it so the file goes back to 'normal' state and continue operation after the thread pool is resized? Now every message tried to be put into the JMS is causing an error. Is this a bug or is the process not realiable anymore after this exception and should it be restarted?
Chris
Re: java.nio.channels.ClosedByInterruptException when sending me
February 22, 2012 - 15:02
A MQ issue has been filed for this
java.nio.channels.ClosedByInterruptException
This exception occurred while the broker, in embedded mode, was trying
to store the message to disk. The Java doc says this exception is
"Checked exception received by a thread when another thread interrupts
it while it is blocked in an I/O operation upon a channel. Before this
exception is thrown the channel will have been closed .."
The thread is a GlassFish server thread. If the server is not in
shutting down, another possibility of the thread interrupt could be
coming from the thread pool, e.g. resizing. You can try to adjust this
GlassFish server thread pool setting, e.g. to avoid resizing happening,
to see whether the problem still happens.
Amy
On 10/09/2011 08:43 PM, forums@java.net wrote:
> Hello,
>
> In one of our projects we use JMS to break up processing of received
> messages. Messages are posted to a servlet. The servlet passes the
> data to an
> EJB which persists it in the database and posts a message into the JMS
> queue.
> Then a message driven bean is triggered which starts some processing.
> However, sometimes a ClosedByInterruptException is thrown on sending a
> message to the queue. After this has happened all messages posted to this
> queue are rejected. The EJB which handles this get the connection factory
> injected.
>
> The deployment runs on Glassfish 3.0.1 with an embedded JMS host (the
> default implementation) on Linux CentOS.
>
> Here is the stack trace:
>
> [08/Oct/2011:21:29:43 CEST] ERROR [B4004]: Failed to persist message
> 127032-127.0.0.1(8c:39:df:52:f7:99)-1-1318102183310:
> java.nio.channels.ClosedByInterruptException [08/Oct/2011:21:29:43 CEST]
> ERROR sendMessage: Sending message failed. Connection ID:
> 8436423961112646912:
> com.sun.messaging.jmq.jmsserver.util.BrokerException:
> java.nio.channels.ClosedByInterruptException at
> com.sun.messaging.jmq.jmsserver.core.PacketReference.store(PacketReference.java:1224)
>
> at
> com.sun.messaging.jmq.jmsserver.core.Queue.routeNewMessage(Queue.java:542)
> at
> com.sun.messaging.jmq.jmsserver.data.handlers.DataHandler.routeMessage(DataHandler.java:462)
>
> at
> com.sun.messaging.jmq.jmsserver.data.protocol.ProtocolImpl.processMessage(ProtocolImpl.java:912)
>
> at
> com.sun.messaging.jmq.jmsserver.service.imq.IMQDirectService.sendMessage(IMQDirectService.java:1939)
>
> at
> com.sun.messaging.jms.ra.DirectSession._sendMessage(DirectSession.java:1837)
>
> at
> com.sun.messaging.jms.ra.DirectProducer._send(DirectProducer.java:1083) at
>
> com.sun.messaging.jms.ra.DirectProducer.send(DirectProducer.java:451) at
> my.company.jms.MessageLogicBean.sendToProcessingQueue(MessageLogicBean.java:1248)
>
> at
> my.company.jms.MessageLogicBean$1.afterCompletion(MessageLogicBean.java:178)
>
> at
> com.sun.enterprise.transaction.JavaEETransactionImpl.commit(JavaEETransactionImpl.java:508)
>
> at
> com.sun.enterprise.transaction.JavaEETransactionManagerSimplified.commit(JavaEETransactionManagerSimplified.java:837)
>
> at
> com.sun.ejb.containers.BaseContainer.completeNewTx(BaseContainer.java:5040)
>
> at
> com.sun.ejb.containers.BaseContainer.postInvokeTx(BaseContainer.java:4805)
> at
> com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:2004)
> at
> com.sun.ejb.containers.BaseContainer.postInvoke(BaseContainer.java:1955)
> at
> com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:198)
>
> at
> com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:84)
>
> at $Proxy408.receiveMessages(Unknown Source) at
> my.company.jms.MessageReceiverBean.receiveMessages(MessageReceiverBean.java:64)
>
> at sun.reflect.GeneratedMethodAccessor627.invoke(Unknown Source) at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>
> at java.lang.reflect.Method.invoke(Method.java:597) at
> org.glassfish.ejb.security.application.EJBSecurityManager.runMethod(EJBSecurityManager.java:1056)
>
> at
> org.glassfish.ejb.security.application.EJBSecurityManager.invoke(EJBSecurityManager.java:1128)
>
> at
> com.sun.ejb.containers.BaseContainer.invokeBeanMethod(BaseContainer.java:5292)
>
> at com.sun.ejb.EjbInvocation.invokeBeanMethod(EjbInvocation.java:615) at
> com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:797)
>
> at com.sun.ejb.EjbInvocation.proceed(EjbInvocation.java:567) at
> com.sun.ejb.containers.interceptors.SystemInterceptorProxy.doAround(SystemInterceptorProxy.java:157)
>
> at
> com.sun.ejb.containers.interceptors.SystemInterceptorProxy.aroundInvoke(SystemInterceptorProxy.java:139)
>
> at sun.reflect.GeneratedMethodAccessor257.invoke(Unknown Source) at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>
> at java.lang.reflect.Method.invoke(Method.java:597) at
> com.sun.ejb.containers.interceptors.AroundInvokeInterceptor.intercept(InterceptorManager.java:858)
>
> at
> com.sun.ejb.containers.interceptors.AroundInvokeChainImpl.invokeNext(InterceptorManager.java:797)
>
> at
> com.sun.ejb.containers.interceptors.InterceptorManager.intercept(InterceptorManager.java:367)
>
> at
> com.sun.ejb.containers.BaseContainer.__intercept(BaseContainer.java:5264)
> at
> com.sun.ejb.containers.BaseContainer.intercept(BaseContainer.java:5252) at
>
> com.sun.ejb.containers.EJBLocalObjectInvocationHandler.invoke(EJBLocalObjectInvocationHandler.java:190)
>
> at
> com.sun.ejb.containers.EJBLocalObjectInvocationHandlerDelegate.invoke(EJBLocalObjectInvocationHandlerDelegate.java:84)
>
> at $Proxy409.receiveMessages(Unknown Source) at
> my.company.jms.MyServlet.doPost(MyServlet.java:157) at
> javax.servlet.http.HttpServlet.service(HttpServlet.java:754) at
> javax.servlet.http.HttpServlet.service(HttpServlet.java:847) at
> org.apache.catalina.core.StandardWrapper.service(StandardWrapper.java:1523)
>
> at
> org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:279)
>
> at
> org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:188)
>
> at
> org.apache.catalina.core.StandardPipeline.invoke(StandardPipeline.java:641)
>
> at com.sun.enterprise.web.WebPipeline.invoke(WebPipeline.java:97) at
> com.sun.enterprise.web.PESessionLockingStandardPipeline.invoke(PESessionLockingStandardPipeline.java:85)
>
> at
> org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:185)
>
> at
> org.apache.catalina.connector.CoyoteAdapter.doService(CoyoteAdapter.java:325)
>
> at
> org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:226)
>
> at
> com.sun.enterprise.v3.services.impl.ContainerMapper.service(ContainerMapper.java:239)
>
> at
> com.sun.grizzly.http.ProcessorTask.invokeAdapter(ProcessorTask.java:791)
> at
> com.sun.grizzly.http.ProcessorTask.doProcess(ProcessorTask.java:693) at
> com.sun.grizzly.http.ProcessorTask.process(ProcessorTask.java:954) at
> com.sun.grizzly.http.DefaultProtocolFilter.execute(DefaultProtocolFilter.java:170)
>
> at
> com.sun.grizzly.DefaultProtocolChain.executeProtocolFilter(DefaultProtocolChain.java:135)
>
> at
> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:102)
>
> at
> com.sun.grizzly.DefaultProtocolChain.execute(DefaultProtocolChain.java:88)
> at
> com.sun.grizzly.http.HttpProtocolChain.execute(HttpProtocolChain.java:76)
> at
> com.sun.grizzly.ProtocolChainContextTask.doCall(ProtocolChainContextTask.java:53)
>
> at
> com.sun.grizzly.SelectionKeyContextTask.call(SelectionKeyContextTask.java:57)
>
> at com.sun.grizzly.ContextTask.run(ContextTask.java:69) at
> com.sun.grizzly.util.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:330)
>
> at
> com.sun.grizzly.util.AbstractThreadPool$Worker.run(AbstractThreadPool.java:309)
>
> at java.lang.Thread.run(Thread.java:662) Caused by:
> java.nio.channels.ClosedByInterruptException at
> java.nio.channels.spi.AbstractInterruptibleChannel.end(AbstractInterruptibleChannel.java:184)
>
> at sun.nio.ch.FileChannelImpl.write(FileChannelImpl.java:643) at
> com.sun.messaging.jmq.io.VRFileRAF.writeByteBuffer(VRFileRAF.java:732) at
> com.sun.messaging.jmq.io.VRecordRAF.write(VRecordRAF.java:277) at
> com.sun.messaging.jmq.jmsserver.persist.file.MessageInfo.storeStates(MessageInfo.java:751)
>
> at
> com.sun.messaging.jmq.jmsserver.persist.file.MessageInfo.(MessageInfo.java:213)
>
> at
> com.sun.messaging.jmq.jmsserver.persist.file.DstMsgStore.storeMessage(DstMsgStore.java:304)
>
> at
> com.sun.messaging.jmq.jmsserver.persist.file.MsgStore.storeMessage(MsgStore.java:315)
>
> at
> com.sun.messaging.jmq.jmsserver.persist.file.FileStore.storeMessage(FileStore.java:728)
>
> at
> com.sun.messaging.jmq.jmsserver.core.PacketReference.store(PacketReference.java:1216)
>
> ... 68 more
> When the instance is restarted everything seems to be okay, but the
> message
> returns after some time. This can be a week, but also 3 weeks. The
> last time
> this happened the load wasn't much more as usual.
>
> Any ideas?
>
> Regards,
>
> Chris
>
>
>
>
> --
>
> [Message sent by forum member 'sisirhc']
>
> View Post: http://forums.java.net/node/851634
>
>