IndexOutOfBoundsException during close of idle ssl connection

Hi Jonas,

What version of java are you using? Can you describe the circumstances in which this happens? Eg does it happen after a lot of load over many connections or is it very light traffic and few connections etc. What is the client, is it a browser or other type of client? Finally, it would be great if you could test jetty-7.1.5 just to be sure that the problem is still there.

thanks,
Jan

Hi Jan,

we're using java 1.6.0_11-b03 (64 bit). Load seems to be rater high, ranging from 300-1000 connections. Clients are browsers (ie, firefox, etc.). I'll have to see if we're able to upgrade to 7.1.5, because iirc we ran into different issues when using 7.1.3 a while ago.

Thanks,
Jonas

We upgraded some of our production servers to jetty 7.1.5. I'll let you know if the problem still occurs.

We'll have to try this again once http://jira.codehaus.org/browse/JETTY-1249 is fixed, since jetty 7.1.5 doesn't seem to expire idle connections at all.

I've committed a speculative fix r2109... but will leave issue open until I can reproduce and confirm with test harness.

There was a slight race with the recycled SSL buffers (harmless) when an asynchronous close was applied.
fixed now.

Unfortunately, this doesn't seem to be fixed in jetty 7.1.6. I just encountered the following stack trace:

Thread[pool-5-thread-18,5,main]
java.lang.IndexOutOfBoundsException
at java.nio.Buffer.checkIndex(Unknown Source)
at java.nio.DirectByteBuffer.get(Unknown Source)
at com.sun.net.ssl.internal.ssl.EngineInputRecord.read(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.readRecord(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.readNetRecord(Unknown Source)
at com.sun.net.ssl.internal.ssl.SSLEngineImpl.unwrap(Unknown Source)
at javax.net.ssl.SSLEngine.unwrap(Unknown Source)
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.unwrap(SslSelectChannelEndPoint.java:712)
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.shutdownOutput(SslSelectChannelEndPoint.java:224)
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.close(SslSelectChannelEndPoint.java:288)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.idleExpired(SelectChannelEndPoint.java:241)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.checkIdleTimestamp(SelectChannelEndPoint.java:232)
at org.eclipse.jetty.io.nio.SelectorManager$SelectSet$2.run(SelectorManager.java:768)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(Unknown Source)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
at java.lang.Thread.run(Unknown Source)

I'm seeing this too.
Here's the stack trace from my server, it's embedded jetty, ubuntu, 1.6.0_20-b02

2010-09-20 23:34:28,762 DEBUG [org.eclipse.jetty.http.ssl] [Session-1, SSL_NULL_WITH_NULL_NULL] close wrap Status = CLOSED HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 0 bytesProduced = 23
2010-09-20 23:34:28,762 DEBUG [org.eclipse.jetty.http.ssl] [Session-1, SSL_NULL_WITH_NULL_NULL] fill wrap Status = CLOSED HandshakeStatus = NOT_HANDSHAKING
bytesConsumed = 0 bytesProduced = 0
2010-09-20 23:34:28,762 DEBUG [org.eclipse.jetty.util.log] EXCEPTION
java.nio.channels.ClosedChannelException
at sun.nio.ch.SocketChannelImpl.ensureWriteOpen(SocketChannelImpl.java:126)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:324)
at org.eclipse.jetty.io.nio.ChannelEndPoint.flush(ChannelEndPoint.java:187)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.flush(SelectChannelEndPoint.java:273)
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.flush(SslSelectChannelEndPoint.java:615)
at org.eclipse.jetty.io.nio.SslSelectChannelEndPoint.fill(SslSelectChannelEndPoint.java:438)
at org.eclipse.jetty.http.HttpParser.parseNext(HttpParser.java:289)
at org.eclipse.jetty.http.HttpParser.parseAvailable(HttpParser.java:211)
at org.eclipse.jetty.server.HttpConnection.handle(HttpConnection.java:424)
at org.eclipse.jetty.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:506)
at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:436)
at java.lang.Thread.run(Thread.java:619)
2010-09-20 23:34:28,762 DEBUG [org.eclipse.jetty.util.log] EOF

Guy,

I think your exception is normal and is only being reported because you have debug turned on.

I've tried expiring SSL connections and I'm not getting any problems. I definitely can't reproduce the IOOBE.

Note that these kinds of exceptions while closing a connection at expiry are almost always ignorable - but I will see if I can be less verbose without suppressing real exceptions.

Greg,

Thanks for the information.
In 7.1.3 we experienced server hang while seeing in the logs many of these types of messages. Actually, after upgrading to 7.1.6 (36 hours ago) we didn't experience server hanging until now.

Guy

I'm closing this again for now as I think it is resolved.
Jonas, if you are still seeing IOOBE, please reopen, but at a lower priority (because it is an ignorable exception that is caused by some strangeness while closing an SSL connection).