[Remoting] - Re: Race condition in ConnectionValidator - jboss-user

Wednesday, 1 April 2009

Ok. This is pretty lengthy (2 Scenarios. One with long pingPeriod and the other one with a
much shorter one). The ping period is set to 70 seconds the same as the ping timeout.
Server comes back in under 70 seconds from the restart.

Scenario where the server is restarted before ping period. No listener is called.

10:27:51,480 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977]
SocketServerInvoker[UNINITIALIZED].invoke() returned null
10:27:51,480 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977] oneway request,
writing no reply on the wire
10:27:51,480 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977] preparing to process
next invocation invocation
10:27:51,480 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977] blocking to read
version from input stream
10:27:57,312 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977] read version -1 from
input stream

I KILL the server here. Our message listener is not in any stack trace

10:27:57,316 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977] EOFException
received. This is likely due to client finishing communication.
java.io.EOFException
        at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:565)
        at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:420)
        at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:173)
10:27:57,317 DEBUG [ServerThread] WorkerThread#0[192.168.1.20:41977]
WorkerThread#0[192.168.1.20:41977] closing socketWrapper: ServerSocketWrapper[Socket[a
ddr=tarek02/192.168.1.20,port=41977,localport=46727].3770bdf7]
10:27:57,317 DEBUG [SocketWrapper] WorkerThread#0[192.168.1.20:41977]
ServerSocketWrapper[Socket[addr=tarek02/192.168.1.20,port=41977,localport=46727].3770
bdf7] closing
10:27:57,317 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977]
WorkerThread#0[192.168.1.20:41977] removing itself from clientpool and going to thread
pool
10:27:57,317 TRACE [ServerThread] WorkerThread#0[192.168.1.20:41977]
WorkerThread#0[192.168.1.20:41977] begins to wait
10:28:34,968 TRACE [MicroRemoteClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457](1) invoking InvocationRequest[4ada629a, JMS,
OnewayInvocation[org.jboss.jms.wireformat.SessionSendRequest@477f92da]]
10:28:34,968 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] obtained semaphore: 0
10:28:34,968 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] creating socket
10:28:34,968 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] created socket:
Socket[addr=/192.168.1.20,port=4457,localport=38873]
10:28:34,968 TRACE [SocketWrapper] Timer-6 constructing
org.jboss.jms.client.remoting.ClientSocketWrapper instance for
Socket[addr=/192.168.1.20,port=4457,localport=38873], using timeout 0
10:28:34,968 TRACE [SocketWrapper] Timer-6
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38873].8824ae2] setting
timeout to 0
10:28:34,968 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] writing version 22 on output stream
10:28:34,968 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] writing invocation to marshaller
10:28:34,968 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] done writing invocation to marshaller
10:28:34,969 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] sent oneway invocation, so not waiting for response, returning
null
10:28:34,969 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] returned
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38873].8824ae2] to pool
10:28:34,969 TRACE [MicroSocketClientInvoker] Timer-6 SocketClientInvoker[113f25e3,
bisocket://tarek02:4457] released semaphore: 1
10:28:43,238 TRACE [LeasePinger] Timer-1 LeasePinger[SocketClientInvoker[76dbab83,
bisocket://tarek02:4457](5c4o1k-u8g2wa-ft043q7b-1-ft043z6u-16)] sending ping to server.
Currently managing lease for following clients:
    5c4o1k-u8g2wa-ft043q7b-1-ft043z6s-14

10:28:43,238 TRACE [MicroRemoteClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457](1) invoking InvocationRequest[ebd3f80, $PING$]
10:28:43,238 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] obtained semaphore: 199
10:28:43,238 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] creating socket
10:28:43,239 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] created socket:
Socket[addr=/192.168.1.20,port=4457,localport=38875]
10:28:43,239 TRACE [SocketWrapper] Timer-1 constructing
org.jboss.jms.client.remoting.ClientSocketWrapper instance for
Socket[addr=/192.168.1.20,port=4457,localport=38875], using timeout 0
10:28:43,239 TRACE [SocketWrapper] Timer-1
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38875].2a93f40f] setting
timeout to 0
10:28:43,239 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] writing version 22 on output stream
10:28:43,239 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] writing invocation to marshaller
10:28:43,240 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] done writing invocation to marshaller
10:28:43,240 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] reading version from input stream
10:28:43,374 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] read version 22 from input stream
10:28:43,375 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] reading response from unmarshaller
10:28:43,375 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] returned
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38875].2a93f40f] to
pool
10:28:43,375 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] released semaphore: 200
10:28:43,375 TRACE [MicroSocketClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] received response InvocationResponse[514e7b87,
InvocationResponse[779005c4, true]]
10:28:43,375 TRACE [MicroRemoteClientInvoker] Timer-1 SocketClientInvoker[76dbab83,
bisocket://tarek02:4457] received InvocationResponse so going to return response's
return value of InvocationResponse[779005c4, true]
10:28:43,375 TRACE [LeasePinger] Timer-1 LeasePinger[SocketClientInvoker[76dbab83,
bisocket://tarek02:4457](5c4o1k-u8g2wa-ft043q7b-1-ft043z6u-16)] successfully pinged the
server
10:28:43,418 TRACE [ConnectionValidator] Timer-3
ConnectionValidator[SocketClientInvoker[51b2bcc2, bisocket://tarek02:4457],
pingPeriod=70000 ms] sending PING tied to lease
10:28:43,418 TRACE [ConnectionValidator] Timer-3 pinging, sending
InvocationRequest[106ac42f, self, $PING$] over SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457]
10:28:43,418 TRACE [MicroRemoteClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457](1) invoking InvocationRequest[106ac42f, self, $PING$]
10:28:43,418 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] obtained semaphore: 49
10:28:43,418 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] creating socket
10:28:43,420 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] created socket:
Socket[addr=/192.168.1.20,port=4457,localport=38876]
10:28:43,420 TRACE [SocketWrapper] Timer-3 constructing
org.jboss.jms.client.remoting.ClientSocketWrapper instance for
Socket[addr=/192.168.1.20,port=4457,localport=38876], using timeout 0
10:28:43,420 TRACE [SocketWrapper] Timer-3
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38876].5175f214] setting
timeout to 0
10:28:43,420 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] writing version 22 on output stream
10:28:43,420 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] writing invocation to marshaller
10:28:43,420 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] done writing invocation to marshaller
10:28:43,421 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] reading version from input stream
10:28:43,425 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] read version 22 from input stream
10:28:43,425 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] reading response from unmarshaller
10:28:43,425 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] returned
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38876].5175f214] to
pool
10:28:43,425 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] released semaphore: 50
10:28:43,425 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] received response InvocationResponse[3a33517f, true]
10:28:43,425 TRACE [MicroRemoteClientInvoker] Timer-3 SocketClientInvoker[51b2bcc2,
bisocket://tarek02:4457] received InvocationResponse so going to return response's
return value of true
10:28:43,425 TRACE [ConnectionValidator] Timer-3 Return from server ping is :true
Happy ping even though ever was restarted. Strange 
10:28:43,425 TRACE [ConnectionValidator] Timer-3 ConnectionValidator got successful ping
using SocketClientInvoker[51b2bcc2, bisocket://tarek02:4457]

==============================

10:29:06,725 TRACE [MicroRemoteClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457](1) invoking
InvocationRequest[3a5f299d, JMS,
org.jboss.jms.wireformat.ConnectionCreateSessionDelegateRequest@3da5205b]
10:29:06,725 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] obtained semaphore: 199
10:29:06,725 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] reusing pooled connection:
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38875].2a93f40f]
10:29:06,725 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] writing version 22 on output
stream
10:29:06,725 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] writing invocation to marshaller
10:29:06,725 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] done writing invocation to
marshaller
10:29:06,725 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] reading version from input stream
10:29:06,729 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] read version 22 from input stream
10:29:06,729 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] reading response from unmarshaller
10:29:06,732 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] returned
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38875].2a93f40f] to
pool
10:29:06,732 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] released semaphore: 200
10:29:06,732 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] received response
InvocationResponse[6d5454d, java.lang.IllegalStateException: Cannot find object in
dispatcher with id k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5]
10:29:06,732 TRACE [MicroRemoteClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] received a server-side exception as
response to the invocation: 

The error after subsequent JMS calls. Never recovers 

java.lang.IllegalStateException: Cannot find object in dispatcher with id
k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5
10:29:06,733 ERROR [JMSLeaseRenewStrategy] SwingWorker-pool-1-thread-1 Failed to invoke
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.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$createSessionDelegate$aop(ClientConnectionDelegate.java:186)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.container.StateCreationAspect.handleCreateSessionDelegate(StateCreationAspect.java:122)
        at
org.jboss.aop.advice.org.jboss.jms.client.container.StateCreationAspect2.invoke(StateCreationAspect2.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.container.ConnectionAspect.handleCreateSessionDelegate(ConnectionAspect.java:164)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.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.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.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.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate.createSessionDelegate(ClientConnectionDelegate.java)
        at
org.jboss.jms.client.JBossConnection.createSessionInternal(JBossConnection.java:269)
        at org.jboss.jms.client.JBossConnection.createSession(JBossConnection.java:91)
        at com.enfusion.lease.JMSLeaseRenewStrategy.(JMSLeaseRenewStrategy.java:26)
        at
com.enfusion.feed.client.transport.jms.JMSFeedSessionTransport.(JMSFeedSessionTransport.java:96)
        at com.enfusion.feed.client.FeedSession.createJMSFeedSession(FeedSession.java:35)
        at com.enfusion.fas.feeds.report.RemoteDocument.(RemoteDocument.java:60)
        at
com.enfusion.mazzika.report.service.ReportComponent$DynamicReportWorker.doInBackground(ReportComponent.java:560)
        at javax.swing.SwingWorker$1.call(SwingWorker.java:278)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at javax.swing.SwingWorker.run(SwingWorker.java:317)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.IllegalStateException: Cannot find object in dispatcher with id
k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5
        at
org.jboss.jms.wireformat.ConnectionCreateSessionDelegateRequest.serverInvoke(ConnectionCreateSessionDelegateRequest.java:84)
        at
org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
        at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:866)
        at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:608)
        at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:420)
        at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:173)
        at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:174)
        at org.jboss.remoting.Client.invoke(Client.java:1645)
        at org.jboss.remoting.Client.invoke(Client.java:559)
        at org.jboss.remoting.Client.invoke(Client.java:547)
        at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
        ... 34 more
10:29:06,735 TRACE [MicroRemoteClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457](1) invoking
InvocationRequest[eebafe, JMS,
org.jboss.jms.wireformat.ConnectionCreateSessionDelegateRequest@39367a2c]
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] obtained semaphore: 199
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] reusing pooled connection:
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38875].2a93f40f]
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] writing version 22 on output
stream
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] writing invocation to marshaller
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] done writing invocation to
marshaller
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] reading version from input stream
10:29:06,735 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] read version 22 from input stream
10:29:06,736 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] reading response from unmarshaller
10:29:06,736 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] returned
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=38875].2a93f40f] to
pool
10:29:06,736 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] released semaphore: 200
10:29:06,736 TRACE [MicroSocketClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] received response
InvocationResponse[19f21412, java.lang.IllegalStateException: Cannot find object in
dispatcher with id k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5]
10:29:06,736 TRACE [MicroRemoteClientInvoker] SwingWorker-pool-1-thread-1
SocketClientInvoker[76dbab83, bisocket://tarek02:4457] received a server-side exception as
response to the invocation: java.lang.IllegalStateException: Cannot find object in
dispatcher with id k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5
10:29:06,736 ERROR [JMSFeedSessionTransport] SwingWorker-pool-1-thread-1 Failed to invoke
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.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$createSessionDelegate$aop(ClientConnectionDelegate.java:186)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.container.StateCreationAspect.handleCreateSessionDelegate(StateCreationAspect.java:122)
        at
org.jboss.aop.advice.org.jboss.jms.client.container.StateCreationAspect2.invoke(StateCreationAspect2.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.container.ConnectionAspect.handleCreateSessionDelegate(ConnectionAspect.java:164)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.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.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.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.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate.createSessionDelegate(ClientConnectionDelegate.java)
        at
org.jboss.jms.client.JBossConnection.createSessionInternal(JBossConnection.java:269)
        at org.jboss.jms.client.JBossConnection.createSession(JBossConnection.java:91)
        at
com.enfusion.feed.client.transport.jms.JMSFeedSessionTransport.(JMSFeedSessionTransport.java:100)
        at com.enfusion.feed.client.FeedSession.createJMSFeedSession(FeedSession.java:35)
        at com.enfusion.fas.feeds.report.RemoteDocument.(RemoteDocument.java:60)
        at
com.enfusion.mazzika.report.service.ReportComponent$DynamicReportWorker.doInBackground(ReportComponent.java:560)
        at javax.swing.SwingWorker$1.call(SwingWorker.java:278)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at javax.swing.SwingWorker.run(SwingWorker.java:317)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
Caused by: java.lang.IllegalStateException: Cannot find object in dispatcher with id
k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5
        at
org.jboss.jms.wireformat.ConnectionCreateSessionDelegateRequest.serverInvoke(ConnectionCreateSessionDelegateRequest.java:84)
        at
org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
        at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:866)
        at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:608)
        at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:420)
        at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:173)
        at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:174)
        at org.jboss.remoting.Client.invoke(Client.java:1645)
        at org.jboss.remoting.Client.invoke(Client.java:559)
        at org.jboss.remoting.Client.invoke(Client.java:547)
        at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
        ... 33 more
10:29:06,782 ERROR [ReportComponent$DynamicReportWorker] AWT-EventQueue-0
org.jboss.jms.exception.MessagingJMSException: Failed to invoke
java.lang.RuntimeException: org.jboss.jms.exception.MessagingJMSException: Failed to
invoke
        at
com.enfusion.feed.client.transport.jms.JMSFeedSessionTransport.(JMSFeedSessionTransport.java:152)
        at com.enfusion.feed.client.FeedSession.createJMSFeedSession(FeedSession.java:35)
        at com.enfusion.fas.feeds.report.RemoteDocument.(RemoteDocument.java:60)
        at
com.enfusion.mazzika.report.service.ReportComponent$DynamicReportWorker.doInBackground(ReportComponent.java:560)
        at javax.swing.SwingWorker$1.call(SwingWorker.java:278)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
        at javax.swing.SwingWorker.run(SwingWorker.java:317)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
        at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
        at java.lang.Thread.run(Thread.java:619)
Caused by: 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.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$createSessionDelegate$aop(ClientConnectionDelegate.java:186)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.container.StateCreationAspect.handleCreateSessionDelegate(StateCreationAspect.java:122)
        at
org.jboss.aop.advice.org.jboss.jms.client.container.StateCreationAspect2.invoke(StateCreationAspect2.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.container.ConnectionAspect.handleCreateSessionDelegate(ConnectionAspect.java:164)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.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.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.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.ClientConnectionDelegate$createSessionDelegate_6052335267724906805.invokeNext(ClientConnectionDelegate$createSessionDelegate_6052335267724906805.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate.createSessionDelegate(ClientConnectionDelegate.java)
        at
org.jboss.jms.client.JBossConnection.createSessionInternal(JBossConnection.java:269)
        at org.jboss.jms.client.JBossConnection.createSession(JBossConnection.java:91)
        at
com.enfusion.feed.client.transport.jms.JMSFeedSessionTransport.(JMSFeedSessionTransport.java:100)
        ... 10 more
Caused by: java.lang.IllegalStateException: Cannot find object in dispatcher with id
k22-baz340tf-1-fbh040tf-5h3vog-k1o4c5
        at
org.jboss.jms.wireformat.ConnectionCreateSessionDelegateRequest.serverInvoke(ConnectionCreateSessionDelegateRequest.java:84)
        at
org.jboss.jms.server.remoting.JMSServerInvocationHandler.invoke(JMSServerInvocationHandler.java:143)
        at org.jboss.remoting.ServerInvoker.invoke(ServerInvoker.java:866)
        at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:608)
        at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:420)
        at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:173)
        at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:174)
        at org.jboss.remoting.Client.invoke(Client.java:1645)
        at org.jboss.remoting.Client.invoke(Client.java:559)
        at org.jboss.remoting.Client.invoke(Client.java:547)
        at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
        ... 33 more

 Much Smaller ping period 10 seconds. The results is what I expect.

10:41:32,976 TRACE [ConnectionValidator] Timer-3
ConnectionValidator[SocketClientInvoker[1197886c, bisocket://tarek02:4457],
pingPeriod=10000 ms] sending PING tied to lease
10:41:32,977 TRACE [ConnectionValidator] Timer-3 pinging, sending
InvocationRequest[712d0ef5, self, $PING$] over SocketClientInvoker[1197886c,
bisocket://tarek02:4457]
10:41:32,977 TRACE [MicroRemoteClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457](1) invoking InvocationRequest[712d0ef5, self, $PING$]
10:41:32,977 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] obtained semaphore: 49
10:41:32,977 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] creating socket
10:41:32,977 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] created socket:
Socket[addr=/192.168.1.20,port=4457,localport=34532]
10:41:32,977 TRACE [SocketWrapper] Timer-3 constructing
org.jboss.jms.client.remoting.ClientSocketWrapper instance for
Socket[addr=/192.168.1.20,port=4457,localport=34532], using timeout 0
10:41:32,977 TRACE [SocketWrapper] Timer-3
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=34532].207fa3f6] setting
timeout to 0
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] writing version 22 on output stream
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] writing invocation to marshaller
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] done writing invocation to marshaller
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] reading version from input stream
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] read version 22 from input stream
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] reading response from unmarshaller
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] returned
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=34532].207fa3f6] to
pool
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] released semaphore: 50
10:41:32,978 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] received response InvocationResponse[8763c3c, true]
10:41:32,979 TRACE [MicroRemoteClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] received InvocationResponse so going to return response's
return value of true
10:41:32,979 TRACE [ConnectionValidator] Timer-3 Return from server ping is :true
10:41:32,979 TRACE [ConnectionValidator] Timer-3 ConnectionValidator got successful ping
using SocketClientInvoker[1197886c, bisocket://tarek02:4457]

10:41:35,107 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] read version 22 from
input stream
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] blocking to read
invocation from unmarshaller
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] read
InvocationRequest[a6c8b7b, CALLBACK, OnewayInvocation[InternalInvocation[5c393d95]]] from
unmarshaller
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] about to call
SocketServerInvoker[UNINITIALIZED].invoke()
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] received
OnewayInvocation[InternalInvocation[5c393d95]]
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607] reusing oneway
thread pool
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] placing InvocationRequest[a6c8b7b, CALLBACK,
InternalInvocation[5c393d95]] in onewayThreadPool
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] received InternalInvocation[5c393d95]
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607] handling
InternalInvocation where method name = handleCallback
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607] ServerInvoker
(SocketServerInvoker[UNINITIALIZED]) is being asked to deliver callback on client callback
handler with session id of null.
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] successfully dispatched invocation, returning null from
subsystem 'CALLBACK' to client null
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED].invoke() returned null
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] oneway request,
writing no reply on the wire
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] preparing to process
next invocation invocation
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] blocking to read
version from input stream
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] read version 22 from
input stream
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] blocking to read
invocation from unmarshaller
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] read
InvocationRequest[31fa3080, CALLBACK, OnewayInvocation[InternalInvocation[20863d22]]] from
unmarshaller
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] about to call
SocketServerInvoker[UNINITIALIZED].invoke()
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] received
OnewayInvocation[InternalInvocation[20863d22]]
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607] reusing oneway
thread pool
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] placing InvocationRequest[31fa3080, CALLBACK,
InternalInvocation[20863d22]] in onewayThreadPool
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] received InternalInvocation[20863d22]
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607] handling
InternalInvocation where method name = handleCallback
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607] ServerInvoker
(SocketServerInvoker[UNINITIALIZED]) is being asked to deliver callback on client callback
handler with session id of null.
10:41:35,108 TRACE [ServerInvoker] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED] successfully dispatched invocation, returning null from
subsystem 'CALLBACK' to client null
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607]
SocketServerInvoker[UNINITIALIZED].invoke() returned null
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] oneway request,
writing no reply on the wire
10:41:35,108 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] preparing to process
next invocation invocation
10:41:35,110 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] blocking to read
version from input stream
10:41:40,471 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] read version -1 from
input stream
10:41:40,474 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607] EOFException
received. This is likely due to client finishing communication.
java.io.EOFException
        at
org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:565)
        at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:420)
        at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:173)
10:41:40,475 DEBUG [ServerThread] WorkerThread#0[192.168.1.20:57607]
WorkerThread#0[192.168.1.20:57607] closing socketWrapper:
ServerSocketWrapper[Socket[addr=tarek02/192.168.1.20,port=57607,localport=44371].161abc23]
10:41:40,475 DEBUG [SocketWrapper] WorkerThread#0[192.168.1.20:57607]
ServerSocketWrapper[Socket[addr=tarek02/192.168.1.20,port=57607,localport=44371].161abc23]
closing
10:41:40,475 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607]
WorkerThread#0[192.168.1.20:57607] removing itself from clientpool and going to
threadpool
10:41:40,476 TRACE [ServerThread] WorkerThread#0[192.168.1.20:57607]
WorkerThread#0[192.168.1.20:57607] begins to wait
10:41:42,976 TRACE [ConnectionValidator] Timer-3
ConnectionValidator[SocketClientInvoker[1197886c, bisocket://tarek02:4457],
pingPeriod=10000 ms] sending PING tied to lease
10:41:42,976 TRACE [ConnectionValidator] Timer-3 pinging, sending
InvocationRequest[6045e90f, self, $PING$] over SocketClientInvoker[1197886c,
bisocket://tarek02:4457]
10:41:42,976 TRACE [MicroRemoteClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457](1) invoking InvocationRequest[6045e90f, self, $PING$]
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] obtained semaphore: 49
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] reusing pooled connection:
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=34532].207fa3f6]
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] writing version 22 on output stream
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] writing invocation to marshaller
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] done writing invocation to marshaller
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] reading version from input stream
10:41:42,976 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] read version -1 from input stream
10:41:42,977 DEBUG [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] got SocketException java.net.SocketException: end of file
10:41:42,977 TRACE [MicroSocketClientInvoker] Timer-3 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] released semaphore: 50
10:41:42,977 DEBUG [SocketWrapper] Timer-3
ClientSocketWrapper[Socket[addr=/192.168.1.20,port=4457,localport=34532].207fa3f6]
closing
10:41:42,977 ERROR [SocketClientInvoker] Timer-3 Got marshalling exception, exiting
java.net.SocketException: end of file
        at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:624)
        at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:422)
        at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:133)
        at
org.jboss.remoting.ConnectionValidator.doCheckConnectionWithLease(ConnectionValidator.java:551)
        at org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:331)
        at java.util.TimerThread.mainLoop(Timer.java:512)
        at java.util.TimerThread.run(Timer.java:462)
10:41:42,979 DEBUG [ConnectionValidator] Timer-3 ConnectionValidator failed to ping via
SocketClientInvoker[1197886c, bisocket://tarek02:4457]
java.rmi.MarshalException: Failed to communicate.  Problem during
marshalling/unmarshalling; nested exception is:
        java.net.SocketException: end of file
        at
org.jboss.remoting.transport.socket.SocketClientInvoker.handleException(SocketClientInvoker.java:127)
        at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:699)
        at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:422)
        at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:133)
        at
org.jboss.remoting.ConnectionValidator.doCheckConnectionWithLease(ConnectionValidator.java:551)
        at org.jboss.remoting.ConnectionValidator.run(ConnectionValidator.java:331)
        at java.util.TimerThread.mainLoop(Timer.java:512)
        at java.util.TimerThread.run(Timer.java:462)
Caused by: java.net.SocketException: end of file
        at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:624)
        ... 6 more
10:41:42,979 DEBUG [ConnectionValidator] Timer-4
ConnectionValidator[SocketClientInvoker[1197886c, bisocket://tarek02:4457],
pingPeriod=10000 ms]'s connections is invalid
10:41:42,980 ERROR [JBOSSMessagingDelegate] Thread-15 Failure on underlying remoting
connection
javax.jms.JMSException: Failure on underlying remoting connection
        at
org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:102)
        at org.jboss.remoting.ConnectionValidator$1.run(ConnectionValidator.java:649)
10:41:42,981 TRACE [InvokerRegistry] Timer-4 destroying client invoker InvokerLocator
[bisocket://tarek02:4457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=70000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=false&stopLeaseOnFailure=true&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat&validatorPingPeriod=10000&validatorPingTimeout=70000],
config {validatorPingPeriod=10000, numberOfRetries=10, socket.check_connection=false,
stopLeaseOnFailure=true, marshaller=org.jboss.jms.wireformat.JMSWireFormat,
unmarshaller=org.jboss.jms.wireformat.JMSWireFormat, clientLeasePeriod=70000,
clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper,
numberOfCallRetries=1, dataType=jms, pingWindowFactor=10, connection_checker=true,
NumberOfCallRetries=1, JBM_clientMaxPoolSize=200, pingFrequency=214748364, timeout=70000,
validatorPingTimeout=70000}
10:41:42,982 DEBUG [InvokerRegistry] Timer-4 removed SocketClientInvoker[1197886c,
bisocket://tarek02:4457] from registry
10:41:42,982 TRACE [InvokerRegistry] Timer-4 disconnecting SocketClientInvoker[1197886c,
bisocket://tarek02:4457]
10:41:42,982 DEBUG [MicroSocketClientInvoker] Timer-4 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] disconnecting ...
10:41:42,982 TRACE [MicroRemoteClientInvoker] Timer-4 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] disconnecting ...
10:41:42,982 TRACE [MicroRemoteClientInvoker] Timer-4 SocketClientInvoker[1197886c,
bisocket://tarek02:4457] disconnected
10:41:42,982 DEBUG [ConnectionValidator] Timer-4
ConnectionValidator[SocketClientInvoker[1197886c, bisocket://tarek02:4457],
pingPeriod=10000 ms] stopped, returning true
10:41:42,982 DEBUG [ConnectionValidator] Timer-4
org.jboss.remoting.ConnectionValidator$WaitOnConnectionCheckTimerTask@37190ae9 detected
connection failure: stopping LeasePinger
10:41:42,982 DEBUG [LeasePinger] Timer-4 LeasePinger[SocketClientInvoker[38c5564e,
bisocket://tarek02:4457](5c4o1k-zhbdmy-ft04lhns-1-ft04lr9o-16)] setting disconnect timeout
to: -1
10:41:42,983 TRACE [LeasePinger] Timer-4 LeasePinger[SocketClientInvoker[38c5564e,
bisocket://tarek02:4457](5c4o1k-zhbdmy-ft04lhns-1-ft04lr9o-16)] stopping lease timer
10:41:42,983 TRACE [MicroRemoteClientInvoker] Timer-4 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457](1) invoking InvocationRequest[411167f3, $DISCONNECT$]
10:41:42,983 TRACE [MicroSocketClientInvoker] Timer-4 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457] obtained semaphore: 199
10:41:42,983 TRACE [MicroSocketClientInvoker] Timer-4 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457] creating socket
10:41:42,986 TRACE [MicroSocketClientInvoker] Timer-4 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457] released semaphore: 200
10:41:42,986 DEBUG [MicroRemoteClientInvoker] Timer-4 error shutting down lease pinger
10:41:42,986 DEBUG [ConnectionValidator] Timer-4
ConnectionValidator[SocketClientInvoker[1197886c, bisocket://tarek02:4457],
pingPeriod=10000 ms] shut down lease pinger
10:41:42,986 TRACE [MicroRemoteClientInvoker] Thread-15 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457](1) invoking InvocationRequest[1140d57b, JMS,
org.jboss.jms.wireformat.ConnectionStopRequest@377f8716]
10:41:42,987 TRACE [MicroSocketClientInvoker] Thread-15 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457] obtained semaphore: 199
10:41:42,987 TRACE [MicroSocketClientInvoker] Thread-15 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457] creating socket
10:41:42,987 TRACE [MicroSocketClientInvoker] Thread-15 SocketClientInvoker[38c5564e,
bisocket://tarek02:4457] released semaphore: 200
10:41:42,987 ERROR [JBOSSMessagingDelegate] Thread-15
org.jboss.jms.exception.MessagingNetworkFailureException
        at
org.jboss.jms.client.delegate.DelegateSupport.handleThrowable(DelegateSupport.java:240)
        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.ClientConnectionDelegate.org$jboss$jms$client$delegate$ClientConnectionDelegate$stop$aop(ClientConnectionDelegate.java:258)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$stop_N2856118408655404442.invokeNext(ClientConnectionDelegate$stop_N2856118408655404442.java)
        at
org.jboss.jms.client.container.ConnectionAspect.handleStop(ConnectionAspect.java:157)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
        at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
        at java.lang.reflect.Method.invoke(Method.java:597)
        at org.jboss.aop.advice.PerInstanceAdvice.invoke(PerInstanceAdvice.java:121)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate$stop_N2856118408655404442.invokeNext(ClientConnectionDelegate$stop_N2856118408655404442.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.ClientConnectionDelegate$stop_N2856118408655404442.invokeNext(ClientConnectionDelegate$stop_N2856118408655404442.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.ClientConnectionDelegate$stop_N2856118408655404442.invokeNext(ClientConnectionDelegate$stop_N2856118408655404442.java)
        at
org.jboss.jms.client.delegate.ClientConnectionDelegate.stop(ClientConnectionDelegate.java)
        at org.jboss.jms.client.JBossConnection.stop(JBossConnection.java:126)
 Our listener being called
        at
com.enfusion.feed.client.transport.jms.JBOSSMessagingDelegate.close(JBOSSMessagingDelegate.java:56)
        at
com.enfusion.feed.client.transport.jms.JBOSSMessagingDelegate$ExceptionListenerImpl.onException(JBOSSMessagingDelegate.java:117)
        at
org.jboss.jms.client.remoting.ConsolidatedRemotingConnectionListener.handleConnectionException(ConsolidatedRemotingConnectionListener.java:113)
        at org.jboss.remoting.ConnectionValidator$1.run(ConnectionValidator.java:649)
Caused by: org.jboss.remoting.CannotConnectException: Can not get connection to server.
Problem establishing socket connection for InvokerLocator
[bisocket://tarek02:4457/?JBM_clientMaxPoolSize=200&clientLeasePeriod=70000&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&dataType=jms&marshaller=org.jboss.jms.wireformat.JMSWireFormat&numberOfCallRetries=1&numberOfRetries=10&pingFrequency=214748364&pingWindowFactor=10&socket.check_connection=fal
se&stopLeaseOnFailure=true&timeout=0&unmarshaller=org.jboss.jms.wireformat.JMSWireFormat&validatorPingPeriod=10000&validatorPingTimeout=70000]
        at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:579)
        at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.transport(BisocketClientInvoker.java:422)
        at
org.jboss.remoting.MicroRemoteClientInvoker.invoke(MicroRemoteClientInvoker.java:133)
        at org.jboss.remoting.Client.invoke(Client.java:1645)
        at org.jboss.remoting.Client.invoke(Client.java:559)
        at org.jboss.remoting.Client.invoke(Client.java:547)
        at
org.jboss.jms.client.delegate.DelegateSupport.doInvoke(DelegateSupport.java:189)
        ... 22 more
Caused by: java.net.ConnectException: Connection refused
        at java.net.PlainSocketImpl.socketConnect(Native Method)
        at java.net.PlainSocketImpl.doConnect(PlainSocketImpl.java:333)
        at java.net.PlainSocketImpl.connectToAddress(PlainSocketImpl.java:195)
        at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:182)
        at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:366)
        at java.net.Socket.connect(Socket.java:519)
        at
org.jboss.remoting.transport.socket.SocketClientInvoker.createSocket(SocketClientInvoker.java:192)
        at
org.jboss.remoting.transport.bisocket.BisocketClientInvoker.createSocket(BisocketClientInvoker.java:429)
        at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.getConnection(MicroSocketClientInvoker.java:827)
        at
org.jboss.remoting.transport.socket.MicroSocketClientInvoker.transport(MicroSocketClientInvoker.java:569)
        ... 28 more

View the original post :
http://www.jboss.org/index.html?module=bb&op=viewtopic&p=4222664#...

Reply to the post :
http://www.jboss.org/index.html?module=bb&op=posting&mode=reply&a...

2025

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

2010

2009

2008

2007

2006

[Remoting] - Re: Race condition in ConnectionValidator