What type of connections "RMI TCP Connection(idle)" threads correspond to?

Question

I'm working on a distributed system which is RMI based using jdk1.6.

Occasionally I can see ConcurrentModificationException errors on that thread happening within the RMI runtime when it fails to serialize objects. I can reproduce that exception easily by concurrently updating object being returned from remote method.

But the problem is that I can't find the source of those calls. RMI exception is written to stderr (captured on server side within runtime code after it exits remote object method), but there are no matching exception in client services (while if that was a legitimate remote call, RemoteException with appropriate cause would be raised).

The only different thing about those exceptions is that they are happening on "RMI TCP Connection(idle)" thread and not on a thread like "RMI TCP Connection(<connection count>)-<client endpoint info>".

Any clues on what are those "idle" threads in RMI? I failed to find such within the openjdk sources.

Upd: I'm adding an exception stack trace as reproduced, which is what you usually see in described situation.

Server side console shows:

Exception dispatching call to [-3534448f:12f54948b7f:-7fff, 349678755005857493] in thread "RMI TCP Connection(6)-x.x.x.x" at Thu Apr 14 16:15:13 BST 2011:
java.util.ConcurrentModificationException
    at java.util.ArrayList.writeObject(ArrayList.java:573)
    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 java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:945)
    at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1469)
    at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1400)
    at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1158)
    at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:330)
    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:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)

Client size exception thrown to caller:

java.rmi.UnmarshalException: error unmarshalling return; nested exception is:
    java.io.EOFException
    at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:173)
    at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(RemoteObjectInvocationHandler.java:178)
    at java.rmi.server.RemoteObjectInvocationHandler.invoke(RemoteObjectInvocationHandler.java:132)
    at $Proxy0.getData(Unknown Source)
    at Clnt.main(Clnt.java:11)
    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 com.intellij.rt.execution.application.AppMain.main(AppMain.java:115)
Caused by: java.io.EOFException
    at java.io.ObjectInputStream$BlockDataInputStream.peekByte(ObjectInputStream.java:2553)
    at java.io.ObjectInputStream.skipCustomData(ObjectInputStream.java:1899)
    at java.io.ObjectInputStream.readSerialData(ObjectInputStream.java:1873)
    at java.io.ObjectInputStream.readOrdinaryObject(ObjectInputStream.java:1752)
    at java.io.ObjectInputStream.readObject0(ObjectInputStream.java:1328)
    at java.io.ObjectInputStream.readObject(ObjectInputStream.java:350)
    at sun.rmi.server.UnicastRef.unmarshalValue(UnicastRef.java:306)
    at sun.rmi.server.UnicastRef.invoke(UnicastRef.java:155)
    ... 9 more

Answer 1

Threads are created in RMI's connection pool with the name 'RMI TCP Connection(idle)'. When one of these is used, the runnable it is being used to execute renames the thread to 'RMI TCP Connection(n)' where n is the connection number being handled (a sequential number), and renames back to 'idle' in the runnable's finally block. So any trace labelled 'RMI TCP Connection(idle)' must come before the runnable renames it as a connection thread, or after it has been renamed back.

Don't ask me how that is possible. The actual answer to your problem, if not your question, is not to modify objects while they are concurrently being returned ;-)

Answer 2

I got to the bottom of it. Problem happens in two cases:

1. When marshaling a return value throws some exception and that exception in turn contains an object prone to concurrent modification. UnicastServerRef tries to write the cause into the (already corrupted) return stream and causes ConcurrentModificationException.
2. When method raises an exception and this exception fails to serialize with ConcurrentModificationException (or any other runtime exception).
   This exception goes all the way up the stack and is caught and logged by thread pool, not RMI runtime (that's why there is no Exception dispatching call to line at the beginning). That explains thread name being idle since it is already returned to pool from RMI's point of view.

Here's the real exception which is in fact a bit different from what reproduced exception shows in terms of first line and actual call trace:

Exception in thread "RMI TCP Connection(idle)" java.util.ConcurrentModificationException
 at java.util.ArrayList.writeObject(ArrayList.java:573)
 at sun.reflect.GeneratedMethodAccessor6.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.defaultWriteFields(ObjectOutputStream.java:1509)
 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.defaultWriteFields(ObjectOutputStream.java:1509)
 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.defaultWriteFields(ObjectOutputStream.java:1509)
 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 sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:343)
 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:886)
 at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
 at java.lang.Thread.run(Thread.java:619)

It doesn't give much clues to the original problem, so I'll have to wait for a client exception to show up at some point to fix that.
If that kind of exception happens when reading JMX attribute by jconsole, it'll not show stacktrace, but will show attribute value as Unavailable.