Sockets left in CLOSE_WAIT on server for JMS connections

[slimamar]

Hi,

We 're using JBoss AS 5.1.0.GA (with JBoss Messaging) and a client close a JMS connection
a socket is left in the CLOSE_WAIT state on the server.
We then quickly run out of file descriptors because of all the CLOSE_WAIT sockets left open.

Is the same problem with :
http://community.jboss.org/message/368512#368512

How can we resolve this issue ?

Thanks in adavance.

[ron_sigal]

Hi Amar,

Could you run the Application Server with logging enabled at the TRACE level for org.jboss.remoting?  You can set the log level in $JBOSS_HOME/server/default/conf/jboss-log4j.xml.  Then look for the sockets in CLOSE_WAIT and tell me about how they were created.  That might shed some light on which sockets are causing the problem.

-Ron

[slimamar]

Hi Ron,

I 've attached the server.log file with TRACE DEBUG level for org.jboss.remoting.

When a client JMS close the connection we have at the server side the socket which is listening at the port 4458 left open.

$ netstat -a
tcp        1      0 163.104.9.185:4458          163.104.9.160:43479              CLOSE_WAIT

Thanks for your response.

[slimamar]

Hi Ron,

Do you have some news ?

Do i have to submit an issue ?

Thanks for your response.

[ron_sigal]

Hi Amar,

Sorry ... your response fell through the cracks.

I looked at your server.log, but I don't see anything strange.  There are four worker threads, each one managing exactly one socket.  When the worker threads close, they close their socket.  I.e., you should see four sockets in CLOSE_WAIT for a few minutes.  I'm guessing that maybe you attached a server.log with a simple case as a demonstration.  In general, if you see one socket in CLOSE_WAIT per closed worker thread, then everything is normal.  Is that not what you're seeing?

By the way, have you tried increasing the number of file descriptors with ulimit -n?

-Ron

[jselvin]

Hi Ron,

I am observing similar issue in my application. We are using Jboss 4.2.0.GA, Jboss Remoting 2.5.3.SP1

We have a firewall between our server and client and we followed the forum,

http://blog.akquinet.de/2009/09/30/using-jboss-messaging-in-a-firewalled-environment-the-toll-road/

to set our parameters like below,

               <attribute name="marshaller" isParam="true">org.jboss.jms.wireformat.JMSWireFormat</attribute>

               <attribute name="unmarshaller" isParam="true">org.jboss.jms.wireformat.JMSWireFormat</attribute>

               <attribute name="dataType" isParam="true">jms</attribute>

               <attribute name="socket.check_connection" isParam="true">true</attribute>              

               <attribute name="serverBindAddress">${jboss.bind.address}</attribute>

               <attribute name="serverBindPort">4457</attribute>

               <attribute name="clientSocketClass" isParam="true">org.jboss.jms.client.remoting.ClientSocketWrapper</attribute>

               <attribute name="serverSocketClass">org.jboss.jms.server.remoting.ServerSocketWrapper</attribute>

               <attribute name="numberOfCallRetries" isParam="true">5</attribute>

               <attribute name="pingFrequency" isParam="true">5000</attribute>

               <attribute name="pingWindowFactor" isParam="true">2</attribute>

               <attribute name="onewayThreadPool">org.jboss.jms.server.remoting.DirectThreadPool</attribute>              

               <attribute name="stopLeaseOnFailure" isParam="true">true</attribute>

               <attribute name="clientLeasePeriod" isParam="true">10000</attribute>

               <attribute name="validatorPingPeriod" isParam="true">10000</attribute>

               <attribute name="validatorPingTimeout" isParam="true">5000</attribute>

               <attribute name="failureDisconnectTimeout" isParam="true">0</attribute>

               <attribute name="callbackErrorsAllowed">1</attribute>

               <attribute name="registerCallbackListener">false</attribute>

               <attribute name="useClientConnectionIdentity" isParam="true">true</attribute>

              <attribute name="timeout" isParam="true">1800000</attribute>

               <attribute name="numberOfRetries" isParam="true">10</attribute>

               <attribute name="JBM_clientMaxPoolSize" isParam="true">200</attribute>

               <attribute name="callbackTimeout">10000</attribute>

               <attribute name="secondaryBindPort">4481</attribute>

With this implementation, we have mulitple Connections in CLOSE_WAIT state most of them getting cleared and some left behind.

After several days, we loose the JMS communication. We need to restart the application again to get rid off.

Also we observed the below exception multiple times when the issue happens,

Exception:

2011-03-28 11:50:10,271 TRACE [org.jboss.remoting.transport.socket.ServerThread(638)](WorkerThread#4[10.255.254.134:42933]) WorkerThread#4[10.255.254.134:42933] EOFException received. This is likely due to client finishing communication.

java.io.EOFException

        at org.jboss.remoting.transport.socket.ServerThread.processInvocation(ServerThread.java:740)

        at org.jboss.remoting.transport.socket.ServerThread.dorun(ServerThread.java:586)

        at org.jboss.remoting.transport.socket.ServerThread.run(ServerThread.java:234)

Kindly share some light to resolve this.

Regards,

Joseph.

[ron_sigal]

Hi Joseph,

Hmmm.  When ServerThread gets the EOFException, it should close the socket which should move it out of the CLOSE_WAIT state.  Can you identify the socket mentioned in the exception (the one with remote port 42933 in this case) with a socket in the CLOSE_WAIT state?  Also, do you see the output of either

     log.debug(this + " closing socketWrapper: " + socketWrapper);

or

    log.error("failed to close socket wrapper", ex);

for that socket?

-Ron

[jselvin]

Hi Ron,

We changed the pingFrequency to 180000 and updated the Remoting Jar to 2.5.4.

This issue seems not appearing nowadays :-)

But we are facing the issue in our client,

Our client Application is losing the connection sometimes(not consistently) and never comes up,

We need to stop the client(but not server) to recreate the session successfully.

These are the below exceptions we see during that time.

[12 May 2011 16:52:36]  WARN [Timer-3] (BisocketServerInvoker.java:1281) - org.jboss.remoting.transport.bisocket.BisocketServerInvoker$ControlMonitorTimerTask@6105a6: detected failure on control connection Thread[control: Socket[addr=omcr-rmg3.com/10.255.254.134,port=4481,localport=3132],6,] (4ss2s-vevhkq-gnlg644p-1-gnlg6c36-l: requesting new control connection

[12 May 2011 16:52:36] DEBUG [controlConnectionRecreate:control: Socket[addr=omcr-rmg3.com/10.255.254.134,port=4481,localport=3132]] (BisocketClientInvoker.java:628) - getting secondary locator

[12 May 2011 16:52:36] DEBUG [controlConnectionRecreate:control: Socket[addr=omcr-rmg3.com/10.255.254.134,port=4481,localport=3132]] (BisocketClientInvoker.java:636) - secondary locator: InvokerLocator [null://omcr-rmg3.com:4481/?]

[12 May 2011 16:52:36] DEBUG [controlConnectionRecreate:control: Socket[addr=omcr-rmg3.com/10.255.254.134,port=4481,localport=3132]] (BisocketServerInvoker.java:379) - creating control connection: InvokerLocator [null://omcr-rmg3.com:4481/?]

[12 May 2011 16:52:36] DEBUG [controlConnectionRecreate:control: Socket[addr=omcr-rmg3.com/10.255.254.134,port=4481,localport=3132]] (BisocketServerInvoker.java:463) - SocketServerInvoker[172.28.2.28:345279834] created control connection (4ss2s-vevhkq-gnlg644p-1-gnlg6c36-l): Socket[addr=omcr-rmg3.com/10.255.254.134,port=4481,localport=3153]

Also attached the complete log file.

Kindly provide your analysis for this issue.

Thanks.

Joseph.

[ron_sigal]

Hi Joseph,

Are you still having this problem?

When you get a "detected failure on control connection" message, it means a PING from the server to the client isn't arriving in time.  These failures might be a sign of a congested network, in which case you might want to lengthen the PING cycle.  You can play with the parameters

* pingFrequency: how often the ping is sent

* pingWindowFactor: multiplied by pingFrequency to give the window within which the PING is expected.

-Ron