William
Reputation: 250
Jetty is throwing exceptions on ktor i think issue with http2
I'm getting these crashes on server using ktor with jetty. On start of jetty server it show exception of idle timeout then after sometime it throw too many other exceptions which i mentioned and server stop working please tell help me to findout this problem thanks.
2020-05-20 11:56:10.566 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.AbstractEndPoint - close DecryptedEndPoint@1066e08c{/152.32.102.11:14898<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=152/30000}
2020-05-20 11:56:10.566 [qtp897848096-2713] DEBUG org.eclipse.jetty.server.HttpChannel - handle https://{HOST}:7171/{ENDPOINT} ServerHttpChannelOverHTTP2@35396382{s=HttpChannelState@715f84bd{s=WOKEN rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WOKEN,uri=https://{HOST}:7171/{ENDPOINT},age=52973}#3
2020-05-20 11:56:10.566 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.AbstractEndPoint - close(null) DecryptedEndPoint@1066e08c{/152.32.102.11:14898<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=152/30000}
2020-05-20 11:56:10.566 [qtp897848096-2713] DEBUG o.e.jetty.server.HttpChannelState - handling HttpChannelState@715f84bd{s=WOKEN rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-05-20 11:56:10.566 [qtp897848096-2713] DEBUG org.eclipse.jetty.server.HttpChannel - action ASYNC_ERROR ServerHttpChannelOverHTTP2@35396382{s=HttpChannelState@715f84bd{s=HANDLING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=https://{HOST}:7171/{ENDPOINT},age=52973}#3
2020-05-20 11:56:10.566 [qtp897848096-2875] DEBUG o.e.j.u.t.ReservedThreadExecutor - ReservedThreadExecutor@6a969fb8{s=1/2,p=0}@2b7501a0 task=EatWhatYouKill@47733c6f/HTTP2Producer@53a8567/IDLE/p=true/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=6,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=1/2,p=0}][pc=0,pic=0,pec=0,epc=2]@2020-05-20T11:56:10.566514Z
2020-05-20 11:56:10.566 [qtp897848096-2713] WARN org.eclipse.jetty.server.HttpChannel - handleException /{ENDPOINT}
java.nio.channels.ClosedChannelException: null
at org.eclipse.jetty.http2.HTTP2Session.onShutdown(HTTP2Session.java:926)
at org.eclipse.jetty.http2.HTTP2Connection$HTTP2Producer.produce(HTTP2Connection.java:283)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
at org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:170)
at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:125)
at org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:348)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:543)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:398)
at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:388)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
at java.base/java.lang.Thread.run(Thread.java:834)
Suppressed: java.lang.Throwable: HttpInput failure
at org.eclipse.jetty.server.HttpInput.failed(HttpInput.java:823)
at org.eclipse.jetty.http2.server.HttpChannelOverHTTP2.onFailure(HttpChannelOverHTTP2.java:323)
at org.eclipse.jetty.http2.server.HTTP2ServerConnection.onStreamFailure(HTTP2ServerConnection.java:221)
at org.eclipse.jetty.http2.server.HTTP2ServerConnection.onSessionFailure(HTTP2ServerConnection.java:261)
at org.eclipse.jetty.http2.server.HTTP2ServerConnectionFactory$HTTPServerSessionListener.onFailure(HTTP2ServerConnectionFactory.java:128)
at org.eclipse.jetty.http2.HTTP2Session.notifyFailure(HTTP2Session.java:1156)
at org.eclipse.jetty.http2.HTTP2Session.abort(HTTP2Session.java:1060)
... 23 common frames omitted
and also getting these crashes
2020-05-20 11:56:04.979 [Connector-Scheduler-74f6c5d8-1] DEBUG org.eclipse.jetty.io.IdleTimeout - SocketChannelEndPoint@1aea799a{/110.54.160.90:41470<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=30000/30000}{io=1/1,kio=1,kro=1}->SslConnection@662a1f2b{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@4724da13{/110.54.160.90:41470<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=540007/30000}=>HTTP2ServerConnection@4fc8491c idle timeout check, elapsed: 30000 ms, remaining: 0 ms
2020-05-20 11:56:04.979 [Connector-Scheduler-74f6c5d8-1] DEBUG org.eclipse.jetty.io.IdleTimeout - SocketChannelEndPoint@1aea799a{/110.54.160.90:41470<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=30000/30000}{io=1/1,kio=1,kro=1}->SslConnection@662a1f2b{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@4724da13{/110.54.160.90:41470<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=540007/30000}=>HTTP2ServerConnection@4fc8491c idle timeout expired
2020-05-20 11:56:04.979 [Connector-Scheduler-74f6c5d8-1] DEBUG o.e.jetty.http2.HTTP2Connection - Ignored idle timeout on HTTP2ServerSession@720ff58e{l:/10.16.0.6:7171 <-> r:/110.54.160.90:41470,sendWindow=16777216,recvWindow=1047530,streams=3,NOT_CLOSED,null}: {}
2020-05-20 11:56:05.049 [Connector-Scheduler-74f6c5d8-1] DEBUG org.eclipse.jetty.io.IdleTimeout - HTTP2Stream@ad94434#11{sendWindow=16777216,recvWindow=524288,reset=false/false,REMOTELY_CLOSED,age=450006,attachment=ServerHttpChannelOverHTTP2@7dbb8795{s=HttpChannelState@6d3b17f6{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WAITING,uri=https://{HOST}:7171/{ENDPOINT}=11335&type=sub,age=450007}#11} idle timeout check, elapsed: 30000 ms, remaining: 0 ms
2020-05-20 11:56:05.049 [Connector-Scheduler-74f6c5d8-1] DEBUG org.eclipse.jetty.io.IdleTimeout - HTTP2Stream@ad94434#11{sendWindow=16777216,recvWindow=524288,reset=false/false,REMOTELY_CLOSED,age=450006,attachment=ServerHttpChannelOverHTTP2@7dbb8795{s=HttpChannelState@6d3b17f6{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WAITING,uri=https://{HOST}:7171/{ENDPOINT}=11335&type=sub,age=450007}#11} idle timeout expired
2020-05-20 11:56:05.049 [Connector-Scheduler-74f6c5d8-1] DEBUG org.eclipse.jetty.http2.HTTP2Stream - Idle timeout 30000ms expired on HTTP2Stream@ad94434#11{sendWindow=16777216,recvWindow=524288,reset=false/false,REMOTELY_CLOSED,age=450006,attachment=ServerHttpChannelOverHTTP2@7dbb8795{s=HttpChannelState@6d3b17f6{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WAITING,uri=https://{HOST}:7171/{ENDPOINT}=11335&type=sub,age=450007}#11}
2020-05-20 11:56:05.049 [Connector-Scheduler-74f6c5d8-1] DEBUG o.e.j.h.s.HttpTransportOverHTTP2 - HTTP2 Response #11/11a5a716 idle timeout ignored
java.util.concurrent.TimeoutException: Idle timeout expired: 30000/30000 ms
at org.eclipse.jetty.io.IdleTimeout.checkIdleTimeout(IdleTimeout.java:171)
at org.eclipse.jetty.io.IdleTimeout.idleCheck(IdleTimeout.java:113)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:304)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:834)
2020-05-20 11:56:05.049 [Connector-Scheduler-74f6c5d8-1] DEBUG o.e.jetty.http2.HTTP2Connection - Ignored idle timeout on HTTP2Stream@ad94434#11{sendWindow=16777216,recvWindow=524288,reset=false/false,REMOTELY_CLOSED,age=450006,attachment=ServerHttpChannelOverHTTP2@7dbb8795{s=HttpChannelState@6d3b17f6{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WAITING,uri=https://{HOST}:7171/{ENDPOINT}=11335&type=sub,age=450007}#11}: {}
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@1530ee6d woken up from select, 1/1/156 selected
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@1530ee6d processing 1 keys, 0 updates
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.ManagedSelector - selected 1 channel=java.nio.channels.SocketChannel[connected local=/10.16.0.6:7171 remote=/194.208.155.11:40676], selector=sun.nio.ch.EPollSelectorImpl@1530ee6d, interestOps=1, readyOps=1 SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}{io=1/1,kio=1,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.ChannelEndPoint - onSelected 1->0 r=true w=false for SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}{io=1/0,kio=1,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.ChannelEndPoint - task CEP:SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}{io=1/0,kio=1,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d:runFillable:EITHER
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG o.e.j.u.t.ReservedThreadExecutor - ReservedThreadExecutor@6a969fb8{s=2/2,p=0} tryExecute EatWhatYouKill@771db12c/SelectorProducer@522ba524/PRODUCING/p=false/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=8,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=2/2,p=0}][pc=9,pic=39,pec=56,epc=12927]@2020-05-20T11:56:05.101877Z
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG o.e.j.u.t.ReservedThreadExecutor - ReservedThreadExecutor@6a969fb8{s=1/2,p=0}@e0a082e offer EatWhatYouKill@771db12c/SelectorProducer@522ba524/PRODUCING/p=false/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=8,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=1/2,p=0}][pc=9,pic=39,pec=56,epc=12927]@2020-05-20T11:56:05.101908Z
2020-05-20 11:56:05.101 [qtp897848096-2890] DEBUG o.e.j.u.t.strategy.EatWhatYouKill - EatWhatYouKill@771db12c/SelectorProducer@522ba524/IDLE/p=true/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=8,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=1/2,p=0}][pc=9,pic=39,pec=56,epc=12927]@2020-05-20T11:56:05.10194Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}{io=1/0,kio=1,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d:runFillable:EITHER/EITHER
2020-05-20 11:56:05.101 [qtp897848096-2875] DEBUG o.e.j.u.t.ReservedThreadExecutor - ReservedThreadExecutor@6a969fb8{s=1/2,p=0}@e0a082e task=EatWhatYouKill@771db12c/SelectorProducer@522ba524/IDLE/p=true/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=8,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=1/2,p=0}][pc=9,pic=39,pec=56,epc=12927]@2020-05-20T11:56:05.101972Z
2020-05-20 11:56:05.102 [qtp897848096-2875] DEBUG o.e.j.u.t.strategy.EatWhatYouKill - EatWhatYouKill@771db12c/SelectorProducer@522ba524/IDLE/p=true/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=8,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=1/2,p=0}][pc=9,pic=39,pec=56,epc=12928]@2020-05-20T11:56:05.102015Z tryProduce true
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.FillInterest - fillable FillInterest@6289cab9{SSLC.NBReadCB@51776ee4{SslConnection@51776ee4::SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}{io=1/0,kio=1,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d}}
2020-05-20 11:56:05.102 [qtp897848096-2875] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 0
2020-05-20 11:56:05.102 [qtp897848096-2875] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - >c.onFillable SslConnection@51776ee4::SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}{io=1/0,kio=1,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.102 [qtp897848096-2875] DEBUG org.eclipse.jetty.io.ChannelEndPoint - Key interests updated 1 -> 0 on SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}{io=0/0,kio=0,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.102 [qtp897848096-2875] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@1530ee6d waiting with 156 keys
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - onFillable SslConnection@51776ee4::SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}{io=0/0,kio=0,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=INTERESTED,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=FI,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.FillInterest - fillable FillInterest@2e4aca68{org.eclipse.jetty.http2.HTTP2Connection$FillableCallback@3c01c9c5}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.HTTP2Connection - HTTP2 onFillable HTTP2ServerConnection@5269686d::DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.HTTP2Connection - HTTP2 produce HTTP2ServerConnection@5269686d::DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.j.u.t.strategy.EatWhatYouKill - EatWhatYouKill@3c801a15/HTTP2Producer@a602086/IDLE/p=false/QueuedThreadPool[qtp897848096]@35841320{STARTED,8<=12<=200,i=8,r=2,q=0}[ReservedThreadExecutor@6a969fb8{s=1/2,p=0}][pc=0,pic=0,pec=0,epc=3]@2020-05-20T11:56:05.102181Z tryProduce false
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.HTTP2Connection - Dequeued task null
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.HTTP2Connection - Acquired NetworkBuffer@2e9c5b61{HeapByteBuffer@7e4d63f9[p=0,l=0,c=17408,r=0]={<<<>>>\x00\x00"\x01\x05\x00\x00\x00\x0b...\x00\x00\x00\x00\x00\x00\x00},r=1}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - >fill SslConnection@51776ee4::SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}{io=0/0,kio=0,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - fill NOT_HANDSHAKING
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG org.eclipse.jetty.io.ChannelEndPoint - filled 42 HeapByteBuffer@7f14d7ed[p=0,l=42,c=17408,r=42]={<<<\x17\x03\x03\x00%\x00\x00\x00\x00\x00\x00\x00\x08\x17i0\x0f\x02\xB2\x9ac\xD0U99\xDa-q\xFaXT\x07\x90R2\x9c\x13\xE720\x10E>>>\xCe\xC4~ez\x0b\x93\xDa\xAb...\x00\x00\x00\x00\x00\x00\x00}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - net filled=42
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - unwrap net_filled=42 Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 42 bytesProduced = 13 encryptedBuffer=[p=42,l=42,c=17408,r=0] unwrapBuffer=HeapByteBuffer@7e4d63f9[p=0,l=13,c=17408,r=13]={<<<\x00\x00\x04\x03\x00\x00\x00\x00\x03\x00\x00\x00\x08>>>\x93\xC6j\n\xC0\xEb\xAd\x89\x8a...\x00\x00\x00\x00\x00\x00\x00} appBuffer=HeapByteBuffer@7e4d63f9[p=0,l=13,c=17408,r=13]={<<<\x00\x00\x04\x03\x00\x00\x00\x00\x03\x00\x00\x00\x08>>>\x93\xC6j\n\xC0\xEb\xAd\x89\x8a...\x00\x00\x00\x00\x00\x00\x00}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.io.ssl.SslConnection - <fill f=13 uf=false SslConnection@51776ee4::SocketChannelEndPoint@6a358a13{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->SslConnection@51776ee4{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@345f0a02{/194.208.155.11:40676<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=589/30000}=>HTTP2ServerConnection@5269686d
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.HTTP2Connection - Filled 13 bytes in NetworkBuffer@2e9c5b61{HeapByteBuffer@7e4d63f9[p=0,l=13,c=17408,r=13]={<<<\x00\x00\x04\x03\x00\x00\x00\x00\x03\x00\x00\x00\x08>>>\x93\xC6j\n\xC0\xEb\xAd\x89\x8a...\x00\x00\x00\x00\x00\x00\x00},r=1}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.parser.ServerParser - Parsing java.nio.HeapByteBuffer[pos=0 lim=13 cap=17408]
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.eclipse.jetty.http2.parser.Parser - Parsed [RST_STREAM|4|0|3] frame header from java.nio.HeapByteBuffer[pos=9 lim=13 cap=17408]
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG org.eclipse.jetty.http2.HTTP2Session - Received ResetFrame@6859fe12#3{cancel_stream_error}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG org.eclipse.jetty.http2.HTTP2Session - Removed remote HTTP2Stream@728ac07f#3{sendWindow=16777216,recvWindow=524288,reset=false/true,CLOSED,age=324671,attachment=ServerHttpChannelOverHTTP2@7f28ff8d{s=HttpChannelState@3a9673c7{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WAITING,uri=https://{HOST}:7171/{ENDPOINT}=1633&type=sub,age=324672}#3}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.jetty.http2.HTTP2Connection - Processing failure on HTTP2Stream@728ac07f#3{sendWindow=16777216,recvWindow=524288,reset=false/true,CLOSED,age=324672,attachment=ServerHttpChannelOverHTTP2@7f28ff8d{s=HttpChannelState@3a9673c7{s=WAITING rs=ASYNC os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=WAITING,uri=https://{HOST}:7171/{ENDPOINT}=1633&type=sub,age=324672}#3}: {}
2020-05-20 11:56:05.102 [qtp897848096-2890] DEBUG o.e.j.h.s.HttpTransportOverHTTP2 - HTTP2 Response #3/724f0d35 flush ignored
org.eclipse.jetty.io.EofException: Reset cancel_stream_error
at org.eclipse.jetty.http2.server.HTTP2ServerConnectionFactory$HTTPServerSessionListener.onReset(HTTP2ServerConnectionFactory.java:157)
at org.eclipse.jetty.http2.HTTP2Stream.notifyReset(HTTP2Stream.java:574)
at org.eclipse.jetty.http2.HTTP2Stream.onReset(HTTP2Stream.java:343)
at org.eclipse.jetty.http2.HTTP2Stream.process(HTTP2Stream.java:252)
at org.eclipse.jetty.http2.HTTP2Session.onReset(HTTP2Session.java:295)
at org.eclipse.jetty.http2.parser.Parser$Listener$Wrapper.onReset(Parser.java:372)
at org.eclipse.jetty.http2.parser.BodyParser.notifyReset(BodyParser.java:144)
at org.eclipse.jetty.http2.parser.ResetBodyParser.onReset(ResetBodyParser.java:97)
at org.eclipse.jetty.http2.parser.ResetBodyParser.parse(ResetBodyParser.java:66)
at org.eclipse.jetty.http2.parser.Parser.parseBody(Parser.java:198)
at org.eclipse.jetty.http2.parser.Parser.parse(Parser.java:127)
at org.eclipse.jetty.http2.parser.ServerParser.parse(ServerParser.java:115)
at org.eclipse.jetty.http2.HTTP2Connection$HTTP2Producer.produce(HTTP2Connection.java:248)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produceTask(EatWhatYouKill.java:360)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:184)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
at org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:170)
at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:125)
at org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:348)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.onFillable(SslConnection.java:543)
at org.eclipse.jetty.io.ssl.SslConnection.onFillable(SslConnection.java:398)
at org.eclipse.jetty.io.ssl.SslConnection$2.succeeded(SslConnection.java:161)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:117)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:388)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:806)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:938)
at java.base/java.lang.Thread.run(Thread.java:834)
and this too
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG org.eclipse.jetty.http2.HTTP2Session - Disconnecting HTTP2ServerSession@1a9813fd{l:/10.16.0.6:7171 <-> r:/152.32.102.11:43890,sendWindow=16777216,recvWindow=1048437,streams=0,CLOSED,null}
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.AbstractEndPoint - close DecryptedEndPoint@1456064f{/152.32.102.11:43890<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=115/30000}
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.AbstractEndPoint - close(null) DecryptedEndPoint@1456064f{/152.32.102.11:43890<->/10.16.0.6:7171,OPEN,fill=-,flush=-,to=115/30000}
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.ssl.SslConnection - shutdownOutput: SslConnection@4d317d32::SocketChannelEndPoint@31397a33{/152.32.102.11:43890<->/10.16.0.6:7171,ISHUT,fill=-,flush=-,to=115/30000}{io=1/0,kio=1,kro=1}->SslConnection@4d317d32{NOT_HANDSHAKING,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@1456064f{/152.32.102.11:43890<->/10.16.0.6:7171,CLOSED,fill=-,flush=-,to=115/30000}=>HTTP2ServerConnection@7ebcadd4 oshut=false, ishut=true
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.ssl.SslConnection - >flush SslConnection@4d317d32::SocketChannelEndPoint@31397a33{/152.32.102.11:43890<->/10.16.0.6:7171,ISHUT,fill=-,flush=-,to=115/30000}{io=1/0,kio=1,kro=1}->SslConnection@4d317d32{NEED_WRAP,eio=-1/-1,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@1456064f{/152.32.102.11:43890<->/10.16.0.6:7171,CLOSED,fill=-,flush=-,to=115/30000}=>HTTP2ServerConnection@7ebcadd4
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.ssl.SslConnection - flush b[0]=HeapByteBuffer@17a64e32[p=0,l=0,c=0,r=0]={<<<>>>}
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.ssl.SslConnection - flush NEED_WRAP
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.ssl.SslConnection - wrap Status = CLOSED HandshakeStatus = NEED_UNWRAP bytesConsumed = 0 bytesProduced = 31 sequenceNumber = 3 [p=0,l=31,c=17408,r=31] ioDone=false/true
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG org.eclipse.jetty.io.ChannelEndPoint - flushed 31 SocketChannelEndPoint@31397a33{/152.32.102.11:43890<->/10.16.0.6:7171,ISHUT,fill=-,flush=-,to=115/30000}{io=1/0,kio=1,kro=1}->SslConnection@4d317d32{NEED_UNWRAP,eio=-1/0,di=-1,fill=IDLE,flush=IDLE}~>DecryptedEndPoint@1456064f{/152.32.102.11:43890<->/10.16.0.6:7171,CLOSED,fill=-,flush=-,to=115/30000}=>HTTP2ServerConnection@7ebcadd4
2020-05-20 11:56:10.528 [qtp897848096-2877] DEBUG o.eclipse.jetty.io.ssl.SslConnection - net flushed=true, ac=true
2020-05-20 11:56:10.528 [qtp897848096-2875] DEBUG org.eclipse.jetty.io.WriteFlusher - ignored: WriteFlusher@2fa70bfd{IDLE}->null
java.nio.channels.ClosedChannelException: null
at org.eclipse.jetty.io.WriteFlusher.onClose(WriteFlusher.java:521)
at org.eclipse.jetty.io.AbstractEndPoint.onClose(AbstractEndPoint.java:354)
at org.eclipse.jetty.io.ChannelEndPoint.onClose(ChannelEndPoint.java:214)
at org.eclipse.jetty.io.AbstractEndPoint.doOnClose(AbstractEndPoint.java:225)
at org.eclipse.jetty.io.AbstractEndPoint.shutdownOutput(AbstractEndPoint.java:157)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.flush(SslConnection.java:1081)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.doShutdownOutput(SslConnection.java:1278)
at org.eclipse.jetty.io.ssl.SslConnection$DecryptedEndPoint.doClose(SslConnection.java:1343)
at org.eclipse.jetty.io.AbstractEndPoint.doOnClose(AbstractEndPoint.java:220)
at org.eclipse.jetty.io.AbstractEndPoint.close(AbstractEndPoint.java:192)
at org.eclipse.jetty.io.AbstractEndPoint.close(AbstractEndPoint.java:175)
at org.eclipse.jetty.http2.HTTP2Session.disconnect(HTTP2Session.java:1023)
at org.eclipse.jetty.http2.HTTP2Session.terminate(HTTP2Session.java:1045)
at org.eclipse.jetty.http2.HTTP2Session.access$1200(HTTP2Session.java:72)
at org.eclipse.jetty.http2.HTTP2Session$TerminateCallback.complete(HTTP2Session.java:1647)
at org.eclipse.jetty.http2.HTTP2Session$TerminateCallback.succeeded(HTTP2Session.java:1628)
at org.eclipse.jetty.util.Callback$Nested.succeeded(Callback.java:266)
at org.eclipse.jetty.util.CountingCallback.succeeded(CountingCallback.java:68)
at org.eclipse.jetty.http2.server.HttpChannelOverHTTP2$FailureTask.run(HttpChannelOverHTTP2.java:407)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.produce(EatWhatYouKill.java:135)
at org.eclipse.jetty.http2.HTTP2Connection.produce(HTTP2Connection.java:170)
at org.eclipse.jetty.http2.HTTP2Connection.onFillable(HTTP2Connection.java:125)
at org.eclipse.jetty.http2.HTTP2Connection$FillableCallback.succeeded(HTTP2Connection.java:348)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103)
Upvotes: 0
Views: 882
Answers (1)
sbordet
Reputation: 18597
These are DEBUG logs, so you may find logged there exceptions that are not "crashes" but just logging what happened in the implementation.
The first and third exceptions reported are a TLS problem, but since the log is incomplete (lacks what happens before the channel is closed), it's difficult to tell what's going on.
A common problem is that the client does not connect with a sufficiently strong cipher, and the server rejects the connection as required by HTTP/2.
I would review what the client sends (what TLS protocol version, what cipher, etc.) and modern clients should work fine.
Upvotes: 0
Related Questions
- Strange exception using Jersey with embedded Jetty
- How to enable http/2 on an embedded Jetty 10?
- Instrument Jetty HttpClient for Http2
- IllegalStateException in HttpChannel.handle in Jetty
- Webapp with embedded jetty giving exception
- How to avoid a java.lang.ExceptionInInitializerError when trying to run a Ktor app via an embedded Jetty server?
- Jetty client can't connect to Jetty server via HTTP/2
- Enable HTTP2 with maven-jetty-plugin
- Embedded Jetty HTTP/2 not working with Firefox/Chrome but seems ok with Safari
- java.util.concurrent.RejectedExecutionException: org.eclipse.jetty.client.HttpClient