Mark Torres [http://community.jboss.org/people/mark_v_torres] created the discussion "Re: LeasePinger, sessionId, jboss messaging" To view the discussion, visit: http://community.jboss.org/message/583131#583131 -------------------------------------------------------------- Hi Ron, Thanks for your reply. Its been a couple of weeks so the exact behavior is a little hazy in my memory. I'll try to test later. For the case where the LeasePinger awakes first, what happens is the server cleans up its associated resources for that lease, but the client eventually still tries to use the lease. We eventually end up with repeating log entries that contains the following WARN  [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ http://community.jboss.org/mailto:ControlMonitorTimerTask@2b22ebae ControlMonitorTimerTask@2b22ebae: detected failure on control connection Thread[control: Socket[addr=/*.*.*.*,port=*****,localport=*****],5,jboss] (3j011-cnnwn5-gg6xpq1c-1-gg6xw0ay-c: requesting new control connection WARN  [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ http://community.jboss.org/mailto:ControlMonitorTimerTask@2b22ebae ControlMonitorTimerTask@2b22ebae: detected failure on control connection Thread[control: Socket[addr=/*.*.*.*,port=*****,localport=*****],5,jboss] (3j011-cnnwn5-gg6xpq1c-1-gg6xw0ay-c: requesting new control connection WARN  [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ http://community.jboss.org/mailto:ControlMonitorTimerTask@2b22ebae ControlMonitorTimerTask@2b22ebae: detected failure on control connection Thread[control: Socket[addr=/*.*.*.*,port=*****,localport=*****],5,jboss] (3j011-cnnwn5-gg6xpq1c-1-gg6xw0ay-c: requesting new control connection WARN  [org.jboss.remoting.transport.bisocket.BisocketServerInvoker] org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ http://community.jboss.org/mailto:ControlMonitorTimerTask@2b22ebae ControlMonitorTimerTask@2b22ebae: detected failure on control connection Thread[control: Socket[addr=/*.*.*.*,port=*****,localport=*****],5,jboss] (3j011-cnnwn5-gg6xpq1c-1-gg6xw0ay-c: requesting new control connection +But I'm not sure your "recreation" is a faithful representation of the problem.  When you say "the connection becomes dead on the server side", do you mean+ Neither the server nor the client gets restarted. They remain connected on the network, but on my "recreation" the client experienced a heavy load that its not able to send out pings for some time. "The connection becomes dead on the server side" - What I mean to say is that the resources have been cleaned up from the server side for that lease, but the actual server jvm is still running. Here's the trace log that I got from the server during an unsuccesful disconnection... --connect 2010-12-28 09:15:09,940 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream 2010-12-28 09:15:19,911 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream 2010-12-28 09:15:19,911 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller 2010-12-28 09:15:19,911 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[5d4a62, $PING$] from unmarshaller 2010-12-28 09:15:19,911 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[192.168.1.3:4457].invoke() 2010-12-28 09:15:19,911 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] received $PING$ 2010-12-28 09:15:19,911 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for invoker session id: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.ServerInvoker] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] matches: leasePingerId: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] requestMap: {ClientHolderKey={5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6=org.jboss.remoting.ClientHolder@be8e12}, timeStamp=1293545641187, leasePingerId=5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9} 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] last update: 1293545631187, this update: 1293545641187 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] updating: new Client list: 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.Lease] 5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9:  5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.ServerInvoker] Updated lease for invoker session id (5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8) 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] returning InvocationResponse[6159c4, true] 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[192.168.1.3:4457].invoke() returned InvocationResponse[6159c4, true] 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream 2010-12-28 09:15:19,912 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation -- disconnect 2010-12-28 09:15:59,806 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] did not receive ping: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8 2010-12-28 09:15:59,808 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] notifying listeners about 1 expired client(s) 2010-12-28 09:15:59,808 DEBUG [org.jboss.remoting.ConnectionNotifier] mailto:org.jboss.remoting.ConnectionNotifier@fe8c4 org.jboss.remoting.ConnectionNotifier@fe8c4 Server connection lost to client (session id = 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] removing server callback handler ServerInvokerCallbackHandler[5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6+5c4o16-3bs5xt-gi8uuno8-1-gi8uw25b-d]. 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.Client] Client[4806599:3j011-y3aa1o-gi84ufr8-1-gi8uxqvf-c] entering disconnect() 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] entering terminateLease() for null 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] leasePinger is null: must have been shut down already 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] leaving terminateLease() for null 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.InvokerRegistry] destroying client invoker InvokerLocator [bisocket://192.168.1.6:452753942/callback?callbackServerHost=192.168.1.6&callbackServerPort=452753942&callbackServerProtocol=bisocket&clientMaxPoolSize=1&clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper&datatype=jms&guid=5c4o16-3bs5xt-gi8uuno8-1-gi8uw24g-c&isCallbackServer=true&onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool&serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper], config {callbackErrorsAllowed=1, registerCallbackListener=false, callbackServerProtocol=bisocket, serverInvokerCallbackHandler=ServerInvokerCallbackHandler[5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6+5c4o16-3bs5xt-gi8uuno8-1-gi8uw25b-d], stopLeaseOnFailure=true, socket.check_connection=false, listenerId=5c4o16-3bs5xt-gi8uuno8-1-gi8uw25b-d, unmarshaller=org.jboss.jms.wireformat.JMSWireFormat, marshaller=org.jboss.jms.wireformat.JMSWireFormat, serverInvoker=SocketServerInvoker[192.168.1.3:4457], clientLeasePeriod=10000, onewayThreadPool=org.jboss.jms.server.remoting.DirectThreadPool, useClientConnectionIdentity=true, callbackServerHost=192.168.1.6, JBM_clientMaxPoolSize=200, callbackTimeout=10000, clientMaxPoolSize=1, validatorPingTimeout=5000, isCallbackServer=true, validatorPingPeriod=10000, numberOfRetries=10, serverSocketClass=org.jboss.jms.server.remoting.ServerSocketWrapper, failureDisconnectTimeout=0, clientSocketClass=org.jboss.jms.client.remoting.ClientSocketWrapper, callbackServerPort=452753942, guid=5c4o16-3bs5xt-gi8uuno8-1-gi8uw24g-c, dataType=jms, serverBindPort=4457, datatype=jms, serverBindAddress=192.168.1.3, timeout=10000} 2010-12-28 09:15:59,809 DEBUG [org.jboss.remoting.InvokerRegistry] removed SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] from registry 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.InvokerRegistry] disconnecting SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] 2010-12-28 09:15:59,809 DEBUG [org.jboss.remoting.transport.socket.MicroSocketClientInvoker] SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] disconnecting ... 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] disconnecting ... 2010-12-28 09:15:59,809 TRACE [org.jboss.remoting.MicroRemoteClientInvoker] SocketClientInvoker[43fb68, bisocket://192.168.1.6:452753942] disconnected 2010-12-28 09:15:59,809 DEBUG [org.jboss.remoting.Client] Client[4806599:3j011-y3aa1o-gi84ufr8-1-gi8uxqvf-c] is disconnected 2010-12-28 09:15:59,809 DEBUG [org.jboss.remoting.callback.ServerInvokerCallbackHandler] ServerInvokerCallbackHandler[5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6+5c4o16-3bs5xt-gi8uuno8-1-gi8uw25b-d] shut down 2010-12-28 09:15:59,810 DEBUG [org.jboss.remoting.ConnectionNotifier] mailto:org.jboss.remoting.ConnectionNotifier@fe8c4 org.jboss.remoting.ConnectionNotifier@fe8c4 notified ConnectionManager[1aea727] of connection lost to: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6 2010-12-28 09:15:59,810 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] Notified connection listener of lease expired due to lost connection from client (client session id = 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6 2010-12-28 09:15:59,810 TRACE [org.jboss.remoting.Lease] Lease[406c7e:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] removed lease:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8 --ping returns true but should be false 2010-12-28 09:18:47,448 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream 2010-12-28 09:18:47,448 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[1887dd5, $PING$] from unmarshaller 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[192.168.1.3:4457].invoke() 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] received $PING$ 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.ServerInvoker] Getting lease for invoker session id: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.Lease] Lease[c83cfd:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] initialized with lastUpdate: 1293545848717 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.Lease] Lease[c83cfd:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] initialized with requestPayload: {5c4o16-3bs5xt-gi8uuno8-1-gi8uw21m-6=org.jboss.remoting.ClientHolder@1c232a} 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.Lease] leasePingerId: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.Lease] Starting lease for client invoker (session id = 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8) with lease window time of 20000 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.ServerInvoker] No lease established for invoker session id (5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8), so starting a new one:Lease[c83cfd:5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8:5c4o16-3bs5xt-gi8uuno8-1-gi8uw222-9] 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] returning InvocationResponse[148ccb8, true] 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[192.168.1.3:4457].invoke() returned InvocationResponse[148ccb8, true] 2010-12-28 09:18:47,449 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance 2010-12-28 09:18:47,450 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream 2010-12-28 09:18:47,450 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation 2010-12-28 09:18:47,450 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream 2010-12-28 09:18:47,486 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[d1e832, self, $PING$] from unmarshaller 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] about to call SocketServerInvoker[192.168.1.3:4457].invoke() 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] received $PING$ 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.ServerInvoker] Checking lease for invoker session id: 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.ServerInvoker] Found lease for invoker session id (5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8) 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.ServerInvoker] SocketServerInvoker[192.168.1.3:4457] responding true to $PING$ for invoker sessionId 5c4o16-3bs5xt-gi8uuno8-1-gi8uw21q-8 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] SocketServerInvoker[192.168.1.3:4457].invoke() returned true 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] creating response instance 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] wrote response to the output stream 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] preparing to process next invocation invocation 2010-12-28 09:18:47,487 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read version from input stream 2010-12-28 09:18:57,440 TRACE [org.jboss.remoting.transport.socket.ServerThread] read version 22 from input stream 2010-12-28 09:18:57,440 TRACE [org.jboss.remoting.transport.socket.ServerThread] blocking to read invocation from unmarshaller 2010-12-28 09:18:57,440 TRACE [org.jboss.remoting.transport.socket.ServerThread] read InvocationRequest[84a74, InternalI -------------------------------------------------------------- Reply to this message by going to Community [http://community.jboss.org/message/583131#583131] Start a new discussion in JBoss Remoting at Community [http://community.jboss.org/choose-container!input.jspa?contentType=1&...]