Skip to main content

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index] [List Home]
[jetty-users] onWebSocketError "java.net.SocketTimeoutException: Timeout on Read"

Good evening,

I run Jetty with:

# java -Dorg.eclipse.jetty.LEVEL=DEBUG -jar /usr/share/java/jetty-distribution-9.3.10.v20160621/start.jar jetty.home=/usr/share/java/jetty-distribution-9.3.10.v20160621 jetty.base=/var/www/jetty-base jetty.http.host=127.0.0.1

And connect from _javascript_ to a custom WebSocketServlet

public class WsServlet extends WebSocketServlet {
    @Override
    public void configure(WebSocketServletFactory factory) {
        factory.getPolicy().setIdleTimeout(120 * 1000);
        factory.getPolicy().setMaxBinaryMessageSize(1);
        factory.getPolicy().setMaxTextMessageSize(64 * 1024);
        factory.register(MyListener.class);
    }
}

The _javascript_ client sends a short text message and receives one from the WebSocketServlet.

After that no data is exchanged for longer time, but I'd like to keep connection on.

Until today it worked well (I use HAProxy with "timeout tunnel 1h" in front of the Jetty and I left the browser repeatedly for longer untouched and the connection was only closed after 1 hour).

But today I repeatedly get the exception:

2016-07-13 21:05:52.180:DBUG:oejs.session:Scheduler-739498517: Scavenging sessions at 1468436752180
2016-07-13 21:05:52.302:DBUG:oejs.session:Scheduler-739498517: Scavenging sessions at 1468436752302
2016-07-13 21:05:52.386:DBUG:oejs.session:Scheduler-739498517: Scavenging sessions at 1468436752386
2016-07-13 21:05:52.410:DBUG:oejs.session:Scheduler-739498517: Scavenging sessions at 1468436752410
2016-07-13 21:06:04.536:DBUG:oeji.IdleTimeout:Scheduler-739498517: SelectChannelEndPoint@464b78d4{/127.0.0.1:40866<->8080,Open,in,out,FI,-,120000/120000,WebSocketServerConnection@5341fbdc}{io=1/1,kio=1,kro=1} idle timeout check, elapsed: 120000 ms, remaining: 0 ms
2016-07-13 21:06:04.536:DBUG:oeji.IdleTimeout:Scheduler-739498517: SelectChannelEndPoint@464b78d4{/127.0.0.1:40866<->8080,Open,in,out,FI,-,120000/120000,WebSocketServerConnection@5341fbdc}{io=1/1,kio=1,kro=1} idle timeout expired
2016-07-13 21:06:04.536:DBUG:oeji.AbstractConnection:Scheduler-739498517: WebSocketServerConnection@5341FBDC{endp=org.eclipse.jetty.server.ProxyConnectionFactory$ProxyEndPoint@45edfc89,ios=IOState@4133b674[OPEN,in,out],f=Flusher[queueSize=0,aggregateSize=0,failure=null],g=Generator[SERVER,validating,+rsv1],p=Parser@907768b[ExtensionStack,s=START,c=0,len=291,f=null]} onFillInterestedFailed java.util.concurrent.TimeoutException: Idle timeout expired: 120000/120000 ms
2016-07-13 21:06:04.537:WARN:daw.MyListener:Scheduler-739498517: onWebSocketError: {}
java.net.SocketTimeoutException: Timeout on Read
at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onReadTimeout(AbstractWebSocketConnection.java:592)
at org.eclipse.jetty.io.AbstractConnection.onFillInterestedFailed(AbstractConnection.java:168)
at org.eclipse.jetty.websocket.common.io.AbstractWebSocketConnection.onFillInterestedFailed(AbstractWebSocketConnection.java:538)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.failed(AbstractConnection.java:279)
at org.eclipse.jetty.io.FillInterest.onFail(FillInterest.java:125)
at org.eclipse.jetty.io.AbstractEndPoint.onIdleExpired(AbstractEndPoint.java:166)
at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:166)
at org.eclipse.jetty.io.IdleTimeout$1.run(IdleTimeout.java:50)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
at java.util.concurrent.FutureTask.run(FutureTask.java:266)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at java.lang.Thread.run(Thread.java:745)
2016-07-13 21:06:04.538:DBUG:oeji.WriteFlusher:Scheduler-739498517: write: WriteFlusher@5ab91e26{IDLE} [DirectByteBuffer@1831d372[p=0,l=2,c=1024,r=2]={<<<\x88\x02>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00},HeapByteBuffer@5d335e10[p=0,l=2,c=2,r=2]={<<<\x03\xE8>>>}]
2016-07-13 21:06:04.538:DBUG:oeji.WriteFlusher:Scheduler-739498517: update WriteFlusher@5ab91e26{WRITING}:IDLE-->WRITING
2016-07-13 21:06:04.538:DBUG:oeji.ChannelEndPoint:Scheduler-739498517: flushed 4 SelectChannelEndPoint@464b78d4{/127.0.0.1:40866<->8080,Open,in,out,-,W,120002/120000,WebSocketServerConnection@5341fbdc}{io=1/1,kio=1,kro=1}
2016-07-13 21:06:04.538:DBUG:oeji.WriteFlusher:Scheduler-739498517: Flushed=true 2/2+1 WriteFlusher@5ab91e26{WRITING}
2016-07-13 21:06:04.538:DBUG:oeji.WriteFlusher:Scheduler-739498517: update WriteFlusher@5ab91e26{IDLE}:WRITING-->IDLE
2016-07-13 21:06:04.539:DBUG:oeji.WriteFlusher:Scheduler-739498517: ignored: WriteFlusher@5ab91e26{IDLE} java.util.concurrent.TimeoutException: Idle timeout expired: 120000/120000 ms

Would could be the cause for that please?

I am attaching the full log file:

    https://gist.github.com/afarber/9b76a6b98da8f0837f31e54efbfc1e87

Regards
Alex



Back to the top