Jetty version 9.4.33.v20201020
Java version 1.8
OS type/version Redhat 7.4
Description
I am seeing intermittent occurrences of connection loss from the server
It is not often but we haven't seen this issue when using the 9.2.x version before the upgrade
From the client we see
KeepAliveFailure The underlying connection was closed: A connection that was expected to be kept alive was closed by the server.
With the jetty debug logs enabled, it looks like jetty is aborting the connection due to a IOException: unconsumed input
It is not always reproducible.
Wanted insight from the jetty team to help determine the cause and how to avoid
Below is a snippet of the debug logs which captures the failing request
Any help is appreciated
21380: Selector sun.nio.ch.EPollSelectorImpl@70e457b woken with none selected
2020-11-05 22:26:54.151:DBUG:oeji.ManagedSelector:qtp1378318626-21380: Selector sun.nio.ch.EPollSelectorImpl@70e457b woken up from select, 0/0/1 selected
2020-11-05 22:26:54.151:DBUG:oejs.HttpConnection:qtp1378318626-16923: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0} onFillable exit HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:26:54.151:DBUG:oeji.ManagedSelector:qtp1378318626-21380: Selector sun.nio.ch.EPollSelectorImpl@70e457b processing 0 keys, 1 updates
2020-11-05 22:26:54.151:DBUG:oeji.ManagedSelector:qtp1378318626-21380: updateable 1
2020-11-05 22:26:54.151:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-16923: ReservedThreadExecutor@629db94d{s=3/20,p=0}@5ddf9d34 waiting
2020-11-05 22:26:54.151:DBUG:oeji.ManagedSelector:qtp1378318626-21380: update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@eaa5af3
2020-11-05 22:26:54.151:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: Key interests updated 0 -> 1 on SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=0/30000}{io=1/1,kio=1,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:54.151:DBUG:oeji.ManagedSelector:qtp1378318626-21380: updates 0
2020-11-05 22:26:54.151:DBUG:oeji.ManagedSelector:qtp1378318626-21380: Selector sun.nio.ch.EPollSelectorImpl@70e457b waiting with 1 keys
2020-11-05 22:26:54.172:DBUG:oeji.ManagedSelector:qtp1378318626-21380: Selector sun.nio.ch.EPollSelectorImpl@70e457b woken up from select, 1/1/1 selected
2020-11-05 22:26:54.172:DBUG:oeji.ManagedSelector:qtp1378318626-21380: Selector sun.nio.ch.EPollSelectorImpl@70e457b processing 1 keys, 0 updates
2020-11-05 22:26:54.172:DBUG:oeji.ManagedSelector:qtp1378318626-21380: selected 1 sun.nio.ch.SelectionKeyImpl@749cb8f1 SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=21/30000}{io=1/1,kio=1,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:54.172:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: onSelected 1->0 r=true w=false for SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=21/30000}{io=1/0,kio=1,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:54.172:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: task CEP:SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=21/30000}{io=1/0,kio=1,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
2020-11-05 22:26:54.172:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-21380: ReservedThreadExecutor@629db94d{s=3/20,p=0} tryExecute EatWhatYouKill@3e0218ef/SelectorProducer@3e0218eb/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=3/20,p=0}][pc=235,pic=0,pec=6,epc=775]@2020-11-05T22:26:54.172996062Z
2020-11-05 22:26:54.173:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-21380: ReservedThreadExecutor@629db94d{s=2/20,p=0}@5ddf9d34 offer EatWhatYouKill@3e0218ef/SelectorProducer@3e0218eb/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=2/20,p=0}][pc=235,pic=0,pec=6,epc=775]@2020-11-05T22:26:54.173049559Z
2020-11-05 22:26:54.173:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-16923: ReservedThreadExecutor@629db94d{s=2/20,p=0}@5ddf9d34 task=EatWhatYouKill@3e0218ef/SelectorProducer@3e0218eb/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=2/20,p=0}][pc=235,pic=0,pec=6,epc=775]@2020-11-05T22:26:54.173155782Z
2020-11-05 22:26:54.173:DBUG:oejuts.EatWhatYouKill:qtp1378318626-21380: EatWhatYouKill@3e0218ef/SelectorProducer@3e0218eb/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=2/20,p=0}][pc=235,pic=0,pec=6,epc=775]@2020-11-05T22:26:54.173103891Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=22/30000}{io=1/0,kio=1,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING
2020-11-05 22:26:54.173:DBUG:oejuts.EatWhatYouKill:qtp1378318626-16923: EatWhatYouKill@3e0218ef/SelectorProducer@3e0218eb/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=2/20,p=0}][pc=235,pic=0,pec=6,epc=776]@2020-11-05T22:26:54.17321245Z tryProduce true
2020-11-05 22:26:54.173:DBUG:oeji.ManagedSelector:qtp1378318626-16923: updateable 0
2020-11-05 22:26:54.173:DBUG:oeji.ManagedSelector:qtp1378318626-16923: updates 0
2020-11-05 22:26:54.173:DBUG:oeji.FillInterest:qtp1378318626-21380: fillable FillInterest@eaa5afe{AC.ReadCB@eaa5362{HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=22/30000}{io=1/0,kio=1,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:26:54.173:DBUG:oeji.ChannelEndPoint:qtp1378318626-16923: Key interests updated 1 -> 0 on SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=FI,flush=-,to=22/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:54.173:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=22/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0} onFillable enter HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:26:54.173:DBUG:oeji.ManagedSelector:qtp1378318626-16923: Selector sun.nio.ch.EPollSelectorImpl@70e457b waiting with 1 keys
2020-11-05 22:26:54.173:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1:2187630],\n[Hierarchie>>>}
2020-11-05 22:26:54.173:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0} filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1:2187630],\n[Hierarchie>>>}
2020-11-05 22:26:54.173:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=START,0 of -1},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=4,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1:2187630],\n[Hierarchie>>>} {}
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: parseNext s=START HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1:2187630],\n[Hierarchie>>>}
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: START --> SPACE1
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: SPACE1 --> URI
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: URI --> SPACE2
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: SPACE2 --> REQUEST_VERSION
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: REQUEST_VERSION --> HEADER
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; MS Web Services Client Protocol 4.0.30319.36627) --> IN_VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; MS Web Services Client Protocol 4.0.30319.36627) --> FIELD
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Content-Type: text/xml; charset=UTF-8 --> IN_VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Content-Type: text/xml; charset=UTF-8 --> FIELD
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER: --> IN_NAME
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:SOAPAction --> VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:SOAPAction --> IN_VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:SOAPAction --> FIELD
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Host: hostnameA:8082 --> IN_VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Host: hostnameA:8082 --> FIELD
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Content-Length --> VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Content-Length --> IN_VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Content-Length --> FIELD
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Accept-Encoding: gzip --> IN_VALUE
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER:Accept-Encoding: gzip --> FIELD
2020-11-05 22:26:54.173:DBUG:oejh.HttpParser:qtp1378318626-21380: HEADER --> CONTENT
2020-11-05 22:26:54.173:DBUG:oejs.HttpChannel:qtp1378318626-21380: REQUEST for //hostnameA:8082/application/webservices/Queries on HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0}
POST //hostnameA:8082/application/webservices/Queries HTTP/1.1
User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; MS Web Services Client Protocol 4.0.30319.36627)
Content-Type: text/xml; charset=UTF-8
SOAPAction: ""
Host: hostnameA:8082
Content-Length: 14781
Accept-Encoding: gzip
2020-11-05 22:26:54.173:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0} parsed true HttpParser{s=CONTENT,0 of 14781}
2020-11-05 22:26:54.173:DBUG:oejs.HttpChannel:qtp1378318626-21380: handle //hostnameA:8082/application/webservices/Queries HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:26:54.173:DBUG:oejs.HttpChannelState:qtp1378318626-21380: handling HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:26:54.173:DBUG:oejs.HttpChannel:qtp1378318626-21380: action DISPATCH HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:26:54.173:DBUG:oejs.Server:qtp1378318626-21380: REQUEST POST /application/webservices/Queries on HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:26:54.173:DBUG:oejsh.ContextHandler:qtp1378318626-21380: scope ||/application/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application-app/temp/jetty-0_0_0_0-8082-application-app-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application-app/lib/application-app-1.2.1-20201023_205439.war}
2020-11-05 22:26:54.173:DBUG:oejsh.ContextHandler:qtp1378318626-21380: context=/application||/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application-app/temp/jetty-0_0_0_0-8082-application-app-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application-app/lib/application-app-1.2.1-20201023_205439.war}
2020-11-05 22:26:54.173:DBUG:oejs.session:qtp1378318626-21380: Entering scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800, dispatch=REQUEST asyncstarted=false
2020-11-05 22:26:54.173:DBUG:oejs.session:qtp1378318626-21380: sessionHandler=org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 session=
2020-11-05 22:26:54.174:DBUG:oejs.ServletHandler:qtp1378318626-21380: servlet /application||/webservices/Queries -> springDispatcherServlet@abe94f11==org.springframework.web.servlet.DispatcherServlet,jsp=null,order=1,inst=true,async=false
2020-11-05 22:26:54.174:DBUG:oejs.ServletHandler:qtp1378318626-21380: chain=Chain@4ed594f6(springSecurityFilterChain@5d5577f3==org.springframework.web.filter.DelegatingFilterProxy,inst=true,async=false)->ChainEnd@4ed594f4(springDispatcherServlet@abe94f11==org.springframework.web.servlet.DispatcherServlet,jsp=null,order=1,inst=true,async=false)
2020-11-05 22:26:54.174:DBUG:oejs.session:qtp1378318626-21380: Creating new session id=node0val0bgye9f3z1ex6wtbo2fpo010270
2020-11-05 22:26:54.174:DBUG:oejs.session:qtp1378318626-21380: Session node0val0bgye9f3z1ex6wtbo2fpo010270 in use, stopping timer, active requests=1
2020-11-05 22:26:54.174:DBUG:oejs.session:qtp1378318626-21380: Cancelled timer for session node0val0bgye9f3z1ex6wtbo2fpo010270
2020-11-05 22:26:54.174:DBUG:oejs.Request:qtp1378318626-21380: Request Request(POST //hostnameA:8082/application/webservices/Queries)@eaa53e6 entering session=Session@2677f78e{id=node0val0bgye9f3z1ex6wtbo2fpo010270,x=node0val0bgye9f3z1ex6wtbo2fpo010270.node0,req=1,res=true}
2020-11-05 22:26:54.174:DBUG:oejh.HttpCookie:qtp1378318626-21380: No default value for SameSite
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannelState:qtp1378318626-21380: sendError HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:26:54.174:DBUG:oejs.session:qtp1378318626-21380: Leaving scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 dispatch=REQUEST, async=false, session=Session@2677f78e{id=node0val0bgye9f3z1ex6wtbo2fpo010270,x=node0val0bgye9f3z1ex6wtbo2fpo010270.node0,req=1,res=true}, oldsession=, oldsessionhandler=
2020-11-05 22:26:54.174:DBUG:oejs.Server:qtp1378318626-21380: handled=true async=false committed=true on HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=true i=true al=0},r=5,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannelState:qtp1378318626-21380: unhandle HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=true i=true al=0}
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannelState:qtp1378318626-21380: nextAction(false) SEND_ERROR HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannel:qtp1378318626-21380: action SEND_ERROR HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0},r=5,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:26:54.174:DBUG:oejs.ErrorPageErrorHandler:qtp1378318626-21380: getErrorPage(POST /application/webservices/Queries) => error_page=null (from global default)
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannelState:qtp1378318626-21380: completing HttpChannelState@eaa53ec{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannel:qtp1378318626-21380: sendResponse info= content=DirectByteBuffer@fbcfc13[p=0,l=496,c=32768,r=496]={<<<<html>\n<head>\n<meta http-...<hr/>\n\n</body>\n</html>\n>>>evelPerHi...alue xs} complete=true committing=true callback=org.eclipse.jetty.util.Callback$3@267627b7
2020-11-05 22:26:54.174:DBUG:oejs.HttpChannel:qtp1378318626-21380: COMMIT for /application/webservices/Queries on HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=5,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
401 HTTP/1.1
Set-Cookie: JSESSIONID=node0val0bgye9f3z1ex6wtbo2fpo010270.node0; Path=/application
WWW-Authenticate: Basic realm="Realm"
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Frame-Options: DENY
Cache-Control: must-revalidate,no-cache,no-store
Content-Type: text/html;charset=iso-8859-1
2020-11-05 22:26:54.174:DBUG:oejs.Request:qtp1378318626-21380: Response Request[POST //hostnameA:8082/application/webservices/Queries]@eaa53e6 committing for session Session@2677f78e{id=node0val0bgye9f3z1ex6wtbo2fpo010270,x=node0val0bgye9f3z1ex6wtbo2fpo010270.node0,req=1,res=true}
2020-11-05 22:26:54.174:DBUG:oejs.HttpConnection:qtp1378318626-21380: generate: NEED_HEADER for org.eclipse.jetty.server.HttpConnection$SendCallback@eaa5394[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@26763053] (null,[p=0,l=496,c=32768,r=496],true)@START
2020-11-05 22:26:54.174:DBUG:oejh.HttpGenerator:qtp1378318626-21380: generateHeaders HTTP/1.1{s=401,h=7,cl=-1} last=true content=DirectByteBuffer@fbcfc13[p=0,l=496,c=32768,r=496]={<<<<html>\n<head>\n<meta http-...<hr/>\n\n</body>\n</html>\n>>>evelPerHi...alue xs}
2020-11-05 22:26:54.174:DBUG:oejh.HttpGenerator:qtp1378318626-21380: Set-Cookie: JSESSIONID=node0val0bgye9f3z1ex6wtbo2fpo010270.node0; Path=/application<|WWW-Authenticate: Basic realm="Realm"<|X-Content-Type-Options: nosniff<|X-XSS-Protection: 1; mode=block<|X-Frame-Options: DENY<|Cache-Control: must-revalidate,no-cache,no-store<|Content-Type: text/html;charset=iso-8859-1<|<|
2020-11-05 22:26:54.174:DBUG:oejh.HttpGenerator:qtp1378318626-21380: CONTENT_LENGTH
2020-11-05 22:26:54.174:DBUG:oejs.HttpConnection:qtp1378318626-21380: generate: FLUSH for org.eclipse.jetty.server.HttpConnection$SendCallback@eaa5394[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@26763053] ([p=0,l=386,c=8192,r=386],[p=0,l=496,c=32768,r=496],true)@COMPLETING
2020-11-05 22:26:54.174:DBUG:oeji.WriteFlusher:qtp1378318626-21380: write: WriteFlusher@eaa5af5{IDLE}->null [HeapByteBuffer@711c6a74[p=0,l=386,c=8192,r=386]={<<<HTTP/1.1 401 Unauthorized...y(9.4.33.v20201020)\r\n\r\n>>>\nl versio...; EMERG},DirectByteBuffer@fbcfc13[p=0,l=496,c=32768,r=496]={<<<<html>\n<head>\n<meta http-...<hr/>\n\n</body>\n</html>\n>>>evelPerHi...alue xs}]
2020-11-05 22:26:54.174:DBUG:oeji.WriteFlusher:qtp1378318626-21380: update WriteFlusher@eaa5af5{WRITING}->null:IDLE-->WRITING
2020-11-05 22:26:54.174:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: flushed 882 SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=W,to=1/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@eaa53b5{s=COMPLETING}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=5,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:26:54.174:DBUG:oeji.WriteFlusher:qtp1378318626-21380: Flushed=true written=882 remaining=0 WriteFlusher@eaa5af5{WRITING}->null
2020-11-05 22:26:54.174:DBUG:oeji.WriteFlusher:qtp1378318626-21380: update WriteFlusher@eaa5af5{IDLE}->null:WRITING-->IDLE
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: generate: DONE for org.eclipse.jetty.server.HttpConnection$SendCallback@eaa5394[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@26763053] ([p=386,l=386,c=8192,r=0],[p=496,l=496,c=32768,r=0],true)@END
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannelState:qtp1378318626-21380: completed HttpChannelState@eaa53ec{s=HANDLING rs=COMPLETING os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannelState:qtp1378318626-21380: unhandle HttpChannelState@eaa53ec{s=HANDLING rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannelState:qtp1378318626-21380: nextAction(false) TERMINATED HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannel:qtp1378318626-21380: action TERMINATED HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannel:qtp1378318626-21380: onCompleted for /application/webservices/Queries written=496
2020-11-05 22:26:54.175:DBUG:oejs.Request:qtp1378318626-21380: Request Request[POST //hostnameA:8082/application/webservices/Queries]@eaa53e6 leaving session Session@2677f78e{id=node0val0bgye9f3z1ex6wtbo2fpo010270,x=node0val0bgye9f3z1ex6wtbo2fpo010270.node0,req=1,res=true}
2020-11-05 22:26:54.175:DBUG:oejs.session:qtp1378318626-21380: Complete called with session Session@2677f78e{id=node0val0bgye9f3z1ex6wtbo2fpo010270,x=node0val0bgye9f3z1ex6wtbo2fpo010270.node0,req=1,res=true}
2020-11-05 22:26:54.175:DBUG:oejs.session:qtp1378318626-21380: Session node0val0bgye9f3z1ex6wtbo2fpo010270 complete, active requests=0
2020-11-05 22:26:54.175:DBUG:oejs.session:qtp1378318626-21380: Session node0val0bgye9f3z1ex6wtbo2fpo010270 no eviction
2020-11-05 22:26:54.175:DBUG:oejs.session:qtp1378318626-21380: (Re)starting timer for session node0val0bgye9f3z1ex6wtbo2fpo010270 at 1800000ms
2020-11-05 22:26:54.175:DBUG:oeji.CyclicTimeout:qtp1378318626-21380: Installed timeout in 1800000 ms, waking up in 1800000 ms
2020-11-05 22:26:54.175:DBUG:oejs.session:qtp1378318626-21380: Store: id=node0val0bgye9f3z1ex6wtbo2fpo010270, mdirty=true, dirty=true, lsave=0, period=0, elapsed=1604615214175
2020-11-05 22:26:54.175:DBUG:oejs.session:qtp1378318626-21380: Non passivating SessionDataStore, session in SessionCache only id=node0val0bgye9f3z1ex6wtbo2fpo010270
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parse HeapByteBuffer@6b49cc31[p=279,l=8192,c=8192,r=7913]={POST /pro...zip\r\n\r\n<<<<?xml version="1.0" encod...1:2187630],\n[Hierarchie>>>} {}
2020-11-05 22:26:54.175:DBUG:oejh.HttpParser:qtp1378318626-21380: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=279,l=8192,c=8192,r=7913]={POST /pro...zip\r\n\r\n<<<<?xml version="1.0" encod...1:2187630],\n[Hierarchie>>>}
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannel:qtp1378318626-21380: onContent HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} Content@2676aaaf{HeapByteBufferR@2676aaa9[p=279,l=8192,c=8192,r=7913]={POST /pro...zip\r\n\r\n<<<<?xml version="1.0" encod...1:2187630],\n[Hierarchie>>>}}
2020-11-05 22:26:54.175:DBUG:oejs.HttpInput:qtp1378318626-21380: HttpInputOverHTTP@eaa5203[c=0,q=0,[0]=null,s=STREAM] addContent Content@2676aaaf{HeapByteBufferR@2676aaa9[p=279,l=8192,c=8192,r=7913]={POST /pro...zip\r\n\r\n<<<<?xml version="1.0" encod...1:2187630],\n[Hierarchie>>>}}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,7913 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parsed false HttpParser{s=CONTENT,7913 of 14781}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: unconsumed input HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,7913 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: releaseRequestBuffer HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,7913 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:54.175:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: filled 5227 HeapByteBuffer@6b49cc31[p=0,l=5227,c=8192,r=5227]={<<<s].[Global FX].[ALL].[All...NodeA>>>AllMember...rarchie}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,7913 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} filled 5227 HeapByteBuffer@6b49cc31[p=0,l=5227,c=8192,r=5227]={<<<s].[Global FX].[ALL].[All...NodeA>>>AllMember...rarchie}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,7913 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parse HeapByteBuffer@6b49cc31[p=0,l=5227,c=8192,r=5227]={<<<s].[Global FX].[ALL].[All...NodeA>>>AllMember...rarchie} {}
2020-11-05 22:26:54.175:DBUG:oejh.HttpParser:qtp1378318626-21380: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=0,l=5227,c=8192,r=5227]={<<<s].[Global FX].[ALL].[All...NodeA>>>AllMember...rarchie}
2020-11-05 22:26:54.175:DBUG:oejs.HttpChannel:qtp1378318626-21380: onContent HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} Content@2676d903{HeapByteBufferR@2676d90d[p=0,l=5227,c=8192,r=5227]={<<<s].[Global FX].[ALL].[All...NodeA>>>AllMember...rarchie}}
2020-11-05 22:26:54.175:DBUG:oejs.HttpInput:qtp1378318626-21380: HttpInputOverHTTP@eaa5203[c=7913,q=0,[0]=null,s=STREAM] addContent Content@2676d903{HeapByteBufferR@2676d90d[p=0,l=5227,c=8192,r=5227]={<<<s].[Global FX].[ALL].[All...NodeA>>>AllMember...rarchie}}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parsed false HttpParser{s=CONTENT,13140 of 14781}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: releaseRequestBuffer HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:54.175:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:26:54.175:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parse HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie} {}
2020-11-05 22:26:54.175:DBUG:oejh.HttpParser:qtp1378318626-21380: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parsed false HttpParser{s=CONTENT,13140 of 14781}
2020-11-05 22:26:54.175:DBUG:oejs.HttpConnection:qtp1378318626-21380: releaseRequestBuffer HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=5,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:54.176:DBUG:oejs.HttpConnection:qtp1378318626-21380: abort HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=ABORTED is=IDLE awp=false se=false i=false al=0},r=5,c=true/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3} {}
java.io.IOException: unconsumed input
at org.eclipse.jetty.server.HttpConnection.onCompleted(HttpConnection.java:430)
at org.eclipse.jetty.server.HttpChannel.onCompleted(HttpChannel.java:743)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:363)
at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
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:375)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
at java.lang.Thread.run(Thread.java:748)
2020-11-05 22:26:54.176:DBUG:oeji.AbstractEndPoint:qtp1378318626-21380: close SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=ABORTED is=IDLE awp=false se=false i=false al=0},r=5,c=true/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:54.176:DBUG:oeji.AbstractEndPoint:qtp1378318626-21380: close() SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=ABORTED is=IDLE awp=false se=false i=false al=0},r=5,c=true/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:54.176:DBUG:oeji.ChannelEndPoint:qtp1378318626-21380: doClose SocketChannelEndPoint@eaa5ad1{l=/hostnameA_IP:8082,r=/clientA_IP:51419,CLOSED,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@eaa5362[p=HttpParser{s=CONTENT,13140 of 14781},g=HttpGenerator@eaa53b5{s=END}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=ABORTED is=IDLE awp=false se=false i=false al=0},r=5,c=true/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:54.176:DBUG:oeji.FillInterest:qtp1378318626-21380: onClose FillInterest@eaa5afe{null}
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-21380: Wakeup ManagedSelector@3e021b44{STARTED} id=3 keys=1 selected=0 updates=0
2020-11-05 22:26:54.176:DBUG:oejut.QueuedThreadPool:qtp1378318626-21380: queue org.eclipse.jetty.io.ManagedSelector$DestroyEndPoint@2e7e33f1 startThread=0
2020-11-05 22:26:54.176:DBUG:oejs.HttpChannelState:qtp1378318626-21380: recycle HttpChannelState@eaa53ec{s=IDLE rs=COMPLETED os=ABORTED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-16923: Selector sun.nio.ch.EPollSelectorImpl@70e457b woken with none selected
2020-11-05 22:26:54.176:DBUG:oejh.HttpParser:qtp1378318626-21380: close HttpParser{s=CONTENT,13140 of 14781}
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-16923: Selector sun.nio.ch.EPollSelectorImpl@70e457b woken up from select, 0/0/0 selected
2020-11-05 22:26:54.176:DBUG:oejh.HttpParser:qtp1378318626-21380: CONTENT --> CLOSE
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-16923: Selector sun.nio.ch.EPollSelectorImpl@70e457b processing 0 keys, 0 updates
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-16923: updateable 0
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-16923: updates 0
2020-11-05 22:26:54.176:DBUG:oejs.HttpChannel:qtp1378318626-21380: !handle TERMINATED HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:54.176:DBUG:oejut.QueuedThreadPool:qtp1378318626-20348: run org.eclipse.jetty.io.ManagedSelector$DestroyEndPoint@2e7e33f1 in QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=2/20,p=0}]
2020-11-05 22:26:54.176:DBUG:oeji.ManagedSelector:qtp1378318626-16923: Selector sun.nio.ch.EPollSelectorImpl@70e457b waiting with 0 keys
2020-11-05 22:26:54.176:DBUG:oejs.HttpConnection:qtp1378318626-21380: HttpConnection@eaa5362::SocketChannelEndPoint@eaa5ad1{l=0.0.0.0/0.0.0.0:8082,r=null,CLOSED,fill=-,flush=-,to=1/30000}{io=0/0,kio=-1,kro=-1}->HttpConnection@eaa5362[p=HttpParser{s=CLOSE,13140 of 14781},g=HttpGenerator@eaa53b5{s=START}]=>HttpChannelOverHttp@eaa53b2{s=HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=5,c=false/false,a=IDLE,uri=null,age=0} onFillable exit HttpChannelState@eaa53ec{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:26:54.176:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-21380: ReservedThreadExecutor@629db94d{s=3/20,p=0}@5db4c856 waiting
Bug