I am getting a slightly different error today, but the result to my client is the same -
the MessageListener is removed from the queue, and I get nothing on my ExceptionListener.
This is in my client logs at the point at which it fails:
| 2008-11-06 15:07:09,672 org.jboss.jms.client.container.ClientConsumer - Failed to
deliver message
| org.jboss.jms.exception.MessagingJMSException: Failed to invoke
| at
org.jboss.jms.client.delegate.DelegateSupport.handleThrowable(DelegateSupport.java:271)
| at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:205)
| at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate.org$jboss$jms$client$delegate$ClientSessionDelegate$acknowledgeDelivery$aop(ClientSessionDelegate.java:172)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.invokeNext(ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.java)
| at
org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
| at
org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.invokeNext(ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.java)
| at
org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
| at
org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.invokeNext(ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.java)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate.acknowledgeDelivery(ClientSessionDelegate.java)
| at
org.jboss.jms.client.container.SessionAspect.ackDelivery(SessionAspect.java:844)
| at
org.jboss.jms.client.container.SessionAspect.handlePostDeliver(SessionAspect.java:338)
| at
org.jboss.aop.advice.org.jboss.jms.client.container.SessionAspect19.invoke(SessionAspect19.java)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$postDeliver_1255239194451907669.invokeNext(ClientSessionDelegate$postDeliver_1255239194451907669.java)
| at
org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
| at
org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$postDeliver_1255239194451907669.invokeNext(ClientSessionDelegate$postDeliver_1255239194451907669.java)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate.postDeliver(ClientSessionDelegate.java)
| at
org.jboss.jms.client.container.ClientConsumer.callOnMessage(ClientConsumer.java:183)
| at
org.jboss.jms.client.container.ClientConsumer$ListenerRunner.run(ClientConsumer.java:976)
| at org.jboss.messaging.util.JBMExecutor$TCLExecutor.run(JBMExecutor.java:78)
| at
EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
| at java.lang.Thread.run(Thread.java:619)
| Caused by: java.lang.IllegalStateException: Cannot find object in dispatcher with id
uul2-btw8b7nf-1-18ofs1nf-rplxnw-f20a
| at
org.jboss.jms.wireformat.SessionAcknowledgeDeliveryRequest.serverInvoke(SessionAcknowledgeDeliveryRequest.java:75)
| at
org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
| at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:795)
| at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:573)
| at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
| at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
| at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:163)
| at org.jboss.remoting.Client.invoke(Client.java:1634)
| at org.jboss.remoting.Client.invoke(Client.java:548)
| at org.jboss.remoting.Client.invoke(Client.java:536)
| at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
| ... 23 more
| 2008-11-06 15:07:09,672 org.jboss.jms.client.container.ClientConsumer - Failed to
deliver message
| org.jboss.jms.exception.MessagingJMSException: Failed to invoke
| at
org.jboss.jms.client.delegate.DelegateSupport.handleThrowable(DelegateSupport.java:271)
| at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:205)
| at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:160)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate.org$jboss$jms$client$delegate$ClientSessionDelegate$acknowledgeDelivery$aop(ClientSessionDelegate.java:172)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.invokeNext(ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.java)
| at
org.jboss.jms.client.container.FailoverValveInterceptor.invoke(FailoverValveInterceptor.java:92)
| at
org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.invokeNext(ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.java)
| at
org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
| at
org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.invokeNext(ClientSessionDelegate$acknowledgeDelivery_N5825751487881460811.java)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate.acknowledgeDelivery(ClientSessionDelegate.java)
| at
org.jboss.jms.client.container.SessionAspect.ackDelivery(SessionAspect.java:844)
| at
org.jboss.jms.client.container.SessionAspect.handlePostDeliver(SessionAspect.java:338)
| at
org.jboss.aop.advice.org.jboss.jms.client.container.SessionAspect19.invoke(SessionAspect19.java)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$postDeliver_1255239194451907669.invokeNext(ClientSessionDelegate$postDeliver_1255239194451907669.java)
| at
org.jboss.jms.client.container.ClosedInterceptor.invoke(ClosedInterceptor.java:170)
| at
org.jboss.aop.advice.PerInstanceInterceptor.invoke(PerInstanceInterceptor.java:105)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate$postDeliver_1255239194451907669.invokeNext(ClientSessionDelegate$postDeliver_1255239194451907669.java)
| at
org.jboss.jms.client.delegate.ClientSessionDelegate.postDeliver(ClientSessionDelegate.java)
| at
org.jboss.jms.client.container.ClientConsumer.callOnMessage(ClientConsumer.java:183)
| at
org.jboss.jms.client.container.ClientConsumer$ListenerRunner.run(ClientConsumer.java:976)
| at org.jboss.messaging.util.JBMExecutor$TCLExecutor.run(JBMExecutor.java:78)
| at
EDU.oswego.cs.dl.util.concurrent.QueuedExecutor$RunLoop.run(QueuedExecutor.java:89)
| at java.lang.Thread.run(Thread.java:619)
| Caused by: java.lang.IllegalStateException: Cannot find object in dispatcher with id
uul2-btw8b7nf-1-18ofs1nf-rplxnw-f20a
| at
org.jboss.jms.wireformat.SessionAcknowledgeDeliveryRequest.serverInvoke(SessionAcknowledgeDeliveryRequest.java:75)
| at
org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
| at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:795)
| at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:573)
| at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:387)
| at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:166)
| at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:163)
| at org.jboss.remoting.Client.invoke(Client.java:1634)
| at org.jboss.remoting.Client.invoke(Client.java:548)
| at org.jboss.remoting.Client.invoke(Client.java:536)
| at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
| ... 23 more
|
And this in my server logs:
| 2008-11-06 15:06:05,666 WARN [org.jboss.jms.server.endpoint.ServerSessionEndpoint]
Timed out waiting for last message
| 2008-11-06 15:06:16,088 WARN [org.jboss.jms.server.endpoint.ServerSessionEndpoint]
Timed out waiting for last message
| 2008-11-06 15:06:39,652 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic
recovery - first pass <Thu, 6 Nov 2008 15:06:39>
| 2008-11-06 15:06:39,652 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] StatusModule:
first pass
| 2008-11-06 15:06:39,652 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_3] - TORecoveryModule - first
pass
| 2008-11-06 15:06:39,652 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.firstpass] Local XARecoveryModule - first pass
| 2008-11-06 15:06:49,654 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger] Periodic
recovery - second pass <Thu, 6 Nov 2008 15:06:49>
| 2008-11-06 15:06:49,654 DEBUG [com.arjuna.ats.arjuna.logging.arjLogger]
AtomicActionRecoveryModule: Second pass
| 2008-11-06 15:06:49,654 DEBUG [com.arjuna.ats.txoj.logging.txojLoggerI18N]
[com.arjuna.ats.internal.txoj.recovery.TORecoveryModule_6] - TORecoveryModule - second
pass
| 2008-11-06 15:06:49,654 DEBUG [com.arjuna.ats.jta.logging.loggerI18N]
[com.arjuna.ats.internal.jta.recovery.info.secondpass] Local XARecoveryModule - second
pass
| 2008-11-06 15:06:52,808 DEBUG [org.jboss.remoting.ConnectionNotifier] Server
connection lost to client (session id = a02f-zcx09c-fn7b8v1n-1-fn7b8wl6-d
| 2008-11-06 15:06:52,892 DEBUG [org.jboss.remoting.InvokerRegistry] removed
SocketClientInvoker[982d2e, bisocket://10.0.2.15:1281345487] from registry
| 2008-11-06 15:06:52,897 DEBUG
[org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[982d2e,
bisocket://10.0.2.15:1281345487] disconnecting ...
| 2008-11-06 15:06:52,906 DEBUG
[org.jboss.remoting.callback.ServerInvokerCallbackHandler]
ServerInvokerCallbackHandler[a02f-zcx09c-fn7b8v1n-1-fn7b8wl6-d+a02f-zcx09c-fn7b8v1n-1-fn7b8wls-g]
shut down
| 2008-11-06 15:06:52,919 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] A problem has been
detected with the connection to remote client a02f-zcx09c-fn7b8v1n-1-fn7b8wl6-d,
jmsClientID=b-cfw8b7nf-1-n1v8b7nf-c90xcz-f20a. It is possible the client has exited
without closing its connection(s) or the network has failed. All connection resources
corresponding to that client process will now be removed.
| 2008-11-06 15:06:52,919 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] clearing up state for
connection ConnectionEndpoint[tul2-9tw8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:06:52,922 DEBUG [org.jboss.remoting.InvokerRegistry] removed
SocketClientInvoker[e430db, bisocket://10.0.2.15:1281495413] from registry
| 2008-11-06 15:06:52,922 DEBUG
[org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e430db,
bisocket://10.0.2.15:1281495413] disconnecting ...
| 2008-11-06 15:07:08,155 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection
ConnectionEndpoint[tul2-9tw8b7nf-1-18ofs1nf-rplxnw-f20a] with remoting session ID
...-fn7b8wpd-n
| 2008-11-06 15:07:08,155 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] cleared up state for
connection ConnectionEndpoint[tul2-9tw8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,155 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] clearing up state for
connection ConnectionEndpoint[hul2-dfw8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,157 DEBUG [org.jboss.remoting.InvokerRegistry] removed
SocketClientInvoker[97c808, bisocket://10.0.2.15:1279737688] from registry
| 2008-11-06 15:07:08,157 DEBUG
[org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[97c808,
bisocket://10.0.2.15:1279737688] disconnecting ...
| 2008-11-06 15:07:08,182 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection
ConnectionEndpoint[hul2-dfw8b7nf-1-18ofs1nf-rplxnw-f20a] with remoting session ID
...-fn7b8vv2-4
| 2008-11-06 15:07:08,182 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] cleared up state for
connection ConnectionEndpoint[hul2-dfw8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,182 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] clearing up state for
connection ConnectionEndpoint[pul2-cpw8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,251 DEBUG [org.jboss.remoting.InvokerRegistry] removed
SocketClientInvoker[e3b938, bisocket://10.0.2.15:1281439670] from registry
| 2008-11-06 15:07:08,251 DEBUG
[org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[e3b938,
bisocket://10.0.2.15:1281439670] disconnecting ...
| 2008-11-06 15:07:08,252 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection
ConnectionEndpoint[pul2-cpw8b7nf-1-18ofs1nf-rplxnw-f20a] with remoting session ID
...-fn7b8woe-i
| 2008-11-06 15:07:08,252 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] cleared up state for
connection ConnectionEndpoint[pul2-cpw8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,252 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] clearing up state for
connection ConnectionEndpoint[lul2-aow8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,285 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] unregistered connection
ConnectionEndpoint[lul2-aow8b7nf-1-18ofs1nf-rplxnw-f20a] with remoting session ID
...-fn7b8wl6-d
| 2008-11-06 15:07:08,285 DEBUG
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] cleared up state for
connection ConnectionEndpoint[lul2-aow8b7nf-1-18ofs1nf-rplxnw-f20a]
| 2008-11-06 15:07:08,290 DEBUG [org.jboss.remoting.ConnectionNotifier] Server
connection lost to client (session id = a02f-zcx09c-fn7b8v1n-1-fn7b8woe-i
| 2008-11-06 15:07:08,304 DEBUG
[org.jboss.remoting.callback.ServerInvokerCallbackHandler]
ServerInvokerCallbackHandler[a02f-zcx09c-fn7b8v1n-1-fn7b8woe-i+a02f-zcx09c-fn7b8v1n-1-fn7b8wp1-l]
shut down
| 2008-11-06 15:07:08,304 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager]
ConnectionManager[11da858] cannot look up remoting session ID
a02f-zcx09c-fn7b8v1n-1-fn7b8woe-i
| 2008-11-06 15:07:08,304 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] A problem has been
detected with the connection to remote client a02f-zcx09c-fn7b8v1n-1-fn7b8woe-i,
jmsClientID=null. It is possible the client has exited without closing its connection(s)
or the network has failed. All connection resources corresponding to that client process
will now be removed.
| 2008-11-06 15:07:08,306 DEBUG [org.jboss.remoting.ConnectionNotifier] Server
connection lost to client (session id = a02f-zcx09c-fn7b8v1n-1-fn7b8vv2-4
| 2008-11-06 15:07:08,308 DEBUG
[org.jboss.remoting.callback.ServerInvokerCallbackHandler]
ServerInvokerCallbackHandler[a02f-zcx09c-fn7b8v1n-1-fn7b8vv2-4+a02f-zcx09c-fn7b8v1n-1-fn7b8w9g-9]
shut down
| 2008-11-06 15:07:08,313 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager]
ConnectionManager[11da858] cannot look up remoting session ID
a02f-zcx09c-fn7b8v1n-1-fn7b8vv2-4
| 2008-11-06 15:07:08,313 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] A problem has been
detected with the connection to remote client a02f-zcx09c-fn7b8v1n-1-fn7b8vv2-4,
jmsClientID=null. It is possible the client has exited without closing its connection(s)
or the network has failed. All connection resources corresponding to that client process
will now be removed.
| 2008-11-06 15:07:08,313 DEBUG [org.jboss.remoting.ConnectionNotifier] Server
connection lost to client (session id = a02f-zcx09c-fn7b8v1n-1-fn7b8wpd-n
| 2008-11-06 15:07:08,320 DEBUG
[org.jboss.remoting.callback.ServerInvokerCallbackHandler]
ServerInvokerCallbackHandler[a02f-zcx09c-fn7b8v1n-1-fn7b8wpd-n+a02f-zcx09c-fn7b8v1n-1-fn7b8ws9-q]
shut down
| 2008-11-06 15:07:08,320 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager]
ConnectionManager[11da858] cannot look up remoting session ID
a02f-zcx09c-fn7b8v1n-1-fn7b8wpd-n
| 2008-11-06 15:07:08,320 WARN
[org.jboss.jms.server.connectionmanager.SimpleConnectionManager] A problem has been
detected with the connection to remote client a02f-zcx09c-fn7b8v1n-1-fn7b8wpd-n,
jmsClientID=null. It is possible the client has exited without closing its connection(s)
or the network has failed. All connection resources corresponding to that client process
will now be removed.
|
My last successful onMessage logs this:
2008-11-06 15:07:08,132 [@8f8acd0].onMessage() +
JBossConnection->ConnectionDelegate[1046322576,
ID=tul2-9tw8b7nf-1-18ofs1nf-rplxnw-f20a, SID=0]
|
I notice that the server log reports that it is "clearing up state for connection
ConnectionEndpoint[[tul2-9tw8b7nf-1-18ofs1nf-rplxnw-f20a]", which seems to match the
identifier on my logged onMessage connection, but it does not report a problem with that
connection.
To give a little more background info, the remote client is pushing a relatively large
number of messages (around 20,000) across a VPN to this server ; the listener is on the
same machine as the server but running in a separate Java process under Jetty. the
messages are text messages, sometimes up to 1Mb, but not always.
Let me know if I can provide more info. I'm going to struggle to produce a test case,
but if you can give me some hints as to where I should be looking for the cause of this I
would be grateful. As I say, I'm as sure as I can be that I'm closing all my
sessions and connections (apart from the listener one) as soon as I've finished with
them, I'm not using my sessions or connections across threads, I'm at a loss as to
where to go from here.
Thanks in advance for any pointers,
Regards,
Bob
View the original post :
http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4187645#...
Reply to the post :
http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&a...