[logback-user] java.net.SocketException with logback-access on jetty 6

[Steven Parkes]

Not sure if this is a jetty issue or a logback issue:

I'm getting intermittent errors using logback-access to write the jetty access log. Full backtrace below.

A race condition? Maybe the socket already closed before the logger gets run? I've seen it on 6.1.24 and 6.1.26 with 0.9.28.

java.lang.Error: java.net.SocketException: Socket operation on non-socket
	at sun.nio.ch.Net.localAddress(Net.java:128)
	at sun.nio.ch.SocketChannelImpl.localAddress(SocketChannelImpl.java:423)
	at sun.nio.ch.SocketAdaptor.getLocalAddress(SocketAdaptor.java:147)
	at java.net.Socket.getLocalSocketAddress(Socket.java:717)
	at org.mortbay.io.nio.ChannelEndPoint.getLocalPort(ChannelEndPoint.java:341)
	at org.mortbay.jetty.Request.getLocalPort(Request.java:839)
	at ch.qos.logback.access.spi.AccessEvent.getLocalPort(AccessEvent.java:445)
	at ch.qos.logback.access.spi.AccessEvent.prepareForDeferredProcessing(AccessEvent.java:481)
	at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:211)
	at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:108)
	at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:64)
	at ch.qos.logback.access.jetty.RequestLogImpl.log(RequestLogImpl.java:133)
	at org.mortbay.jetty.handler.RequestLogHandler.handle(RequestLogHandler.java:51)
	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
	at org.mortbay.jetty.Server.handle(Server.java:326)
	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
	at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
Caused by: java.net.SocketException: Socket operation on non-socket
	at sun.nio.ch.Net.localInetAddress(Native Method)
	at sun.nio.ch.Net.localAddress(Net.java:125)
	at sun.nio.ch.SocketChannelImpl.localAddress(SocketChannelImpl.java:423)
	at sun.nio.ch.SocketAdaptor.getLocalAddress(SocketAdaptor.java:147)
	at java.net.Socket.getLocalSocketAddress(Socket.java:717)
	at org.mortbay.io.nio.ChannelEndPoint.getLocalPort(ChannelEndPoint.java:341)
	at org.mortbay.jetty.Request.getLocalPort(Request.java:839)
	at ch.qos.logback.access.spi.AccessEvent.getLocalPort(AccessEvent.java:445)
	at ch.qos.logback.access.spi.AccessEvent.prepareForDeferredProcessing(AccessEvent.java:481)
	at ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:211)
	at ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:108)
	at ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
	at ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:64)
	at ch.qos.logback.access.jetty.RequestLogImpl.log(RequestLogImpl.java:133)
	at org.mortbay.jetty.handler.RequestLogHandler.handle(RequestLogHandler.java:51)
	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
	at org.mortbay.jetty.Server.handle(Server.java:326)
	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
	at org.mortbay.jetty.HttpConnection$RequestHandler.headerComplete(HttpConnection.java:923)
	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:547)
	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:212)
	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)