Re: Connection reset

I'm coming back to this very old thread, since after a few years and a couple of changes of network config we have started to get the problem again, but this time we understand a bit more about it.  I've also had a few off-list follow-ups which I wasn't able to reply helpfully to, maybe re-opening the thread can help some more.



----- Original Message ----
From: Peter Jones - JavaSoft East <[email protected]>
To: Robert Gibson <[email protected]>
Cc: [email protected]
Sent: Friday, 17 March, 2006 11:43:03 PM
Subject: Re: Connection reset

>> I'm getting the exception below, 2 hours after running
>> my command. The server-side processing should take
>> about 30 seconds, although the return value is a bunch
>> of HashMaps which may take a while to serialize.
>> 
>> It looks to me like the server thinks it has finished
>> the command, but the client hasn't received all the
>> data it was expecting and so it leaves the connection
>> open.  After 2 hours the server gets bored and resets
>> the connection.
>> 
>> Is this the correct interpretation? If so, what would
>> cause it?  Should I be able to shorten the timeout
>> period with the property
>> sun.rmi.transport.tcp.readTimeout
>>                              ?  Changing this property
>> doesn't seem to have the desired effect (JDK 1.5.0_06,
>> client and server are RH Linux FC3/4).
>
>That system property's default value is indeed two hours, but it
>doesn't seem related to this failure.  It controls the server-side
>socket read timeout, so it only applies when the server is expecting
>data from a connection (like a new remote invocation request, or the
>remainder of the current request).  It appears that the client was in
>the middle of unmarshalling a HashMap contained in the return value of
>a "getDataSet" invocation when the exception occurred.  As the client
>was trying to read from the connection, if the server closed its
>socket because of this timeout, the client should get an EOFException,
>not a connection reset indication.
>
>The two hour delay and the connection reset failure might suggest that
>the TCP keepalive mechanism triggered the failure.  But that would
>seem to indicate that TCP segments between the client and server
>machines were getting dropped at some point.  Does other communication
>between them seem to work throughout this period?
>
This time round I was able to occasionally reproduce the problem with a small test case, and take packet dumps.  The dumps showed that the server machine wasn't responding correctly to MTU negociation and certain packets were just getting unceremoniously (but consistently) swallowed.

>How reproducible is this failure-- always, occasionally, etc.?
>
Occasional.

>Have you gotten thread dumps from the client and server VMs during
>this two hour period?  "netstat" output on the client and server
>machines during this period?
>
I have thread dumps, but I'm not sure they are very interesting.  I'll put them anyway, since you asked.
Client:
"main" prio=10 tid=0x000000004abc9c00 nid=0x2e2e runnable [0x0000000041fb5000..0x0000000041fb5ed0]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketInputStream.socketRead0(Native Method)
    at java.net.SocketInputStream.read(SocketInputStream.java:129)
    at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
    at java.io.BufferedInputStream.read(BufferedInputStream.java:237)
    - locked <0x00002aaade5b3438> (a java.io.BufferedInputStream)
    at java.io.DataInputStream.readByte(DataInputStream.java:248)
    at sun.rmi.transport.StreamRemoteCall.executeCall(StreamRemoteCall.java:195)
    at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:142)
    at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:178)
    at java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:132)
    at $Proxy0.testMethod(Unknown Source)
    at tests.rmi.Client.main(Client.java:17)

Server:
"RMI TCP Connection(53)-172.17.18.141" daemon prio=10 tid=0x08b89000 nid=0x7966 runnable [0xb3fd1000..0xb3fd1e30]
   java.lang.Thread.State: RUNNABLE
    at java.net.SocketOutputStream.socketWrite0(Native Method)
    at java.net.SocketOutputStream.socketWrite(SocketOutputStream.java:92)
    at java.net.SocketOutputStream.write(SocketOutputStream.java:136)
    at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:65)
    at java.io.BufferedOutputStream.write(BufferedOutputStream.java:109)
    - locked <0x818743e0> (a java.io.BufferedOutputStream)
    at java.io.ObjectOutputStream$BlockDataOutputStream.write(ObjectOutputStream.java:1803)
    at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1495)
    at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1474)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1392)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1150)
    at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:326)
    at java.util.HashMap.writeObject(HashMap.java:1001)
    at sun.reflect.GeneratedMethodAccessor5.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:945)
    at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1461)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1392)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1150)
    at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:326)
    at sun.rmi.server.UnicastRef.marshalValue(UnicastRef.java:274)
    at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:315)
    at sun.rmi.transport.Transport$1.run(Transport.java:159)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.rmi.transport.Transport.serviceCall(Transport.java:155)
    at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:885)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907)
    at java.lang.Thread.run(Thread.java:619)

After about 10 minutes, this server thread disappears.
Netstat on both machines shows an established connection at the beginning, although after a while only the client machine shows an established connection.

This time I have some slightly different questions:
1) Where should I look to try and sort out why the MTU negociation isn't happening properly, in the O/S, Java or the network setup?  Does Java rewrite any of the network stack that would be implicated in this kind of problem or is it 100% based on the underlying O/S implementation?  (We're using Sun JDK 1.6.0_06 and RH Linux FC6 kernel 2.6.18 on x86_64.)
2) My network admins tell me they are surprised to see that the RMI packets are all sent with the Don't Fragment bit set.  (This apparently explains why we are only seeing the problem with our RMI traffic and not SMTP, etc.)  Is there any way to adjust this?
3) While I wait for the underlying problem to be fixed, in the face of systematically dropped packets, would you still advise adjusting the property
sun.rmi.transport.tcp.responseTimeout
assuming we can find a value that allows "normal" calls to complete?

Thanks again for your help,
Robert

>> java.lang.RuntimeException: RMI exception
>>         at com.xxx.data.database.AbstractDataDatabase_Stub.getDataSet(AbstractDataDatabase_Stub.java:366)
>>         at com.xxx.data.delegatedatabase.DelegateDataDatabase.getDataSet(DelegateDataDatabase.java:54)
>> Caused by: java.rmi.UnmarshalException: error unmarshalling return; nested exception is:
>>         java.net.SocketException: Connection reset
>>         at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:157)
>>         at com.nexgenfs.data.database.AbstractDataDatabase_Stub.getDataSet(AbstractDataDatabase_Stub.java:359)
>>         ... 7 more
>> Caused by: java.net.SocketException: Connection reset
>>         at java.net.SocketInputStream.read(SocketInputStream.java:168)
>>         at java.io.BufferedInputStream.fill(BufferedInputStream.java:218)
>>         at java.io.BufferedInputStream.read1(BufferedInputStream.java:256)
>>         at java.io.BufferedInputStream.read(BufferedInputStream.java:313)
>>         at java.io.ObjectInputStream$PeekInputStream.read(ObjectInputStream.java:2217)
>>         at java.io.ObjectInputStream$PeekInputStream.readFully(ObjectInputStream.java:2230)
>>         at java.io.ObjectInputStream$BlockDataInputStream.readInt(ObjectInputStream.java:2722)
>>         at java.io.ObjectInputStream.readHandle(ObjectInputStream.java:1398)
>>         at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1279)
>>         at java.io.ObjectInputStream.readObject(ObjectInputStream.java:339)
>>         at java.util.HashMap.readObject(HashMap.java:1013)
>>         at sun.reflect.GeneratedMethodAccessor6.invoke(Unknown Source)
>>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
>>         at java.lang.reflect.Method.invoke(Method.java:585)
>>         at java.io.ObjectStreamClass.invokeReadObject(ObjectStreamClass.java:919)
>>         at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1813)
>>         at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1713)
>>         at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1299)
>>         at java.io.ObjectInputStream.defaultReadFields(ObjectInputStream.java:1912)
>>         at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1836)
>>         at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1713)
>>         at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1299)
>>         at java.io.ObjectInputStream.readObject(ObjectInputStream.java:339)
>>         at sun.rmi.server.UnicastRef.unmarshalValue(UnicastRef.java:290)
>>         at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:139)
>>         ... 8 more
>
>-- Peter


Send instant messages to your online friends http://uk.messenger.yahoo.com 

===========================================================================
To unsubscribe, send email to [email protected] and include in the body
of the message "signoff RMI-USERS".  For general help, send email to
[email protected] and include in the body of the message "help".

For a list of frequently asked RMI questions please refer to:
http://java.sun.com/j2se/1.3/docs/guide/rmi/faq.html

To view past RMI-USERS postings, please see:
http://archives.java.sun.com/archives/rmi-users.html