Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Blocked IO Thread not woken #5605

Closed
tchgitav opened this issue Nov 9, 2020 · 63 comments · Fixed by #5637, #5936 or #5953
Closed

Blocked IO Thread not woken #5605

tchgitav opened this issue Nov 9, 2020 · 63 comments · Fixed by #5637, #5936 or #5953
Assignees
Labels
Bug For general bugs on Jetty side
Milestone

Comments

@tchgitav
Copy link

tchgitav commented Nov 9, 2020

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
@sbordet
Copy link
Contributor

sbordet commented Nov 9, 2020

You send a request with content, but the request is not authorized and it's responded with a 401.

If it's your application that sends the 401, then your application should read the request content before sending the 401.

If you have setup some Jetty Authenticator and it's Jetty that replies with the 401, there is not much that can be done aside making sure beforehand that your request can be accepted by the server.

Jetty cannot read the content as that would be an attack vector (imagine uploading a 16 GiB movie whenever a client attacker discovers a URI that is replied with a 401 -- the server would waste resources reading the request content just to discard it).
Therefore, servers don't read such content and just close the connection.

If you have an authenticator that times out on the server, you have to make sure you renew the credentials before they expire.

@tchgitav
Copy link
Author

tchgitav commented Nov 9, 2020

I believe this 401 is normal as I see the same response in other calls which do not error
I've provided some logs for when there is no error on the client side

2020-11-05 22:26:59.302:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de woken with none selected
2020-11-05 22:26:59.302:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de woken up from select, 0/0/0 selected
2020-11-05 22:26:59.302:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de processing 0 keys, 1 updates
2020-11-05 22:26:59.302:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updateable 1
2020-11-05 22:26:59.302:DBUG:oeji.ManagedSelector:qtp1378318626-17766: update Accept@30aeb047[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/10.117.104.15:62366]]
2020-11-05 22:26:59.303:DBUG:oejut.QueuedThreadPool:qtp1378318626-17766: queue Accept@30aeb047[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/10.117.104.15:62366]] startThread=0
2020-11-05 22:26:59.303:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updates 0
2020-11-05 22:26:59.303:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de waiting with 1 keys
2020-11-05 22:26:59.304:DBUG:oejut.QueuedThreadPool:qtp1378318626-16470: run Accept@30aeb047[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/10.117.104.15:62366]] in QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}]
2020-11-05 22:26:59.304:DBUG:oeji.IdleTimeout:qtp1378318626-16470: SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}-><null> idle timeout check, elapsed: 0 ms, remaining: 30000 ms
2020-11-05 22:26:59.305:DBUG:oejs.HttpChannel:qtp1378318626-16470: new HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} -> SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}-><null>,,HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:26:59.305:DBUG:oejs.HttpConnection:qtp1378318626-16470: New HTTP Connection HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}-><null>
2020-11-05 22:26:59.305:DBUG:oeji.ManagedSelector:qtp1378318626-16470: Queued change lazy=true org.eclipse.jetty.io.ManagedSelector$$Lambda$lambda$createEndPoint$0$3119337209/0x0000000000026048@e374b27 on ManagedSelector@3e02b4cf{STARTED} id=5 keys=1 selected=0 updates=0
2020-11-05 22:26:59.305:DBUG:oeji.AbstractEndPoint:qtp1378318626-16470: onOpen SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.305:DBUG:oeji.AbstractConnection:qtp1378318626-16470: onOpen HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.305:DBUG:oeji.AbstractConnection:qtp1378318626-16470: fillInterested HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.305:DBUG:oeji.FillInterest:qtp1378318626-16470: interested FillInterest@e372afd{AC.ReadCB@e372366{HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:26:59.305:DBUG:oeji.ChannelEndPoint:qtp1378318626-16470: changeInterests p=false 0->1 for SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.305:DBUG:oeji.ManagedSelector:qtp1378318626-16470: Queued change lazy=false org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@e372af0 on ManagedSelector@3e02b4cf{STARTED} id=5 keys=1 selected=0 updates=1
2020-11-05 22:26:59.305:DBUG:oeji.ManagedSelector:qtp1378318626-16470: Wakeup on submit ManagedSelector@3e02b4cf{STARTED} id=5 keys=1 selected=0 updates=2
2020-11-05 22:26:59.305:DBUG:oeji.ManagedSelector:qtp1378318626-16470: Created SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.305:DBUG:oejut.QueuedThreadPool:qtp1378318626-16470: ran Accept@30aeb047[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/10.117.104.15:62366]] in QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}]
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de woken with none selected
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de woken up from select, 0/0/1 selected
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de processing 0 keys, 2 updates
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updateable 2
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: update org.eclipse.jetty.io.ManagedSelector$$Lambda$lambda$createEndPoint$0$3119337209/0x0000000000026048@e374b27
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@e372af0
2020-11-05 22:26:59.313:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: Key interests updated 0 -> 1 on SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=7/30000}{io=1/1,kio=1,kro=0}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updates 0
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de waiting with 1 keys
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de woken up from select, 1/1/1 selected
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@102864de processing 1 keys, 0 updates
2020-11-05 22:26:59.313:DBUG:oeji.ManagedSelector:qtp1378318626-17766: selected 1 sun.nio.ch.SelectionKeyImpl@42eba5ed SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=8/30000}{io=1/1,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} 
2020-11-05 22:26:59.313:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: onSelected 1->0 r=true w=false for SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=8/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.313:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: task CEP:SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=8/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
2020-11-05 22:26:59.314:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=1/20,p=0} tryExecute EatWhatYouKill@3e02b452/SelectorProducer@3e02b46e/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=5,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}][pc=213,pic=0,pec=4,epc=640]@2020-11-05T22:26:59.314093986Z
2020-11-05 22:26:59.314:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=0/20,p=0}@661dc550 offer EatWhatYouKill@3e02b452/SelectorProducer@3e02b46e/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=5,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=0}][pc=213,pic=0,pec=4,epc=640]@2020-11-05T22:26:59.314191403Z
2020-11-05 22:26:59.314:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=0/20,p=1} startReservedThread p=1
2020-11-05 22:26:59.314:DBUG:oejut.QueuedThreadPool:qtp1378318626-17766: queue ReservedThreadExecutor@629db94d{s=0/20,p=1}@42eb0cc9 startThread=0
2020-11-05 22:26:59.314:DBUG:oejuts.EatWhatYouKill:qtp1378318626-17766: EatWhatYouKill@3e02b452/SelectorProducer@3e02b46e/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=1}][pc=213,pic=0,pec=4,epc=640]@2020-11-05T22:26:59.314369273Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=8/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING
2020-11-05 22:26:59.314:DBUG:oeji.FillInterest:qtp1378318626-17766: fillable FillInterest@e372afd{AC.ReadCB@e372366{HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=8/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:26:59.314:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=9/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} onFillable enter HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:26:59.314:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1].[FX_OPTIONS-SRC:5313>>>}
2020-11-05 22:26:59.314:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,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].[FX_OPTIONS-SRC:5313>>>}
2020-11-05 22:26:59.314:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1].[FX_OPTIONS-SRC:5313>>>} {}
2020-11-05 22:26:59.314:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=START HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1].[FX_OPTIONS-SRC:5313>>>}
2020-11-05 22:26:59.314:DBUG:oejh.HttpParser:qtp1378318626-17766: START --> SPACE1
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: SPACE1 --> URI
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: URI --> SPACE2
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: SPACE2 --> REQUEST_VERSION
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: REQUEST_VERSION --> HEADER
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:User-Agent --> VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:User-Agent --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:User-Agent --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Type: text/xml; charset=UTF-8 --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Type: text/xml; charset=UTF-8 --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER: --> IN_NAME
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:SOAPAction --> VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:SOAPAction --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:SOAPAction --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Host --> VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Host --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Host --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Length --> VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Length --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Length --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Accept-Encoding: gzip --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Accept-Encoding: gzip --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Connection: keep-alive --> IN_VALUE
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Connection: keep-alive --> FIELD
2020-11-05 22:26:59.315:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER --> CONTENT
2020-11-05 22:26:59.315:DBUG:oejs.HttpChannel:qtp1378318626-17766: REQUEST for //hostnameA:8082/application/webservices/Queries on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,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.34209)
Content-Type: text/xml; charset=UTF-8
SOAPAction: ""
Host: hostnameA:8082
Content-Length: 14781
Accept-Encoding: gzip
Connection: keep-alive


2020-11-05 22:26:59.315:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,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:59.315:DBUG:oejs.HttpChannel:qtp1378318626-17766: handle //hostnameA:8082/application/webservices/Queries HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0} 
2020-11-05 22:26:59.315:DBUG:oejs.HttpChannelState:qtp1378318626-17766: handling HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:26:59.315:DBUG:oejs.HttpChannel:qtp1378318626-17766: action DISPATCH HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:26:59.315:DBUG:oejs.Server:qtp1378318626-17766: REQUEST POST /application/webservices/Queries on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:26:59.315:DBUG:oejsh.ContextHandler:qtp1378318626-17766: scope ||/application/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application/temp/jetty-0_0_0_0-8082-application-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application/lib/application-1.2.1-20201023_205439.war}
2020-11-05 22:26:59.315:DBUG:oejsh.ContextHandler:qtp1378318626-17766: context=/application||/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application/temp/jetty-0_0_0_0-8082-application-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application/lib/application-1.2.1-20201023_205439.war}
2020-11-05 22:26:59.315:DBUG:oejs.session:qtp1378318626-17766: Entering scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800, dispatch=REQUEST asyncstarted=false
2020-11-05 22:26:59.315:DBUG:oejs.session:qtp1378318626-17766: sessionHandler=org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 session=
2020-11-05 22:26:59.315:DBUG:oejs.ServletHandler:qtp1378318626-17766: servlet /application||/webservices/Queries -> springDispatcherServlet@abe94f11==org.springframework.web.servlet.DispatcherServlet,jsp=null,order=1,inst=true,async=false
2020-11-05 22:26:59.315:DBUG:oejs.ServletHandler:qtp1378318626-17766: 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:59.316:DBUG:oejs.session:qtp1378318626-17766: Creating new session id=node03cwifzsgcre71ozzqa9awxdm010273
2020-11-05 22:26:59.316:DBUG:oejs.session:qtp1378318626-17766: Session node03cwifzsgcre71ozzqa9awxdm010273 in use, stopping timer, active requests=1
2020-11-05 22:26:59.316:DBUG:oejs.session:qtp1378318626-17766: Cancelled timer for session node03cwifzsgcre71ozzqa9awxdm010273
2020-11-05 22:26:59.316:DBUG:oejs.Request:qtp1378318626-17766: Request Request(POST //hostnameA:8082/application/webservices/Queries)@e3723ea entering session=Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}
2020-11-05 22:26:59.316:DBUG:oejh.HttpCookie:qtp1378318626-17766: No default value for SameSite
2020-11-05 22:26:59.316:DBUG:oejs.HttpChannelState:qtp1378318626-17766: sendError HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:26:59.316:DBUG:oejs.session:qtp1378318626-17766: Leaving scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 dispatch=REQUEST, async=false, session=Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}, oldsession=, oldsessionhandler=
2020-11-05 22:26:59.316:DBUG:oejs.Server:qtp1378318626-17766: handled=true async=false committed=true on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=true i=true al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:26:59.316:DBUG:oejs.HttpChannelState:qtp1378318626-17766: unhandle HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=true i=true al=0}
2020-11-05 22:26:59.316:DBUG:oejs.HttpChannelState:qtp1378318626-17766: nextAction(false) SEND_ERROR HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:59.316:DBUG:oejs.HttpChannel:qtp1378318626-17766: action SEND_ERROR HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:26:59.316:DBUG:oejs.ErrorPageErrorHandler:qtp1378318626-17766: getErrorPage(POST /application/webservices/Queries) => error_page=null (from global default)
2020-11-05 22:26:59.316:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-18169: ReservedThreadExecutor@629db94d{s=0/20,p=1}@661dc550 task=EatWhatYouKill@3e02b452/SelectorProducer@3e02b46e/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=1}][pc=213,pic=0,pec=4,epc=641]@2020-11-05T22:26:59.316924772Z
2020-11-05 22:26:59.316:DBUG:oejs.HttpChannelState:qtp1378318626-17766: completing HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannel:qtp1378318626-17766: 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@42ea1c1d
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannel:qtp1378318626-17766: COMMIT for /application/webservices/Queries on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=2}
401  HTTP/1.1
Set-Cookie: JSESSIONID=node03cwifzsgcre71ozzqa9awxdm010273.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:59.316:DBUG:oejuts.EatWhatYouKill:qtp1378318626-18169: EatWhatYouKill@3e02b452/SelectorProducer@3e02b46e/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=1}][pc=213,pic=0,pec=4,epc=641]@2020-11-05T22:26:59.317002338Z tryProduce true
2020-11-05 22:26:59.317:DBUG:oejs.Request:qtp1378318626-17766: Response Request[POST //hostnameA:8082/application/webservices/Queries]@e3723ea committing for session Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}
2020-11-05 22:26:59.317:DBUG:oeji.ManagedSelector:qtp1378318626-18169: updateable 0
2020-11-05 22:26:59.317:DBUG:oeji.ManagedSelector:qtp1378318626-18169: updates 0
2020-11-05 22:26:59.317:DBUG:oejs.HttpConnection:qtp1378318626-17766: generate: NEED_HEADER for org.eclipse.jetty.server.HttpConnection$SendCallback@e372398[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@42ea2da1] (null,[p=0,l=496,c=32768,r=496],true)@START
2020-11-05 22:26:59.317:DBUG:oejh.HttpGenerator:qtp1378318626-17766: 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:59.317:DBUG:oejh.HttpGenerator:qtp1378318626-17766: Set-Cookie: JSESSIONID=node03cwifzsgcre71ozzqa9awxdm010273.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:59.317:DBUG:oejh.HttpGenerator:qtp1378318626-17766: CONTENT_LENGTH
2020-11-05 22:26:59.317:DBUG:oeji.ChannelEndPoint:qtp1378318626-18169: Key interests updated 1 -> 0 on SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=2/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:59.317:DBUG:oejs.HttpConnection:qtp1378318626-17766: generate: FLUSH for org.eclipse.jetty.server.HttpConnection$SendCallback@e372398[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@42ea2da1] ([p=0,l=386,c=8192,r=386],[p=0,l=496,c=32768,r=496],true)@COMPLETING
2020-11-05 22:26:59.317:DBUG:oeji.ManagedSelector:qtp1378318626-18169: Selector sun.nio.ch.EPollSelectorImpl@102864de waiting with 1 keys
2020-11-05 22:26:59.317:DBUG:oeji.WriteFlusher:qtp1378318626-17766: write: WriteFlusher@e372afa{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:59.317:DBUG:oeji.WriteFlusher:qtp1378318626-17766: update WriteFlusher@e372afa{WRITING}->null:IDLE-->WRITING
2020-11-05 22:26:59.317:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: flushed 882 SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=W,to=2/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@e3723bf{s=COMPLETING}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:59.317:DBUG:oeji.WriteFlusher:qtp1378318626-17766: Flushed=true written=882 remaining=0 WriteFlusher@e372afa{WRITING}->null
2020-11-05 22:26:59.317:DBUG:oeji.WriteFlusher:qtp1378318626-17766: update WriteFlusher@e372afa{IDLE}->null:WRITING-->IDLE
2020-11-05 22:26:59.317:DBUG:oejs.HttpConnection:qtp1378318626-17766: generate: DONE for org.eclipse.jetty.server.HttpConnection$SendCallback@e372398[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@42ea2da1] ([p=386,l=386,c=8192,r=0],[p=496,l=496,c=32768,r=0],true)@END
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannelState:qtp1378318626-17766: completed HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannelState:qtp1378318626-17766: unhandle HttpChannelState@e3723d0{s=HANDLING rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannelState:qtp1378318626-17766: nextAction(false) TERMINATED HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannel:qtp1378318626-17766: action TERMINATED HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannel:qtp1378318626-17766: onCompleted for /application/webservices/Queries written=496
2020-11-05 22:26:59.317:DBUG:oejs.Request:qtp1378318626-17766: Request Request[POST //hostnameA:8082/application/webservices/Queries]@e3723ea leaving session Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}
2020-11-05 22:26:59.317:DBUG:oejs.session:qtp1378318626-17766: Complete called with session Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}
2020-11-05 22:26:59.317:DBUG:oejs.session:qtp1378318626-17766: Session node03cwifzsgcre71ozzqa9awxdm010273 complete, active requests=0
2020-11-05 22:26:59.317:DBUG:oejs.session:qtp1378318626-17766: Session node03cwifzsgcre71ozzqa9awxdm010273 no eviction
2020-11-05 22:26:59.317:DBUG:oejs.session:qtp1378318626-17766: (Re)starting timer for session node03cwifzsgcre71ozzqa9awxdm010273 at 1800000ms
2020-11-05 22:26:59.317:DBUG:oeji.CyclicTimeout:qtp1378318626-17766: Installed timeout in 1800000 ms, waking up in 1800000 ms
2020-11-05 22:26:59.317:DBUG:oejs.session:qtp1378318626-17766: Store: id=node03cwifzsgcre71ozzqa9awxdm010273, mdirty=true, dirty=true, lsave=0, period=0, elapsed=1604615219317
2020-11-05 22:26:59.317:DBUG:oejs.session:qtp1378318626-17766: Non passivating SessionDataStore, session in SessionCache only id=node03cwifzsgcre71ozzqa9awxdm010273
2020-11-05 22:26:59.317:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parse HeapByteBuffer@6b49cc31[p=303,l=8192,c=8192,r=7889]={POST /pro...ive\r\n\r\n<<<<?xml version="1.0" encod...1].[FX_OPTIONS-SRC:5313>>>} {}
2020-11-05 22:26:59.317:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=303,l=8192,c=8192,r=7889]={POST /pro...ive\r\n\r\n<<<<?xml version="1.0" encod...1].[FX_OPTIONS-SRC:5313>>>}
2020-11-05 22:26:59.317:DBUG:oejs.HttpChannel:qtp1378318626-17766: onContent HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} Content@42e99701{HeapByteBufferR@42e99707[p=303,l=8192,c=8192,r=7889]={POST /pro...ive\r\n\r\n<<<<?xml version="1.0" encod...1].[FX_OPTIONS-SRC:5313>>>}}
2020-11-05 22:26:59.318:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=0,q=0,[0]=null,s=STREAM] addContent Content@42e99701{HeapByteBufferR@42e99707[p=303,l=8192,c=8192,r=7889]={POST /pro...ive\r\n\r\n<<<<?xml version="1.0" encod...1].[FX_OPTIONS-SRC:5313>>>}}
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7889 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3} parsed false HttpParser{s=CONTENT,7889 of 14781}
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: unconsumed input HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7889 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: releaseRequestBuffer HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7889 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:59.318:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 6892 HeapByteBuffer@6b49cc31[p=0,l=6892,c=8192,r=6892]={<<<01:2187630],\n[Hierarchies...p:Body></soap:Envelope>>>> Total-SR...RC:5313}
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7889 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3} filled 6892 HeapByteBuffer@6b49cc31[p=0,l=6892,c=8192,r=6892]={<<<01:2187630],\n[Hierarchies...p:Body></soap:Envelope>>>> Total-SR...RC:5313}
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7889 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3} parse HeapByteBuffer@6b49cc31[p=0,l=6892,c=8192,r=6892]={<<<01:2187630],\n[Hierarchies...p:Body></soap:Envelope>>>> Total-SR...RC:5313} {}
2020-11-05 22:26:59.318:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=0,l=6892,c=8192,r=6892]={<<<01:2187630],\n[Hierarchies...p:Body></soap:Envelope>>>> Total-SR...RC:5313}
2020-11-05 22:26:59.318:DBUG:oejs.HttpChannel:qtp1378318626-17766: onContent HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3} Content@42e90692{HeapByteBufferR@42e90698[p=0,l=6892,c=8192,r=6892]={<<<01:2187630],\n[Hierarchies...p:Body></soap:Envelope>>>> Total-SR...RC:5313}}
2020-11-05 22:26:59.318:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=7889,q=0,[0]=null,s=STREAM] addContent Content@42e90692{HeapByteBufferR@42e90698[p=0,l=6892,c=8192,r=6892]={<<<01:2187630],\n[Hierarchies...p:Body></soap:Envelope>>>> Total-SR...RC:5313}}
2020-11-05 22:26:59.318:DBUG:oejh.HttpParser:qtp1378318626-17766: CONTENT --> CONTENT_END
2020-11-05 22:26:59.318:DBUG:oejs.HttpChannel:qtp1378318626-17766: onContentComplete HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:59.318:DBUG:oejh.HttpParser:qtp1378318626-17766: CONTENT_END --> END
2020-11-05 22:26:59.318:DBUG:oejs.HttpChannel:qtp1378318626-17766: onRequestComplete HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:59.318:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=7889,q=1,[0]=EOF,s=STREAM] addContent EOF
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=END,14781 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3} parsed false HttpParser{s=END,14781 of 14781}
2020-11-05 22:26:59.318:DBUG:oejs.HttpConnection:qtp1378318626-17766: releaseRequestBuffer HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=END,14781 of 14781},g=HttpGenerator@e3723bf{s=END}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=3}
2020-11-05 22:26:59.319:DBUG:oejs.HttpChannelState:qtp1378318626-17766: recycle HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: reset HttpParser{s=END,14781 of 14781}
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: END --> START
2020-11-05 22:26:59.319:DBUG:oejs.HttpChannel:qtp1378318626-17766: !handle TERMINATED HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:26:59.319:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...EMERGING MARKETS-SRC:53>>>}
2020-11-05 22:26:59.319:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...EMERGING MARKETS-SRC:53>>>}
2020-11-05 22:26:59.319:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...EMERGING MARKETS-SRC:53>>>} {}
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=START HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...EMERGING MARKETS-SRC:53>>>}
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: START --> SPACE1
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: SPACE1 --> URI
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: URI --> SPACE2
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: SPACE2 --> REQUEST_VERSION
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: REQUEST_VERSION --> HEADER
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; MS Web Services Client Protocol 4.0.30319.34209) --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:User-Agent: Mozilla/4.0 (compatible; MSIE 6.0; MS Web Services Client Protocol 4.0.30319.34209) --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Type: text/xml; charset=UTF-8 --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Type: text/xml; charset=UTF-8 --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER: --> IN_NAME
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:SOAPAction --> VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:SOAPAction --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:SOAPAction --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Accept-Encoding: gzip --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Accept-Encoding: gzip --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Authorization --> VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Authorization --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Authorization --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Host: hostnameA:8082 --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Host: hostnameA:8082 --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Cookie --> VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Cookie --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Cookie --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Length --> VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Length --> IN_VALUE
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER:Content-Length --> FIELD
2020-11-05 22:26:59.319:DBUG:oejh.HttpParser:qtp1378318626-17766: HEADER --> CONTENT
2020-11-05 22:26:59.319:DBUG:oejs.HttpChannel:qtp1378318626-17766: REQUEST for //hostnameA:8082/application/webservices/Queries on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,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.34209)
Content-Type: text/xml; charset=UTF-8
SOAPAction: ""
Accept-Encoding: gzip
Authorization: Basic YWRtaW46YWRtaW5wd2Q=
Host: hostnameA:8082
Cookie: JSESSIONID=node03cwifzsgcre71ozzqa9awxdm010273.node0
Content-Length: 14781


2020-11-05 22:26:59.319:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,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:59.319:DBUG:oejs.HttpChannel:qtp1378318626-17766: handle //hostnameA:8082/application/webservices/Queries HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0} 
2020-11-05 22:26:59.319:DBUG:oejs.HttpChannelState:qtp1378318626-17766: handling HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:26:59.319:DBUG:oejs.HttpChannel:qtp1378318626-17766: action DISPATCH HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:26:59.320:DBUG:oejs.Server:qtp1378318626-17766: REQUEST POST /application/webservices/Queries on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:26:59.320:DBUG:oejsh.ContextHandler:qtp1378318626-17766: scope ||/application/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application/temp/jetty-0_0_0_0-8082-application-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application/lib/application-1.2.1-20201023_205439.war}
2020-11-05 22:26:59.320:DBUG:oejsh.ContextHandler:qtp1378318626-17766: context=/application||/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application/temp/jetty-0_0_0_0-8082-application-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application/lib/application-1.2.1-20201023_205439.war}
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: Entering scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800, dispatch=REQUEST asyncstarted=false
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: Got Session ID node03cwifzsgcre71ozzqa9awxdm010273.node0 from cookie JSESSIONID
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: Session node03cwifzsgcre71ozzqa9awxdm010273 in use, stopping timer, active requests=1
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: Cancelled timer for session node03cwifzsgcre71ozzqa9awxdm010273
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: Testing expiry on session node03cwifzsgcre71ozzqa9awxdm010273: expires at 1604617019317 now 1604615219320 maxIdle 1800000
2020-11-05 22:26:59.320:DBUG:oejs.Request:qtp1378318626-17766: Request Request(POST //hostnameA:8082/application/webservices/Queries)@e3723ea entering session=Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: Testing expiry on session node03cwifzsgcre71ozzqa9awxdm010273: expires at 1604617019320 now 1604615219320 maxIdle 1800000
2020-11-05 22:26:59.320:DBUG:oejs.session:qtp1378318626-17766: sessionHandler=org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 session=Session@42eaec03{id=node03cwifzsgcre71ozzqa9awxdm010273,x=node03cwifzsgcre71ozzqa9awxdm010273.node0,req=1,res=true}
2020-11-05 22:26:59.320:DBUG:oejs.ServletHandler:qtp1378318626-17766: servlet /application||/webservices/Queries -> springDispatcherServlet@abe94f11==org.springframework.web.servlet.DispatcherServlet,jsp=null,order=1,inst=true,async=false
2020-11-05 22:26:59.320:DBUG:oejs.ServletHandler:qtp1378318626-17766: 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:59.320:DBUG:oejut.QueuedThreadPool:qtp1378318626-18170: run ReservedThreadExecutor@629db94d{s=0/20,p=1}@42eb0cc9 in QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=1}]
2020-11-05 22:26:59.321:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-18170: ReservedThreadExecutor@629db94d{s=1/20,p=1}@42eb0cc9 started
2020-11-05 22:26:59.321:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-18170: ReservedThreadExecutor@629db94d{s=1/20,p=0}@42eb0cc9 waiting
2020-11-05 22:26:59.489:DBUG:oejs.session:qtp1378318626-17766: Session node03cwifzsgcre71ozzqa9awxdm010273 in use, stopping timer, active requests=2
2020-11-05 22:26:59.489:DBUG:oejs.session:qtp1378318626-17766: Cancelled timer for session node03cwifzsgcre71ozzqa9awxdm010273
2020-11-05 22:26:59.489:DBUG:oejs.session:qtp1378318626-17766: Store: id=node08wvf9k7vmpw29baw2e8hhlbt10274, mdirty=true, dirty=true, lsave=0, period=0, elapsed=1604615219489
2020-11-05 22:26:59.489:DBUG:oejs.session:qtp1378318626-17766: Session id node03cwifzsgcre71ozzqa9awxdm010273 swapped for new id node08wvf9k7vmpw29baw2e8hhlbt10274
2020-11-05 22:26:59.489:DBUG:oejs.session:qtp1378318626-17766: Session node08wvf9k7vmpw29baw2e8hhlbt10274 complete, active requests=1
2020-11-05 22:26:59.489:DBUG:oejs.session:qtp1378318626-17766: Req count=1 for id=node08wvf9k7vmpw29baw2e8hhlbt10274
2020-11-05 22:26:59.489:DBUG:oejh.HttpCookie:qtp1378318626-17766: No default value for SameSite
2020-11-05 22:26:59.490:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=171/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,0 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=171} parse HeapByteBuffer@6b49cc31[p=384,l=8192,c=8192,r=7808]={POST /pro...781\r\n\r\n<<<<?xml version="1.0" encod...EMERGING MARKETS-SRC:53>>>} {}
2020-11-05 22:26:59.490:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=384,l=8192,c=8192,r=7808]={POST /pro...781\r\n\r\n<<<<?xml version="1.0" encod...EMERGING MARKETS-SRC:53>>>}
2020-11-05 22:26:59.490:DBUG:oejs.HttpChannel:qtp1378318626-17766: onContent HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=171} Content@42e844c1{HeapByteBufferR@42e844c7[p=384,l=8192,c=8192,r=7808]={POST /pro...781\r\n\r\n<<<<?xml version="1.0" encod...EMERGING MARKETS-SRC:53>>>}}
2020-11-05 22:26:59.490:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=0,q=0,[0]=null,s=STREAM] addContent Content@42e844c1{HeapByteBufferR@42e844c7[p=384,l=8192,c=8192,r=7808]={POST /pro...781\r\n\r\n<<<<?xml version="1.0" encod...EMERGING MARKETS-SRC:53>>>}}
2020-11-05 22:26:59.490:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=171/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7808 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=171} parsed false HttpParser{s=CONTENT,7808 of 14781}
2020-11-05 22:26:59.490:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=4000,q=0,[0]=null,s=STREAM] read 4000 from Content@42e844c1{HeapByteBufferR@42e844c7[p=4384,l=8192,c=8192,r=3808]={POST /pro... EMERGI<<<NG MARKETS-SRC:531280:218...EMERGING MARKETS-SRC:53>>>}}
2020-11-05 22:26:59.490:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=7808,q=0,[0]=null,s=STREAM] read 3808 from Content@42e844c1{HeapByteBufferR@42e844c7[p=8192,l=8192,c=8192,r=0]={POST /pro...-SRC:53<<<>>>}}
2020-11-05 22:26:59.490:DBUG:oejs.HttpConnection:qtp1378318626-17766: releaseRequestBuffer HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=171/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7808 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172}
2020-11-05 22:26:59.491:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 6973 HeapByteBuffer@6b49cc31[p=0,l=6973,c=8192,r=6973]={<<<1297:2216357].[FX &amp; E...p:Body></soap:Envelope>>>> Total-SR...-SRC:53}
2020-11-05 22:26:59.491:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7808 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172} filled 6973 HeapByteBuffer@6b49cc31[p=0,l=6973,c=8192,r=6973]={<<<1297:2216357].[FX &amp; E...p:Body></soap:Envelope>>>> Total-SR...-SRC:53}
2020-11-05 22:26:59.491:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=CONTENT,7808 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172} parse HeapByteBuffer@6b49cc31[p=0,l=6973,c=8192,r=6973]={<<<1297:2216357].[FX &amp; E...p:Body></soap:Envelope>>>> Total-SR...-SRC:53} {}
2020-11-05 22:26:59.491:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=0,l=6973,c=8192,r=6973]={<<<1297:2216357].[FX &amp; E...p:Body></soap:Envelope>>>> Total-SR...-SRC:53}
2020-11-05 22:26:59.491:DBUG:oejs.HttpChannel:qtp1378318626-17766: onContent HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172} Content@73f1cc5f{HeapByteBufferR@73f1cc65[p=0,l=6973,c=8192,r=6973]={<<<1297:2216357].[FX &amp; E...p:Body></soap:Envelope>>>> Total-SR...-SRC:53}}
2020-11-05 22:26:59.491:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=7808,q=0,[0]=null,s=STREAM] addContent Content@73f1cc5f{HeapByteBufferR@73f1cc65[p=0,l=6973,c=8192,r=6973]={<<<1297:2216357].[FX &amp; E...p:Body></soap:Envelope>>>> Total-SR...-SRC:53}}
2020-11-05 22:26:59.491:DBUG:oejh.HttpParser:qtp1378318626-17766: CONTENT --> CONTENT_END
2020-11-05 22:26:59.491:DBUG:oejs.HttpChannel:qtp1378318626-17766: onContentComplete HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172}
2020-11-05 22:26:59.491:DBUG:oejh.HttpParser:qtp1378318626-17766: CONTENT_END --> END
2020-11-05 22:26:59.491:DBUG:oejs.HttpChannel:qtp1378318626-17766: onRequestComplete HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172}
2020-11-05 22:26:59.491:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=7808,q=1,[0]=EOF,s=STREAM] addContent EOF
2020-11-05 22:26:59.491:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=END,14781 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172} parsed false HttpParser{s=END,14781 of 14781}
2020-11-05 22:26:59.491:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=11808,q=1,[0]=EOF,s=STREAM] read 4000 from Content@73f1cc5f{HeapByteBufferR@73f1cc65[p=4000,l=6973,c=8192,r=2973]={1297:2216...obal FX<<<].[ALL].[AllMember].[Nomu...p:Body></soap:Envelope>>>> Total-SR...-SRC:53}}
2020-11-05 22:26:59.491:DBUG:oejs.HttpInput:qtp1378318626-17766: HttpInputOverHTTP@e372205[c=14781,q=1,[0]=EOF,s=STREAM] read 2973 from Content@73f1cc5f{HeapByteBufferR@73f1cc65[p=6973,l=6973,c=8192,r=0]={1297:2216...velope><<<>>> Total-SR...-SRC:53}}
2020-11-05 22:26:59.491:DBUG:oejs.HttpConnection:qtp1378318626-17766: releaseRequestBuffer HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=END,14781 of 14781},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=172}
2020-11-05 22:27:04.268:DBUG:oejs.HttpChannelState:qtp1378318626-17766: onEof HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:27:04.268:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f3cfa0[p=0,l=81,c=4000,r=81]={<<<<soap:Envelope xmlns:soap.../envelope/"><soap:Body>>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.268:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=81,c=32768,r=81]={<<<<soap:Envelope xmlns:soap.../envelope/"><soap:Body>>>>\n<title>E...alue xs}
2020-11-05 22:27:04.268:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.276:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.277:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.277:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.277:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.277:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.277:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class org.objectweb.asm.Label
2020-11-05 22:27:04.278:DBUG:oejw.WebAppClassLoader:qtp1378318626-17766: found webapp loaded class sun.reflect.ConstructorAccessorImpl
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2ab44[p=0,l=1022,c=1024,r=1022]={<<<<qfs:executeMDXResponse x...ew</qfs:levelName><qfs:>>>\x00\x00})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=1103,c=32768,r=1103]={<<<<soap:Envelope xmlns:soap...ew</qfs:levelName><qfs:>>>PerHierar...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2b701[p=0,l=4,c=4,r=4]={<<<path>>>})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=1107,c=32768,r=1107]={<<<<soap:Envelope xmlns:soap...qfs:levelName><qfs:path>>>ierarchy>...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2be10[p=0,l=1023,c=1024,r=1023]={<<<><qfs:items><qfs:item>ECO...fs:levelName>View</qfs:>>>\x00})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=2130,c=32768,r=2130]={<<<<soap:Envelope xmlns:soap...fs:levelName>View</qfs:>>>/qfs:cell...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2bbda[p=0,l=9,c=9,r=9]={<<<levelName>>>})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=2139,c=32768,r=2139]={<<<<soap:Envelope xmlns:soap...ame>View</qfs:levelName>>>s><qfs:de...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f282f8[p=0,l=1020,c=1024,r=1020]={<<<><qfs:path><qfs:items><qf...qfs:displayInfo>0</qfs:>>>fs:\x00})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=3159,c=32768,r=3159]={<<<<soap:Envelope xmlns:soap...qfs:displayInfo>0</qfs:>>>0.0</qfs:...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f28ec1[p=0,l=11,c=11,r=11]={<<<displayInfo>>>})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=3170,c=32768,r=3170]={<<<<soap:Envelope xmlns:soap...Info>0</qfs:displayInfo>>>em></qfs:...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f295fa[p=0,l=1023,c=1024,r=1023]={<<<><qfs:levelName>View</qfs...ons><qfs:position><qfs:>>>\x00})
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=4193,c=32768,r=4193]={<<<<soap:Envelope xmlns:soap...ons><qfs:position><qfs:>>>member><q...alue xs}
2020-11-05 22:27:04.292:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f291cc[p=0,l=7,c=7,r=7]={<<<members>>>})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=4200,c=32768,r=4200]={<<<<soap:Envelope xmlns:soap...s:position><qfs:members>>><qfs:memb...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f299eb[p=0,l=996,c=1024,r=996]={<<<><qfs:member><qfs:caption...25</qfs:item><qfs:item>>>>sitions><...><qfs:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=5196,c=32768,r=5196]={<<<<soap:Envelope xmlns:soap...25</qfs:item><qfs:item>>>></qfs:cel...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2e5b5[p=0,l=48,c=145,r=48]={<<<FX G10 &amp; EMERGING MARKETS-SRC:531283:2216358>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=5244,c=32768,r=5244]={<<<<soap:Envelope xmlns:soap...KETS-SRC:531283:2216358>>>formatted...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2ed8d[p=0,l=1006,c=1024,r=1006]={<<<</qfs:item></qfs:items></...46</qfs:item><qfs:item>>>>fs:positi...><qfs:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=6250,c=32768,r=6250]={<<<<soap:Envelope xmlns:soap...46</qfs:item><qfs:item>>>>s:value x...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2e94e[p=0,l=44,c=145,r=44]={<<<FX &amp; EMERGING MARKETS-SRC:531280:2187629>>>6346\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=6294,c=32768,r=6294]={<<<<soap:Envelope xmlns:soap...KETS-SRC:531280:2187629>>>744</qfs:...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2f151[p=0,l=997,c=1024,r=997]={<<<</qfs:item><qfs:item>EM R...46</qfs:item><qfs:item>>>>qfs:item>...><qfs:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=7291,c=32768,r=7291]={<<<<soap:Envelope xmlns:soap...46</qfs:item><qfs:item>>>>fs:cell><...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2fd13[p=0,l=44,c=145,r=44]={<<<FX &amp; EMERGING MARKETS-SRC:531280:2187629>>>6346\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=7335,c=32768,r=7335]={<<<<soap:Envelope xmlns:soap...KETS-SRC:531280:2187629>>>mattedVal...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2c532[p=0,l=1020,c=1024,r=1020]={<<<</qfs:item></qfs:items></...2187625</qfs:item><qfs:>>>fs:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=8355,c=32768,r=8355]={<<<<soap:Envelope xmlns:soap...2187625</qfs:item><qfs:>>>:value xs...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2c2fb[p=0,l=4,c=4,r=4]={<<<item>>>})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=8359,c=32768,r=8359]={<<<<soap:Envelope xmlns:soap...625</qfs:item><qfs:item>>>ue xsi:ty...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2c9ae[p=0,l=1014,c=1024,r=1014]={<<<>FX G10 &amp; EMERGING MA...36</qfs:item><qfs:item>>>>><qfs:fs:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=9373,c=32768,r=9373]={<<<<soap:Envelope xmlns:soap...36</qfs:item><qfs:item>>>>qfs:cell>...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2d56b[p=0,l=21,c=145,r=21]={<<<US-SRC:531282:2187625>>>1277:2187...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=9394,c=32768,r=9394]={<<<<soap:Envelope xmlns:soap...m>US-SRC:531282:2187625>>>edValue>-...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2de2b[p=0,l=1021,c=1024,r=1021]={<<<</qfs:item></qfs:items></...:value></qfs:cell><qfs:>>>s:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=10415,c=32768,r=10415]={<<<<soap:Envelope xmlns:soap...:value></qfs:cell><qfs:>>>e xsi:typ...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2dbf3[p=0,l=4,c=4,r=4]={<<<cell>>>})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=10419,c=32768,r=10419]={<<<<soap:Envelope xmlns:soap...ue></qfs:cell><qfs:cell>>>i:type="x...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f22327[p=0,l=1020,c=1024,r=1020]={<<<><qfs:formattedValue>-0</...>-0.0</qfs:value></qfs:>>>:s:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=11439,c=32768,r=11439]={<<<<soap:Envelope xmlns:soap...>-0.0</qfs:value></qfs:>>>value xsi...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f228ef[p=0,l=4,c=4,r=4]={<<<cell>>>})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=11443,c=32768,r=11443]={<<<<soap:Envelope xmlns:soap...0</qfs:value></qfs:cell>>>e xsi:typ...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2305f[p=0,l=1022,c=1024,r=1022]={<<<><qfs:cell><qfs:formatted...nal><qfs:value xsi:type>>>:\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=12465,c=32768,r=12465]={<<<<soap:Envelope xmlns:soap...nal><qfs:value xsi:type>>></qfs:ord...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f23c27[p=0,l=2,c=2,r=2]={<<<=">>>})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=12467,c=32768,r=12467]={<<<<soap:Envelope xmlns:soap...l><qfs:value xsi:type=">>>qfs:ordin...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f205be[p=0,l=1023,c=1024,r=1023]={<<<xs:double">-1576600.76690...fs:formattedValue><qfs:>>>\x00})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=13490,c=32768,r=13490]={<<<<soap:Envelope xmlns:soap...fs:formattedValue><qfs:>>>56</qfs:o...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f20187[p=0,l=7,c=7,r=7]={<<<ordinal>>>})
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=13497,c=32768,r=13497]={<<<<soap:Envelope xmlns:soap...attedValue><qfs:ordinal>>>:ordinal>...alue xs}
2020-11-05 22:27:04.293:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f20aa6[p=0,l=1020,c=1024,r=1020]={<<<>26</qfs:ordinal><qfs:val...ll><qfs:formattedValue>>>>fs:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=14517,c=32768,r=14517]={<<<<soap:Envelope xmlns:soap...ll><qfs:formattedValue>>>>e><qfs:or...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2166e[p=0,l=10,c=145,r=10]={<<<-1,576,601>>>669083257...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=14527,c=32768,r=14527]={<<<<soap:Envelope xmlns:soap...rmattedValue>-1,576,601>>>inal>1610...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f21f55[p=0,l=1019,c=1024,r=1019]={<<<</qfs:formattedValue><qfs...576600.7669083257</qfs:>>>>fs:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=15546,c=32768,r=15546]={<<<<soap:Envelope xmlns:soap...576600.7669083257</qfs:>>><qfs:ordi...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f21b1c[p=0,l=5,c=5,r=5]={<<<value>>>})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=15551,c=32768,r=15551]={<<<<soap:Envelope xmlns:soap...0.7669083257</qfs:value>>>ordinal>1...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f26c75[p=0,l=1015,c=1024,r=1015]={<<<></qfs:cell><qfs:cell><qf...l><qfs:value xsi:type=">>>qfs:>fs:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=16566,c=32768,r=16566]={<<<<soap:Envelope xmlns:soap...l><qfs:value xsi:type=">>>><qfs:lev...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f26832[p=0,l=9,c=145,r=9]={<<<xs:double>>>627124947...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=16575,c=32768,r=16575]={<<<<soap:Envelope xmlns:soap...lue xsi:type="xs:double>>>el>SpotPo...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f27139[p=0,l=1020,c=1024,r=1020]={<<<">-0.0</qfs:value></qfs:c...e><qfs:ordinal>53</qfs:>>>fs:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=17595,c=32768,r=17595]={<<<<soap:Envelope xmlns:soap...e><qfs:ordinal>53</qfs:>>>qfs:level...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f27d01[p=0,l=7,c=7,r=7]={<<<ordinal>>>})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=17602,c=32768,r=17602]={<<<<soap:Envelope xmlns:soap...ordinal>53</qfs:ordinal>>>el><qfs:p...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2465e[p=0,l=1020,c=1024,r=1020]={<<<><qfs:value xsi:type="xs:...mbers><qfs:member><qfs:>>>fs:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=18622,c=32768,r=18622]={<<<<soap:Envelope xmlns:soap...mbers><qfs:member><qfs:>>>hy><qfs:p...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f24226[p=0,l=11,c=11,r=11]={<<<captionPath>>>})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=18633,c=32768,r=18633]={<<<<soap:Envelope xmlns:soap...member><qfs:captionPath>>>itions><q...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f24945[p=0,l=1021,c=1024,r=1021]={<<<><qfs:items><qfs:item>con...qfs:path></qfs:member><>>>s:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=19654,c=32768,r=19654]={<<<<soap:Envelope xmlns:soap...qfs:path></qfs:member><>>>fs:value ...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f2550d[p=0,l=4,c=10,r=4]={<<<qfs:>>>\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=19658,c=32768,r=19658]={<<<<soap:Envelope xmlns:soap...path></qfs:member><qfs:>>>alue xsi:...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f25c18[p=0,l=1020,c=1024,r=1020]={<<<member><qfs:captionPath><...><qfs:captionPath><qfs:>>><s:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=20678,c=32768,r=20678]={<<<<soap:Envelope xmlns:soap...><qfs:captionPath><qfs:>>>s:formatt...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@73f259e0[p=0,l=5,c=5,r=5]={<<<items>>>})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=20683,c=32768,r=20683]={<<<<soap:Envelope xmlns:soap...:captionPath><qfs:items>>>mattedVal...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@4e45173c[p=0,l=920,c=1024,r=920]={<<<><qfs:item>false</qfs:ite...qfs:executeMDXResponse>>>>><qfs:ite...fs:<s:\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=21603,c=32768,r=21603]={<<<<soap:Envelope xmlns:soap...qfs:executeMDXResponse>>>>lue>0</qf...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array HeapByteBuffer@4e451bef[p=0,l=28,c=4000,r=28]={<<<</soap:Body></soap:Envelope>>>>ttp://sch...\x00\x00\x00\x00\x00\x00\x00})
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: write(array) s=OPEN,api=BLOCKING,sc=false,e=null aggregated !flush DirectByteBuffer@fbcfc13[p=0,l=21631,c=32768,r=21631]={<<<<soap:Envelope xmlns:soap...p:Body></soap:Envelope>>>>fs:ordina...alue xs}
2020-11-05 22:27:04.294:DBUG:oejs.HttpOutput:qtp1378318626-17766: close() s=CLOSING,api=BLOCKED,sc=false,e=null c=DirectByteBuffer@fbcfc13[p=0,l=21631,c=32768,r=21631]={<<<<soap:Envelope xmlns:soap...p:Body></soap:Envelope>>>>fs:ordina...alue xs} b=Blocker@e372264{null}
2020-11-05 22:27:04.294:DBUG:oejs.HttpChannel:qtp1378318626-17766: sendResponse info= content=DirectByteBuffer@fbcfc13[p=0,l=21631,c=32768,r=21631]={<<<<soap:Envelope xmlns:soap...p:Body></soap:Envelope>>>>fs:ordina...alue xs} complete=true committing=true callback=Blocker@e372264{null}
2020-11-05 22:27:04.294:DBUG:oejs.HttpChannel:qtp1378318626-17766: COMMIT for /application/webservices/Queries on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=COMMITTED is=READY awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=4975}
200  HTTP/1.1
Date: Thu, 05 Nov 2020 22:26:59 GMT
Set-Cookie: JSESSIONID=node08wvf9k7vmpw29baw2e8hhlbt10274.node0; Path=/application
Expires: Thu, 01 Jan 1970 00:00:00 GMT
Content-Type: text/xml;charset=utf-8
X-Content-Type-Options: nosniff
X-XSS-Protection: 1; mode=block
X-Frame-Options: DENY


2020-11-05 22:27:04.294:DBUG:oejs.Request:qtp1378318626-17766: Response Request(POST //hostnameA:8082/application/webservices/Queries)@e3723ea committing for session Session@42eaec03{id=node08wvf9k7vmpw29baw2e8hhlbt10274,x=node08wvf9k7vmpw29baw2e8hhlbt10274.node0,req=1,res=true}
2020-11-05 22:27:04.295:DBUG:oejs.HttpConnection:qtp1378318626-17766: generate: NEED_HEADER for org.eclipse.jetty.server.HttpConnection$SendCallback@e372398[PROCESSING][i=HTTP/1.1{s=200,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@4e457258] (null,[p=0,l=21631,c=32768,r=21631],true)@START
2020-11-05 22:27:04.295:DBUG:oejh.HttpGenerator:qtp1378318626-17766: generateHeaders HTTP/1.1{s=200,h=7,cl=-1} last=true content=DirectByteBuffer@fbcfc13[p=0,l=21631,c=32768,r=21631]={<<<<soap:Envelope xmlns:soap...p:Body></soap:Envelope>>>>fs:ordina...alue xs}
2020-11-05 22:27:04.295:DBUG:oejh.HttpGenerator:qtp1378318626-17766: Date: Thu, 05 Nov 2020 22:26:59 GMT<|Set-Cookie: JSESSIONID=node08wvf9k7vmpw29baw2e8hhlbt10274.node0; Path=/application<|Expires: Thu, 01 Jan 1970 00:00:00 GMT<|Content-Type: text/xml;charset=utf-8<|X-Content-Type-Options: nosniff<|X-XSS-Protection: 1; mode=block<|X-Frame-Options: DENY<|<|
2020-11-05 22:27:04.295:DBUG:oejh.HttpGenerator:qtp1378318626-17766: CONTENT_LENGTH
2020-11-05 22:27:04.295:DBUG:oejs.HttpConnection:qtp1378318626-17766: generate: FLUSH for org.eclipse.jetty.server.HttpConnection$SendCallback@e372398[PROCESSING][i=HTTP/1.1{s=200,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@4e457258] ([p=0,l=359,c=8192,r=359],[p=0,l=21631,c=32768,r=21631],true)@COMPLETING
2020-11-05 22:27:04.295:DBUG:oeji.WriteFlusher:qtp1378318626-17766: write: WriteFlusher@e372afa{IDLE}->null [HeapByteBuffer@6b49cc31[p=0,l=359,c=8192,r=359]={<<<HTTP/1.1 200 OK\r\nDate: Th...y(9.4.33.v20201020)\r\n\r\n>>>SRC:53131...-SRC:53},DirectByteBuffer@fbcfc13[p=0,l=21631,c=32768,r=21631]={<<<<soap:Envelope xmlns:soap...p:Body></soap:Envelope>>>>fs:ordina...alue xs}]
2020-11-05 22:27:04.295:DBUG:oeji.WriteFlusher:qtp1378318626-17766: update WriteFlusher@e372afa{WRITING}->null:IDLE-->WRITING
2020-11-05 22:27:04.295:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: flushed 21990 SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=W,to=4804/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=END,14781 of 14781},g=HttpGenerator@e3723bf{s=COMPLETING}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=COMMITTED is=READY awp=false se=false i=true al=0},r=2,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=4976}
2020-11-05 22:27:04.295:DBUG:oeji.WriteFlusher:qtp1378318626-17766: Flushed=true written=21990 remaining=0 WriteFlusher@e372afa{WRITING}->null
2020-11-05 22:27:04.295:DBUG:oeji.WriteFlusher:qtp1378318626-17766: update WriteFlusher@e372afa{IDLE}->null:WRITING-->IDLE
2020-11-05 22:27:04.295:DBUG:oejs.HttpConnection:qtp1378318626-17766: generate: DONE for org.eclipse.jetty.server.HttpConnection$SendCallback@e372398[PROCESSING][i=HTTP/1.1{s=200,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@4e457258] ([p=359,l=359,c=8192,r=0],[p=21631,l=21631,c=32768,r=0],true)@END
2020-11-05 22:27:04.295:DBUG:oejs.HttpOutput:qtp1378318626-17766: onWriteComplete(true,) s=CLOSING,api=BLOCKED,sc=false,e=null->s=CLOSED,api=BLOCKING,sc=false,e=null c=null cb= w=false
2020-11-05 22:27:04.295:DBUG:oejs.session:qtp1378318626-17766: Leaving scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 dispatch=REQUEST, async=false, session=Session@42eaec03{id=node08wvf9k7vmpw29baw2e8hhlbt10274,x=node08wvf9k7vmpw29baw2e8hhlbt10274.node0,req=1,res=true}, oldsession=, oldsessionhandler=
2020-11-05 22:27:04.295:DBUG:oejs.Server:qtp1378318626-17766: handled=true async=false committed=true on HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=COMPLETED is=READY awp=false se=false i=true al=0},r=2,c=false/true,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=4976}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannelState:qtp1378318626-17766: unhandle HttpChannelState@e3723d0{s=HANDLING rs=BLOCKING os=COMPLETED is=READY awp=false se=false i=true al=0}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannelState:qtp1378318626-17766: nextAction(false) COMPLETE HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMPLETED is=READY awp=false se=false i=false al=0}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannel:qtp1378318626-17766: action COMPLETE HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMPLETED is=READY awp=false se=false i=false al=0},r=2,c=false/true,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=4976}
2020-11-05 22:27:04.295:DBUG:oejs.HttpOutput:qtp1378318626-17766: complete(org.eclipse.jetty.util.Callback$3@4e458053) s=CLOSED,api=BLOCKING,sc=false,e=null s=true e=, c=null
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannelState:qtp1378318626-17766: completed HttpChannelState@e3723d0{s=HANDLING rs=COMPLETING os=COMPLETED is=READY awp=false se=false i=false al=0}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannelState:qtp1378318626-17766: unhandle HttpChannelState@e3723d0{s=HANDLING rs=COMPLETED os=COMPLETED is=READY awp=false se=false i=false al=0}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannelState:qtp1378318626-17766: nextAction(false) TERMINATED HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=READY awp=false se=false i=false al=0}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannel:qtp1378318626-17766: action TERMINATED HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=READY awp=false se=false i=false al=0},r=2,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=4976}
2020-11-05 22:27:04.295:DBUG:oejs.HttpChannel:qtp1378318626-17766: onCompleted for /application/webservices/Queries written=21631
2020-11-05 22:27:04.295:DBUG:oejs.Request:qtp1378318626-17766: Request Request[POST //hostnameA:8082/application/webservices/Queries]@e3723ea leaving session Session@42eaec03{id=node08wvf9k7vmpw29baw2e8hhlbt10274,x=node08wvf9k7vmpw29baw2e8hhlbt10274.node0,req=1,res=true}
2020-11-05 22:27:04.295:DBUG:oejs.session:qtp1378318626-17766: Complete called with session Session@42eaec03{id=node08wvf9k7vmpw29baw2e8hhlbt10274,x=node08wvf9k7vmpw29baw2e8hhlbt10274.node0,req=1,res=true}
2020-11-05 22:27:04.296:DBUG:oejs.session:qtp1378318626-17766: Session node08wvf9k7vmpw29baw2e8hhlbt10274 complete, active requests=0
2020-11-05 22:27:04.296:DBUG:oejs.session:qtp1378318626-17766: Session node08wvf9k7vmpw29baw2e8hhlbt10274 no eviction
2020-11-05 22:27:04.296:DBUG:oejs.session:qtp1378318626-17766: (Re)starting timer for session node08wvf9k7vmpw29baw2e8hhlbt10274 at 1800000ms
2020-11-05 22:27:04.296:DBUG:oeji.CyclicTimeout:qtp1378318626-17766: Installed timeout in 1800000 ms, waking up in 1795021 ms
2020-11-05 22:27:04.296:DBUG:oejs.session:qtp1378318626-17766: Store: id=node08wvf9k7vmpw29baw2e8hhlbt10274, mdirty=true, dirty=true, lsave=1604615219489, period=0, elapsed=4807
2020-11-05 22:27:04.296:DBUG:oejs.session:qtp1378318626-17766: Non passivating SessionDataStore, session in SessionCache only id=node08wvf9k7vmpw29baw2e8hhlbt10274
2020-11-05 22:27:04.296:DBUG:oejs.HttpChannelState:qtp1378318626-17766: recycle HttpChannelState@e3723d0{s=IDLE rs=COMPLETED os=COMPLETED is=READY awp=false se=false i=false al=0}
2020-11-05 22:27:04.296:DBUG:oejh.HttpParser:qtp1378318626-17766: reset HttpParser{s=END,14781 of 14781}
2020-11-05 22:27:04.296:DBUG:oejh.HttpParser:qtp1378318626-17766: END --> START
2020-11-05 22:27:04.296:DBUG:oejs.HttpChannel:qtp1378318626-17766: !handle TERMINATED HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:04.296:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 ...-SRC:53}
2020-11-05 22:27:04.296:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 ...-SRC:53}
2020-11-05 22:27:04.296:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0} filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 ...-SRC:53}
2020-11-05 22:27:04.296:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 ...-SRC:53} {}
2020-11-05 22:27:04.296:DBUG:oejh.HttpParser:qtp1378318626-17766: parseNext s=START HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>HTTP/1.1 ...-SRC:53}
2020-11-05 22:27:04.296:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=1/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0} parsed false HttpParser{s=START,0 of -1}
2020-11-05 22:27:04.296:DBUG:oejs.HttpConnection:qtp1378318626-17766: releaseRequestBuffer HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=1/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:04.296:DBUG:oeji.AbstractConnection:qtp1378318626-17766: fillInterested HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=-,flush=-,to=1/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:04.296:DBUG:oeji.FillInterest:qtp1378318626-17766: interested FillInterest@e372afd{AC.ReadCB@e372366{HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:27:04.296:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: changeInterests p=false 0->1 for SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:04.296:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Queued change lazy=false org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@e372af0 on ManagedSelector@3e02b4cf{STARTED} id=5 keys=1 selected=0 updates=0
2020-11-05 22:27:04.296:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Wakeup on submit ManagedSelector@3e02b4cf{STARTED} id=5 keys=1 selected=0 updates=1
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: Selector sun.nio.ch.EPollSelectorImpl@102864de woken with none selected
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: Selector sun.nio.ch.EPollSelectorImpl@102864de woken up from select, 0/0/1 selected
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: Selector sun.nio.ch.EPollSelectorImpl@102864de processing 0 keys, 1 updates
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: updateable 1
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@e372af0
2020-11-05 22:27:04.297:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@e372366::SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0} onFillable exit HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:27:04.297:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=2/20,p=0}@52a5be waiting
2020-11-05 22:27:04.297:DBUG:oeji.ChannelEndPoint:qtp1378318626-18169: Key interests updated 0 -> 1 on SocketChannelEndPoint@e372ad6{l=/hostnameA_IP:8082,r=/10.117.104.15:62366,OPEN,fill=FI,flush=-,to=0/30000}{io=1/1,kio=1,kro=1}->HttpConnection@e372366[p=HttpParser{s=START,0 of -1},g=HttpGenerator@e3723bf{s=START}]=>HttpChannelOverHttp@e3723b6{s=HttpChannelState@e3723d0{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=2,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: updates 0
2020-11-05 22:27:04.297:DBUG:oeji.ManagedSelector:qtp1378318626-18169: Selector sun.nio.ch.EPollSelectorImpl@102864de waiting with 1 keys
2020-11-05 22:27:05.209:DBUG:oeji.ManagedSelector:qtp1378318626-57-acceptor-2@7eac6813-ServerConnector@522688b8{HTTP/1.1, (http/1.1)}{0.0.0.0:8082}: Queued change lazy=false Accept@30aeb9ae[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/clientA_IP:51464]] on ManagedSelector@3e028273{STARTED} id=6 keys=0 selected=0 updates=0
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-57-acceptor-2@7eac6813-ServerConnector@522688b8{HTTP/1.1, (http/1.1)}{0.0.0.0:8082}: Wakeup on submit ManagedSelector@3e028273{STARTED} id=6 keys=0 selected=0 updates=1
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken with none selected
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken up from select, 0/0/0 selected
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 processing 0 keys, 1 updates
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: updateable 1
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: update Accept@30aeb9ae[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/clientA_IP:51464]]
2020-11-05 22:27:05.210:DBUG:oejut.QueuedThreadPool:qtp1378318626-20625: queue Accept@30aeb9ae[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/clientA_IP:51464]] startThread=0
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: updates 0
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 waiting with 1 keys
2020-11-05 22:27:05.210:DBUG:oejut.QueuedThreadPool:qtp1378318626-20348: run Accept@30aeb9ae[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/clientA_IP:51464]] 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:27:05.210:DBUG:oeji.IdleTimeout:qtp1378318626-20348: SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}-><null> idle timeout check, elapsed: 0 ms, remaining: 30000 ms
2020-11-05 22:27:05.210:DBUG:oejs.HttpChannel:qtp1378318626-20348: new HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} -> SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}-><null>,,HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:27:05.210:DBUG:oejs.HttpConnection:qtp1378318626-20348: New HTTP Connection HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}-><null>
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20348: Queued change lazy=true org.eclipse.jetty.io.ManagedSelector$$Lambda$lambda$createEndPoint$0$3119337209/0x0000000000026048@5af79b06 on ManagedSelector@3e028273{STARTED} id=6 keys=1 selected=0 updates=0
2020-11-05 22:27:05.210:DBUG:oeji.AbstractEndPoint:qtp1378318626-20348: onOpen SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.210:DBUG:oeji.AbstractConnection:qtp1378318626-20348: onOpen HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.210:DBUG:oeji.AbstractConnection:qtp1378318626-20348: fillInterested HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.210:DBUG:oeji.FillInterest:qtp1378318626-20348: interested FillInterest@5af7bcb0{AC.ReadCB@5af7b331{HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=0/0,kio=0,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:27:05.210:DBUG:oeji.ChannelEndPoint:qtp1378318626-20348: changeInterests p=false 0->1 for SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20348: Queued change lazy=false org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@5af7bcbb on ManagedSelector@3e028273{STARTED} id=6 keys=1 selected=0 updates=1
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20348: Wakeup on submit ManagedSelector@3e028273{STARTED} id=6 keys=1 selected=0 updates=2
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken with none selected
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken up from select, 0/0/1 selected
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 processing 0 keys, 2 updates
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: updateable 2
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: update org.eclipse.jetty.io.ManagedSelector$$Lambda$lambda$createEndPoint$0$3119337209/0x0000000000026048@5af79b06
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@5af7bcbb
2020-11-05 22:27:05.211:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: Key interests updated 0 -> 1 on SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/1,kio=1,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: updates 0
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 waiting with 1 keys
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken up from select, 1/1/1 selected
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Selector sun.nio.ch.EPollSelectorImpl@10280079 processing 1 keys, 0 updates
2020-11-05 22:27:05.211:DBUG:oeji.ManagedSelector:qtp1378318626-20625: selected 1 sun.nio.ch.SelectionKeyImpl@4cb2540c SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/1,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} 
2020-11-05 22:27:05.211:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: onSelected 1->0 r=true w=false for SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.211:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: task CEP:SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
2020-11-05 22:27:05.211:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-20625: ReservedThreadExecutor@629db94d{s=2/20,p=0} tryExecute EatWhatYouKill@3e028216/SelectorProducer@3e028212/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=2/20,p=0}][pc=180,pic=0,pec=1,epc=522]@2020-11-05T22:27:05.211360568Z
2020-11-05 22:27:05.211:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-20625: ReservedThreadExecutor@629db94d{s=1/20,p=0}@52a5be offer EatWhatYouKill@3e028216/SelectorProducer@3e028212/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}][pc=180,pic=0,pec=1,epc=522]@2020-11-05T22:27:05.211423186Z
2020-11-05 22:27:05.211:DBUG:oejuts.EatWhatYouKill:qtp1378318626-20625: EatWhatYouKill@3e028216/SelectorProducer@3e028212/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}][pc=180,pic=0,pec=1,epc=522]@2020-11-05T22:27:05.21147536Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING
2020-11-05 22:27:05.211:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=1/20,p=0}@52a5be task=EatWhatYouKill@3e028216/SelectorProducer@3e028212/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}][pc=180,pic=0,pec=1,epc=523]@2020-11-05T22:27:05.211540803Z
2020-11-05 22:27:05.211:DBUG:oeji.FillInterest:qtp1378318626-20625: fillable FillInterest@5af7bcb0{AC.ReadCB@5af7b331{HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:27:05.211:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0} onFillable enter HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:27:05.210:DBUG:oeji.ManagedSelector:qtp1378318626-20348: Created SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=0}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.228:DBUG:oejut.QueuedThreadPool:qtp1378318626-20348: ran Accept@30aeb9ae[java.nio.channels.SocketChannel[connected local=/hostnameA_IP:8082 remote=/clientA_IP:51464]] in QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}]
2020-11-05 22:27:05.211:DBUG:oejuts.EatWhatYouKill:qtp1378318626-17766: EatWhatYouKill@3e028216/SelectorProducer@3e028212/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}][pc=180,pic=0,pec=1,epc=523]@2020-11-05T22:27:05.211590609Z tryProduce true
2020-11-05 22:27:05.240:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updateable 0
2020-11-05 22:27:05.240:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updates 0
2020-11-05 22:27:05.240:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: Key interests updated 1 -> 0 on SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=12/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.241:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 waiting with 1 keys
2020-11-05 22:27:05.228:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1:2187630],\n[Hierarchie>>>}
2020-11-05 22:27:05.258:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=30/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,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:27:05.259:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=30/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=0,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:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: parseNext s=START HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...1:2187630],\n[Hierarchie>>>}
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: START --> SPACE1
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: SPACE1 --> URI
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: URI --> SPACE2
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: SPACE2 --> REQUEST_VERSION
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: REQUEST_VERSION --> HEADER
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:User-Agent --> VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:User-Agent --> IN_VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:User-Agent --> FIELD
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Content-Type: text/xml; charset=UTF-8 --> IN_VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Content-Type: text/xml; charset=UTF-8 --> FIELD
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER: --> IN_NAME
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:SOAPAction --> VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:SOAPAction --> IN_VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:SOAPAction --> FIELD
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Host --> VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Host --> IN_VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Host --> FIELD
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Content-Length --> VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Content-Length --> IN_VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Content-Length --> FIELD
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Accept-Encoding: gzip --> IN_VALUE
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER:Accept-Encoding: gzip --> FIELD
2020-11-05 22:27:05.259:DBUG:oejh.HttpParser:qtp1378318626-20625: HEADER --> CONTENT
2020-11-05 22:27:05.259:DBUG:oejs.HttpChannel:qtp1378318626-20625: REQUEST for //hostnameA:8082/application/webservices/Queries on HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,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: 14355
Accept-Encoding: gzip


2020-11-05 22:27:05.259:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=30/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,0 of 14355},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0} parsed true HttpParser{s=CONTENT,0 of 14355}
2020-11-05 22:27:05.259:DBUG:oejs.HttpChannel:qtp1378318626-20625: handle //hostnameA:8082/application/webservices/Queries HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=0} 
2020-11-05 22:27:05.259:DBUG:oejs.HttpChannelState:qtp1378318626-20625: handling HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:27:05.259:DBUG:oejs.HttpChannel:qtp1378318626-20625: action DISPATCH HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:27:05.259:DBUG:oejs.Server:qtp1378318626-20625: REQUEST POST /application/webservices/Queries on HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=0}
2020-11-05 22:27:05.259:DBUG:oejsh.ContextHandler:qtp1378318626-20625: scope ||/application/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application/temp/jetty-0_0_0_0-8082-application-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application/lib/application-1.2.1-20201023_205439.war}
2020-11-05 22:27:05.259:DBUG:oejsh.ContextHandler:qtp1378318626-20625: context=/application||/webservices/Queries @ o.e.j.w.WebAppContext@52262d08{/application,file:///home/monjuu-g/dev/application/temp/jetty-0_0_0_0-8082-application-1_2_1-20201023_205439_war-_application-any-1718594855883126077/webapp/,AVAILABLE}{/home/monjuu-g/dev/application/lib/application-1.2.1-20201023_205439.war}
2020-11-05 22:27:05.259:DBUG:oejs.session:qtp1378318626-20625: Entering scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800, dispatch=REQUEST asyncstarted=false
2020-11-05 22:27:05.259:DBUG:oejs.session:qtp1378318626-20625: sessionHandler=org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 session=
2020-11-05 22:27:05.259:DBUG:oejs.ServletHandler:qtp1378318626-20625: servlet /application||/webservices/Queries -> springDispatcherServlet@abe94f11==org.springframework.web.servlet.DispatcherServlet,jsp=null,order=1,inst=true,async=false
2020-11-05 22:27:05.259:DBUG:oejs.ServletHandler:qtp1378318626-20625: 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:27:05.260:DBUG:oejs.session:qtp1378318626-20625: Creating new session id=node0r6eaagajz16vaxz69fiymyfr10275
2020-11-05 22:27:05.260:DBUG:oejs.session:qtp1378318626-20625: Session node0r6eaagajz16vaxz69fiymyfr10275 in use, stopping timer, active requests=1
2020-11-05 22:27:05.260:DBUG:oejs.session:qtp1378318626-20625: Cancelled timer for session node0r6eaagajz16vaxz69fiymyfr10275
2020-11-05 22:27:05.260:DBUG:oejs.Request:qtp1378318626-20625: Request Request(POST //hostnameA:8082/application/webservices/Queries)@5af7b3ad entering session=Session@4cb31be7{id=node0r6eaagajz16vaxz69fiymyfr10275,x=node0r6eaagajz16vaxz69fiymyfr10275.node0,req=1,res=true}
2020-11-05 22:27:05.260:DBUG:oejh.HttpCookie:qtp1378318626-20625: No default value for SameSite
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: sendError HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0}
2020-11-05 22:27:05.260:DBUG:oejs.session:qtp1378318626-20625: Leaving scope org.eclipse.jetty.server.session.SessionHandler1654434902==dftMaxIdleSec=1800 dispatch=REQUEST, async=false, session=Session@4cb31be7{id=node0r6eaagajz16vaxz69fiymyfr10275,x=node0r6eaagajz16vaxz69fiymyfr10275.node0,req=1,res=true}, oldsession=, oldsessionhandler=
2020-11-05 22:27:05.260:DBUG:oejs.Server:qtp1378318626-20625: handled=true async=false committed=true on HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=true i=true al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: unhandle HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=true i=true al=0}
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: nextAction(false) SEND_ERROR HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannel:qtp1378318626-20625: action SEND_ERROR HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:27:05.260:DBUG:oejs.ErrorPageErrorHandler:qtp1378318626-20625: getErrorPage(POST /application/webservices/Queries) => error_page=null (from global default)
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: completing HttpChannelState@5af7b3a3{s=HANDLING rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannel:qtp1378318626-20625: 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>>>:ordinal>...alue xs} complete=true committing=true callback=org.eclipse.jetty.util.Callback$3@4cb3ebf6
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannel:qtp1378318626-20625: COMMIT for /application/webservices/Queries on HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
401  HTTP/1.1
Set-Cookie: JSESSIONID=node0r6eaagajz16vaxz69fiymyfr10275.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:27:05.260:DBUG:oejs.Request:qtp1378318626-20625: Response Request[POST //hostnameA:8082/application/webservices/Queries]@5af7b3ad committing for session Session@4cb31be7{id=node0r6eaagajz16vaxz69fiymyfr10275,x=node0r6eaagajz16vaxz69fiymyfr10275.node0,req=1,res=true}
2020-11-05 22:27:05.260:DBUG:oejs.HttpConnection:qtp1378318626-20625: generate: NEED_HEADER for org.eclipse.jetty.server.HttpConnection$SendCallback@5af7b35b[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@4cb3da55] (null,[p=0,l=496,c=32768,r=496],true)@START
2020-11-05 22:27:05.260:DBUG:oejh.HttpGenerator:qtp1378318626-20625: 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>>>:ordinal>...alue xs}
2020-11-05 22:27:05.260:DBUG:oejh.HttpGenerator:qtp1378318626-20625: Set-Cookie: JSESSIONID=node0r6eaagajz16vaxz69fiymyfr10275.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:27:05.260:DBUG:oejh.HttpGenerator:qtp1378318626-20625: CONTENT_LENGTH
2020-11-05 22:27:05.260:DBUG:oejs.HttpConnection:qtp1378318626-20625: generate: FLUSH for org.eclipse.jetty.server.HttpConnection$SendCallback@5af7b35b[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@4cb3da55] ([p=0,l=385,c=8192,r=385],[p=0,l=496,c=32768,r=496],true)@COMPLETING
2020-11-05 22:27:05.260:DBUG:oeji.WriteFlusher:qtp1378318626-20625: write: WriteFlusher@5af7bcb5{IDLE}->null [HeapByteBuffer@711c6a74[p=0,l=385,c=8192,r=385]={<<<HTTP/1.1 401 Unauthorized...y(9.4.33.v20201020)\r\n\r\n>>>\n\nl versi...; EMERG},DirectByteBuffer@fbcfc13[p=0,l=496,c=32768,r=496]={<<<<html>\n<head>\n<meta http-...<hr/>\n\n</body>\n</html>\n>>>:ordinal>...alue xs}]
2020-11-05 22:27:05.260:DBUG:oeji.WriteFlusher:qtp1378318626-20625: update WriteFlusher@5af7bcb5{WRITING}->null:IDLE-->WRITING
2020-11-05 22:27:05.260:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: flushed 881 SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=W,to=31/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,0 of 14355},g=HttpGenerator@5af7b37a{s=COMPLETING}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=HANDLING rs=COMPLETING os=COMMITTED is=IDLE awp=false se=false i=false al=0},r=1,c=false/false,a=HANDLING,uri=//hostnameA:8082/application/webservices/Queries,age=1}
2020-11-05 22:27:05.260:DBUG:oeji.WriteFlusher:qtp1378318626-20625: Flushed=true written=881 remaining=0 WriteFlusher@5af7bcb5{WRITING}->null
2020-11-05 22:27:05.260:DBUG:oeji.WriteFlusher:qtp1378318626-20625: update WriteFlusher@5af7bcb5{IDLE}->null:WRITING-->IDLE
2020-11-05 22:27:05.260:DBUG:oejs.HttpConnection:qtp1378318626-20625: generate: DONE for org.eclipse.jetty.server.HttpConnection$SendCallback@5af7b35b[PROCESSING][i=HTTP/1.1{s=401,h=7,cl=-1},cb=org.eclipse.jetty.server.HttpChannel$SendCallback@4cb3da55] ([p=385,l=385,c=8192,r=0],[p=496,l=496,c=32768,r=0],true)@END
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: completed HttpChannelState@5af7b3a3{s=HANDLING rs=COMPLETING os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: unhandle HttpChannelState@5af7b3a3{s=HANDLING rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:27:05.260:DBUG:oejs.HttpChannelState:qtp1378318626-20625: nextAction(false) TERMINATED HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: action TERMINATED HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: onCompleted for /application/webservices/Queries written=496
2020-11-05 22:27:05.261:DBUG:oejs.Request:qtp1378318626-20625: Request Request[POST //hostnameA:8082/application/webservices/Queries]@5af7b3ad leaving session Session@4cb31be7{id=node0r6eaagajz16vaxz69fiymyfr10275,x=node0r6eaagajz16vaxz69fiymyfr10275.node0,req=1,res=true}
2020-11-05 22:27:05.261:DBUG:oejs.session:qtp1378318626-20625: Complete called with session Session@4cb31be7{id=node0r6eaagajz16vaxz69fiymyfr10275,x=node0r6eaagajz16vaxz69fiymyfr10275.node0,req=1,res=true}
2020-11-05 22:27:05.261:DBUG:oejs.session:qtp1378318626-20625: Session node0r6eaagajz16vaxz69fiymyfr10275 complete, active requests=0
2020-11-05 22:27:05.261:DBUG:oejs.session:qtp1378318626-20625: Session node0r6eaagajz16vaxz69fiymyfr10275 no eviction
2020-11-05 22:27:05.261:DBUG:oejs.session:qtp1378318626-20625: (Re)starting timer for session node0r6eaagajz16vaxz69fiymyfr10275 at 1800000ms
2020-11-05 22:27:05.261:DBUG:oeji.CyclicTimeout:qtp1378318626-20625: Installed timeout in 1800000 ms, waking up in 1800000 ms
2020-11-05 22:27:05.261:DBUG:oejs.session:qtp1378318626-20625: Store: id=node0r6eaagajz16vaxz69fiymyfr10275, mdirty=true, dirty=true, lsave=0, period=0, elapsed=1604615225261
2020-11-05 22:27:05.261:DBUG:oejs.session:qtp1378318626-20625: Non passivating SessionDataStore, session in SessionCache only id=node0r6eaagajz16vaxz69fiymyfr10275
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,0 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,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:27:05.261:DBUG:oejh.HttpParser:qtp1378318626-20625: 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:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: onContent HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} Content@4cb07c40{HeapByteBufferR@4cb07c4a[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:27:05.261:DBUG:oejs.HttpInput:qtp1378318626-20625: HttpInputOverHTTP@5af7b3d0[c=0,q=0,[0]=null,s=STREAM] addContent Content@4cb07c40{HeapByteBufferR@4cb07c4a[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:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,7913 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parsed false HttpParser{s=CONTENT,7913 of 14355}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: unconsumed input HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,7913 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: releaseRequestBuffer HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,7913 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:27:05.261:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: filled 6442 HeapByteBuffer@6b49cc31[p=0,l=6442,c=8192,r=6442]={<<<s].[Global FX].[ALL].[All...p:Body></soap:Envelope>>>>2216345],...rarchie}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,7913 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} filled 6442 HeapByteBuffer@6b49cc31[p=0,l=6442,c=8192,r=6442]={<<<s].[Global FX].[ALL].[All...p:Body></soap:Envelope>>>>2216345],...rarchie}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=CONTENT,7913 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parse HeapByteBuffer@6b49cc31[p=0,l=6442,c=8192,r=6442]={<<<s].[Global FX].[ALL].[All...p:Body></soap:Envelope>>>>2216345],...rarchie} {}
2020-11-05 22:27:05.261:DBUG:oejh.HttpParser:qtp1378318626-20625: parseNext s=CONTENT HeapByteBuffer@6b49cc31[p=0,l=6442,c=8192,r=6442]={<<<s].[Global FX].[ALL].[All...p:Body></soap:Envelope>>>>2216345],...rarchie}
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: onContent HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} Content@4cb0f261{HeapByteBufferR@4cb0f26b[p=0,l=6442,c=8192,r=6442]={<<<s].[Global FX].[ALL].[All...p:Body></soap:Envelope>>>>2216345],...rarchie}}
2020-11-05 22:27:05.261:DBUG:oejs.HttpInput:qtp1378318626-20625: HttpInputOverHTTP@5af7b3d0[c=7913,q=0,[0]=null,s=STREAM] addContent Content@4cb0f261{HeapByteBufferR@4cb0f26b[p=0,l=6442,c=8192,r=6442]={<<<s].[Global FX].[ALL].[All...p:Body></soap:Envelope>>>>2216345],...rarchie}}
2020-11-05 22:27:05.261:DBUG:oejh.HttpParser:qtp1378318626-20625: CONTENT --> CONTENT_END
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: onContentComplete HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:27:05.261:DBUG:oejh.HttpParser:qtp1378318626-20625: CONTENT_END --> END
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: onRequestComplete HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:27:05.261:DBUG:oejs.HttpInput:qtp1378318626-20625: HttpInputOverHTTP@5af7b3d0[c=7913,q=1,[0]=EOF,s=STREAM] addContent EOF
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=END,14355 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2} parsed false HttpParser{s=END,14355 of 14355}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: releaseRequestBuffer HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=END,14355 of 14355},g=HttpGenerator@5af7b37a{s=END}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0},r=1,c=true/true,a=IDLE,uri=//hostnameA:8082/application/webservices/Queries,age=2}
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannelState:qtp1378318626-20625: recycle HttpChannelState@5af7b3a3{s=IDLE rs=COMPLETED os=COMPLETED is=IDLE awp=false se=false i=false al=0}
2020-11-05 22:27:05.261:DBUG:oejh.HttpParser:qtp1378318626-20625: reset HttpParser{s=END,14355 of 14355}
2020-11-05 22:27:05.261:DBUG:oejh.HttpParser:qtp1378318626-20625: END --> START
2020-11-05 22:27:05.261:DBUG:oejs.HttpChannel:qtp1378318626-20625: !handle TERMINATED HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.261:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:27:05.261:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} filled 0 HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:27:05.261:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} parse HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie} {}
2020-11-05 22:27:05.262:DBUG:oejh.HttpParser:qtp1378318626-20625: parseNext s=START HeapByteBuffer@6b49cc31[p=0,l=0,c=8192,r=0]={<<<>>>s].[Globa...rarchie}
2020-11-05 22:27:05.262:DBUG:oejs.HttpConnection:qtp1378318626-20625: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} parsed false HttpParser{s=START,0 of -1}
2020-11-05 22:27:05.262:DBUG:oejs.HttpConnection:qtp1378318626-20625: releaseRequestBuffer HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.262:DBUG:oeji.AbstractConnection:qtp1378318626-20625: fillInterested HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.262:DBUG:oeji.FillInterest:qtp1378318626-20625: interested FillInterest@5af7bcb0{AC.ReadCB@5af7b331{HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=0/0,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:27:05.262:DBUG:oeji.ChannelEndPoint:qtp1378318626-20625: changeInterests p=false 0->1 for SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=0/1,kio=0,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Queued change lazy=false org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@5af7bcbb on ManagedSelector@3e028273{STARTED} id=6 keys=1 selected=0 updates=0
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-20625: Wakeup on submit ManagedSelector@3e028273{STARTED} id=6 keys=1 selected=0 updates=1
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken with none selected
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken up from select, 0/0/1 selected
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 processing 0 keys, 1 updates
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updateable 1
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: update org.eclipse.jetty.io.ChannelEndPoint$$Lambda$updateKeyAction$637863116/0x0000000000026032@5af7bcbb
2020-11-05 22:27:05.262:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: Key interests updated 0 -> 1 on SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/1,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: updates 0
2020-11-05 22:27:05.262:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 waiting with 1 keys
2020-11-05 22:27:05.263:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 woken up from select, 1/1/1 selected
2020-11-05 22:27:05.263:DBUG:oeji.ManagedSelector:qtp1378318626-17766: Selector sun.nio.ch.EPollSelectorImpl@10280079 processing 1 keys, 0 updates
2020-11-05 22:27:05.263:DBUG:oeji.ManagedSelector:qtp1378318626-17766: selected 1 sun.nio.ch.SelectionKeyImpl@4cb2540c SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/1,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} 
2020-11-05 22:27:05.263:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: onSelected 1->0 r=true w=false for SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}
2020-11-05 22:27:05.263:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: task CEP:SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING
2020-11-05 22:27:05.263:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=1/20,p=0} tryExecute EatWhatYouKill@3e028216/SelectorProducer@3e028212/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=1/20,p=0}][pc=180,pic=0,pec=1,epc=523]@2020-11-05T22:27:05.26329749Z
2020-11-05 22:27:05.263:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=0/20,p=0}@42eb0cc9 offer EatWhatYouKill@3e028216/SelectorProducer@3e028212/PRODUCING/p=false/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=4,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=0}][pc=180,pic=0,pec=1,epc=523]@2020-11-05T22:27:05.263365563Z
2020-11-05 22:27:05.263:DBUG:oejut.ReservedThreadExecutor:qtp1378318626-17766: ReservedThreadExecutor@629db94d{s=0/20,p=1} startReservedThread p=1
2020-11-05 22:27:05.263:DBUG:oejut.QueuedThreadPool:qtp1378318626-17766: queue ReservedThreadExecutor@629db94d{s=0/20,p=1}@7d863e04 startThread=0
2020-11-05 22:27:05.263:DBUG:oejut.QueuedThreadPool:qtp1378318626-21729: run ReservedThreadExecutor@629db94d{s=0/20,p=1}@7d863e04 in QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=1}]
2020-11-05 22:27:05.263:DBUG:oejuts.EatWhatYouKill:qtp1378318626-17766: EatWhatYouKill@3e028216/SelectorProducer@3e028212/IDLE/p=true/QueuedThreadPool[qtp1378318626]@52277922{STARTED,8<=23<=200,i=3,r=20,q=0}[ReservedThreadExecutor@629db94d{s=0/20,p=1}][pc=180,pic=0,pec=1,epc=523]@2020-11-05T22:27:05.263471286Z m=EXECUTE_PRODUCE_CONSUME t=CEP:SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=1/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}:runFillable:BLOCKING/BLOCKING
2020-11-05 22:27:05.263:DBUG:oeji.FillInterest:qtp1378318626-17766: fillable FillInterest@5af7bcb0{AC.ReadCB@5af7b331{HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=FI,flush=-,to=1/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0}}}
2020-11-05 22:27:05.263:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=1/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} onFillable enter HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0} null
2020-11-05 22:27:05.263:DBUG:oeji.ChannelEndPoint:qtp1378318626-17766: filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...MERGING MARKETS-SRC:531>>>}
2020-11-05 22:27:05.263:DBUG:oejs.HttpConnection:qtp1378318626-17766: HttpConnection@5af7b331::SocketChannelEndPoint@5af7bc99{l=/hostnameA_IP:8082,r=/clientA_IP:51464,OPEN,fill=-,flush=-,to=0/30000}{io=1/0,kio=1,kro=1}->HttpConnection@5af7b331[p=HttpParser{s=START,0 of -1},g=HttpGenerator@5af7b37a{s=START}]=>HttpChannelOverHttp@5af7b381{s=HttpChannelState@5af7b3a3{s=IDLE rs=BLOCKING os=OPEN is=IDLE awp=false se=false i=true al=0},r=1,c=false/false,a=IDLE,uri=null,age=0} filled 8192 HeapByteBuffer@6b49cc31[p=0,l=8192,c=8192,r=8192]={<<<POST /application/webservices...MERGING MARKETS-SRC:531>>>}

@joakime
Copy link
Contributor

joakime commented Nov 9, 2020

On the first dump look at the HttpConnection@eaa5362 you'll see that it was reading what looks like json, but didn't finish reading it.

The abort occurred at HttpConnection@eaa5362[p=HttpParser{s=CLOSE,13140 of 14781} which means there was still content on that connection, in an unread state, so it aborted/closed that connection.

@tchgitav
Copy link
Author

tchgitav commented Nov 9, 2020

The content is xml

Yes I agree, that is the same conclusion I arrived at
The connection was aborted because the connection thought the parsing was finished when in fact there was still some more

What I don't understand is why that happened and if there's something I can do/configure to avoid this issue

And to confirm, this is just jetty side http parsing correct?
It hasn't reach the web application yet right?

I am trying to conclude if the issue is on jetty, the web application, or potentially a 3rd party library

@sbordet
Copy link
Contributor

sbordet commented Nov 9, 2020

As I said, if your application is generating the 401, it must read the request content up to -1.

In the logs above no content is read, the response is generated and few lines after you can see HttpParser{s=CONTENT,0 of 14781}:

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>>>} {}

What happens next is that Jetty tries to consume the content that arrived so far, exactly to try to be as nice as possible.

It so happens that there are 13140 bytes arrived that can be read; after that, Jetty has to close the connection.

It may not happen all the times because TCP may split content differently, and there may be other reasons such as chunking, etc. If all the content has arrived, the request content will all be consumed and no error would happen.

It's not a Jetty issue. It's an application (or a library) not reading the content before the 401.

If it's Jetty producing the 401 because you have setup some Jetty Authenticator, then you have to try to avoid it as explained in my previous message.

@tchgitav
Copy link
Author

tchgitav commented Nov 10, 2020

It's an application (or a library) not reading the content before the 401.

Isn't jetty reading the content?

The weird thing is it is happening intermittently, meaning for several hours maybe only show up once and all the other requests are processed fine
I'll look into the application/libraries to see if there's any play there; I didn't see exceptions on the server logs

We never came across this issue when running the same application with the 4.2.x jetty

Thanks for your feedback

@sbordet
Copy link
Contributor

sbordet commented Nov 10, 2020

Isn't jetty reading the content?

Jetty is reading the content on behalf of the application. It is the application that calls httpServletRequest.getInputStream().read(...).

If the application does not call read(...) Jetty does not "read" the request content.

As I said, the fact that you get this intermittently may be due to the fact that the whole content is already arrived to the server when the 401 is produced. It may depend on the size of the content, how it is split by TCP, by the HTTP transfer encoding and by the content encoding too.

@sbordet sbordet self-assigned this Nov 10, 2020
@gregw
Copy link
Contributor

gregw commented Nov 10, 2020

The interesting thing to consider here is that it is jetty not the application that is sending the 401. So perhaps we do have a responsibility to consume the input... or to at least make an attempt at it.

I'm wondering if internally we should be doing the following before committing the 401:

  • try to consume the input in a non-blocking way
    • If content is consumed, then send 401 normally
    • If content is not consumed, then send 401 with Connection: close header and do not block for the content, aborting the connection after committing the response.

@sbordet how would that work for HTTP2? Would it be that we send the 401 header frame and then a reset?

Alternately, we could asynchronously consume all the input on 401 responses - thus reducing the attack vector as we'd not block a thread.

@gregw
Copy link
Contributor

gregw commented Nov 10, 2020

@sbordet I have verified that we don't normally add a Connection: close on a 401 response.

So in summary, I think we are doing the right thing, by not reading the content. However we could be clearer by sending a Connection: close on the 401 when we know we are likely to abort: either because we have content which we wont try to read or we've tried to read it non-blocking, but would block.

@sbordet
Copy link
Contributor

sbordet commented Nov 10, 2020

@gregw +1 on adding Connection: close -- I thought we did already.

For HTTP/2, since it's multiplexed, if the client sends the whole content, the server will read it and discard it.

@joakime
Copy link
Contributor

joakime commented Nov 10, 2020

Please make the Connection: close on 401 response only if there is unconsumed content.
Having it force the close on other scenarios seems wasteful.

@gregw
Copy link
Contributor

gregw commented Nov 10, 2020

@joakime well I'd say that sending content that may need to be authenticated is wasteful :) But yes at the very least we will only add a Content: close if there is content, so most GETs will be OK. If it is simple then we might try a consumeAll prior to sending the 401, so we can know if all content can be consumed or not.

@tchgitav In your usecase, where you are sending content that might be refused every so often, it may be better to send Expect: Continue in the requests and then your client should only send the body of it gets a 101 rather than a 401.

@tchgitav
Copy link
Author

tchgitav commented Nov 10, 2020

Thanks for the discussion

I am currently looking into the source code of the Apache cxf and woodstox utf8Reader to see what might have happened
Could be somewhere there it errored out or thought it finished the content when it hadn't

Regarding the 401, I will focus on that afterwards.
But I believe it might be part of the normal handshaking that is done by Spring security or the client did not preemptively authenticate
It could just configured incorrectly
However we don't see issues in the majority of the requests in regards to the 401 message

gregw added a commit that referenced this issue Nov 10, 2020
Add Connection:close if content can't be consumed during a sendError. Processed after the request has returned to the container.

Signed-off-by: Greg Wilkins <gregw@webtide.com>
@gregw gregw linked a pull request Nov 10, 2020 that will close this issue
@tchgitav
Copy link
Author

tchgitav commented Nov 10, 2020

I am testing the results if I upgrade the woodstox-core dependency to 6.2.1
Originally I wanted to enable finer logging for this dependency but there doesn't seem to be much logging in this library

For the 401 response above, I think this is normal basic Authenticate behavior
I see the same behavior using SOAPUI
If I enable Authenticate pre-emptively on the SOAP UI side, then I don't see the 401 issue anymore
I think our client is just set up the basic authentication
https://stackoverflow.com/questions/7482523/preemptive-authentication-why

In my initial debug log snippet, I don't see logs for HttpInput.read() like below
Is that indicative of anything?

2020-11-10 15:43:58.126:DBUG:oejs.HttpInput:qtp680712932-86: HttpInputOverHTTP@60a03cab[c=4000,q=0,[0]=null,s=STREAM] read 4000 from Content@1167aa1c{HeapByteBufferR@a295b2a[p=4289,l=8192,c=8192,r=3903]={POST /ap-...Member]<<<.[77],\n      [BookId].[Bo...[ALL].[AllMember].[157]>>>}}
2020-11-10 15:43:58.127:DBUG:oejs.HttpInput:qtp680712932-86: HttpInputOverHTTP@60a03cab[c=7903,q=0,[0]=null,s=STREAM] read 3903 from Content@1167aa1c{HeapByteBufferR@a295b2a[p=8192,l=8192,c=8192,r=0]={POST /ap-...].[157]<<<>>>}}

@gregw
Copy link
Contributor

gregw commented Nov 11, 2020

@tchgitav The 401 is indeed a standard part of the auth conversation.
The issue is that if you send a POST with a large body that is not authenticated, so a 401 response is sent, then what should the server do with the body. Jetty makes an effort to consume it, but if it doesn't succeed without blocking, then it aborts that connection... which a server is entitled to do.

So other than the warning you see, is this actually causing any problems for your client? Is it failing the next request?

If so, any chance you can try building/testing #5637, which will give your client a Connection:close warning in those cases.

@tchgitav
Copy link
Author

tchgitav commented Nov 11, 2020

I believe my issue is during the authenticated request and not the initial un-authenticated request
Otherwise I'd see this issue more frequently

I think if you change the 401 response to a connection close, it might not play well with basicAuth
I can try the changes

Update: I tried running with the updated woodstox dependencies, still observe this exception
I'll keep looking

@gregw
Copy link
Contributor

gregw commented Nov 11, 2020

@tchgitav The request can't be authenticated, else we would not be sending a 401.
Closing the connection will work fine with BASIC... it dates from HTTP/1.0 days and worked perfectly well before there was even a concept of persistent connections.

So can you answer if you are just seeing the exception or you are also seeing bad behaviour (eg missed request/response?)
If it is just the exception that you are seeing, then it is ignorable ... hence why it is only in a debug

@tchgitav
Copy link
Author

Yes, we are seeing the missed request on the application side
As well as the connection closed error on the client side

No exceptions on the server logs

@gregw
Copy link
Contributor

gregw commented Nov 11, 2020

@tchgitav So the missed request on the application side is the one that the 401 is sent for?
Does the client resend iit, or does it just get too upset about the closed connection and not retry it??
That could be because clients are not allowed to retry POSTs, so the problem could simply be that it was not authenticated for some reason???

Do you know why it is getting a 401?

@tchgitav
Copy link
Author

So the missed request on the application side is the one that the 401 is sent for?

The missed request is for the one with the credentials which was being parsed but for some reason the connection was aborted due to the IOException: unconsumed input.
I think only the authenticated requests reaches the application so long there are no issues

Does the client resend iit, or does it just get too upset about the closed connection and not retry it??

The client does not resend the request if there was a error in the connection

Do you know why it is getting a 401?

I thought we agreed that was the normal behavior with basic authentication
The client is is not manually handling the 401, it is done so using the C# libraries
https://docs.microsoft.com/en-us/dotnet/api/system.web.services.protocols.soaphttpclientprotocol?view=netframework-4.8

We are looking to test pre-emptive authentication to see if that helps
If we still see this IOExeption with the pre-emptive authentication, we can rule out the issue coming from the 401

@gregw
Copy link
Contributor

gregw commented Nov 12, 2020

@tchgitav
The connection was aborted because otherwise the server is vulnerable to a DOS attack.

Consider any server that uses BASIC authentication. An attacker can send an unauthenticated POST request with a 4GB body. Because it does not go to the applications, there is no change for the app to look at that and say - whoa that's too big I'm not going to consume that. Instead jetty is sending the 401. Now if jetty just tried to read that 4GB to keep the connection open, then a thread would be easilyt consumed for a long time. The attacker could pretty simply consume the thread pool of the server, whilst never passing authentication.

So instead, jetty tries to consume the request to keep the connection open, but if it cannot consume without blocking, it will instead abort the connection... which a server is always entitled to do. The PR we are working on tries to give a bit more notice by including a Connection: close header in the 401 response, but regardless the server is entitled to close that connection after sending the 401 response.

The problem for you however, is that the request is a POST, so that the client is not going to retry sending it when it sees a closed connection... not unless told to do so,

The fundamental problem is not the closing connection, but that the client will not retry a POST if it has sent it already. Preemptive auth should help. It may also help to use Expect: Continue in the request, so the client will send the headers only, then Jetty will send either a 100 Continue if authentication passes and the client can then send the body; or a 401 if authentication fails and the client should be smart enough to retry the POST with auth because it knows it never sent the body.

@tchgitav
Copy link
Author

@gregw
Thank you for your feedback

Enabling pre-emptive authenticate did seem to help us
Ran requests for several hours and did not see the connection close issue on the client side

I understand your point regarding the possibility of the server closing the connection due to the 401
Are you saying if it was a GET call instead, I would see different behavior?

It may also help to use Expect: Continue in the request, so the client will send the headers only, then Jetty will send either a 100 Continue if authentication passes and the client can then send the body; or a 401 if authentication fails and the client should be smart enough to retry the POST with auth because it knows it never sent the body.

I can pass that to the dev team. They are using the c# libraries so might not have the capability to do so

In regards to jetty closing the connection due to the 401, why do we see it intermittently
Why not more frequently as I've seen larger requests not running into this issue.

Also why did we not have issues with jetty 9.2.x; was it more relaxed in this connection close area?
Jetty 9.2.x was also returning a 401 to the client but we never observed this connection issue until moving to 9.4.x

@gregw
Copy link
Contributor

gregw commented Nov 13, 2020

@gregw
Enabling pre-emptive authenticate did seem to help us
Ran requests for several hours and did not see the connection close issue on the client side
Great!

I understand your point regarding the possibility of the server closing the connection due to the 401
Are you saying if it was a GET call instead, I would see different behavior?

GETs are safe and idempotent, so clients are allowed to retry them automatically. So your client should be able to retry on a new connection when it sees the 401 and closed connection.
However some clients may still not retry... depends on your client. It is allowed to retry with a GET, but it may not.

In regards to jetty closing the connection due to the 401, why do we see it intermittently
Why not more frequently as I've seen larger requests not running into this issue.

It depends on the speed of your network, the size of your OS buffers and dispatching of threads. It may be that sometimes the server is successfully able to consume all the content without blocking because it has all arrived and is in local buffers. But sometimes it may not be able to read it all without blocking, so it closes the connection instead of blocking.

Also why did we not have issues with jetty 9.2.x; was it more relaxed in this connection close area?
Jetty 9.2.x was also returning a 401 to the client but we never observed this connection issue until moving to 9.4.x

I think 9.2 just blocked reading and discarding the entire body. So it worked for you all the time, but the server is vulnerable to the DOS attack I described.

@tchgitav
Copy link
Author

tchgitav commented Nov 13, 2020

Thanks for concluding the cause of why we are seeing this issue.

Besides pre-emptive authentication is the only other client recourse the retry logic?

gregw added a commit that referenced this issue Nov 18, 2020
* Issue #5605 unconsumed input on sendError

Add Connection:close if content can't be consumed during a sendError. Processed after the request has returned to the container.

Signed-off-by: Greg Wilkins <gregw@webtide.com>

* Update from review

 + Add close on all uncommitted requests when content cannot be consumed.

* Update from review

 + fixed comment
 + space comma

* Only consume input in COMPLETE if response is >=200 (ie not an upgrade or similar)

* Updated to be less adventurous

I do not think it was valid to always consumeAll in COMPLETE as this could break upgrades with both 101s and 200s
Instead I have reverted to having this consumeAll logic only:
 + in sendError once control has passed back to the container and we are about to generate an error page.
 + in front of all the sendRedirection that we do without calling the application first.

Extra tests also added

* Updated to be less adventurous

reverted test

* Testcase for odd sendError(400) issue.

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>

* Fix for odd sendError(400) issue.

Signed-off-by: Simone Bordet <simone.bordet@gmail.com>

* Testcase for odd sendError(400) issue.

Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>

* Always try to consumeAll on all requests

* Refinements after testing in 10

* Refinements after testing in 10

Fixed test

* Fixed comment from review

* Updates from review

+ added redirect methods that consumeAll
+ ensureContentConsumedOrConnectionClose renamed to ensureConsumeAllOrNotPersistent
+ ensureConsumeAllOrNotPersistent now handles HTTP/1.0 and HTTP/1.1 differently

* better consumeAll implementation

* update from review

 + better javadoc
 + filter out keep-alive
 + added more tests

* update from review

 + better javadoc

* update from review

 + fixed form redirection test for http 1.0 and 1.1

* update from review

 + HttpGenerator removes keep-alive if close present
 + Use isRedirection

Co-authored-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>
Co-authored-by: Simone Bordet <simone.bordet@gmail.com>
joakime added a commit that referenced this issue Nov 18, 2020
Signed-off-by: Joakim Erdfelt <joakim.erdfelt@gmail.com>
sbordet added a commit that referenced this issue Nov 18, 2020
…st parsing.

Writing content in separate writes may result in the server
only reading partial content, producing a response with
`Connection: close` that would cause the client socket to
stop receiving data for the next response, failing the test.

Signed-off-by: Simone Bordet <simone.bordet@gmail.com>
@jaroslawr
Copy link
Contributor

jaroslawr commented Feb 15, 2021

@lorban Small update, while we can now run jetty 10.x for hours which was not possible earlier, some threads still get stuck, either like this:

"request-processing-thread-225" #1053 daemon prio=5 os_prio=0 cpu=1362794.67ms elapsed=15260.89s tid=0x00007fa5bc024800 nid=0x4ae waiting on condition  [0x00007fa50a0cb000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@11.0.5/Native Method)
        - parking to wait for  <0x0000001224309428> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.5/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(java.base@11.0.5/AbstractQueuedSynchronizer.java:2081)
        at org.eclipse.jetty.util.SharedBlockingCallback.acquire(SharedBlockingCallback.java:65)
        at org.eclipse.jetty.server.HttpOutput.close(HttpOutput.java:572)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet.doProcessRequest(AbstractProcessingServlet.java:262)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet.doProcessRequestInScopeLog(AbstractProcessingServlet.java:194)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet.lambda$processRequest$1(AbstractProcessingServlet.java:177)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet$$Lambda$1373/0x00000017c1890040.run(Unknown Source)
        at com.rtbhouse.utils.executor.ThreadPoolRequestProcessingExecutor.lambda$execute$0(ThreadPoolRequestProcessingExecutor.java:47)
        at com.rtbhouse.utils.executor.ThreadPoolRequestProcessingExecutor$$Lambda$1374/0x00000017c1890440.run(Unknown Source)
        at java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.5/Executors.java:515)
        at java.util.concurrent.FutureTask.run(java.base@11.0.5/FutureTask.java:264)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.5/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.5/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.5/Thread.java:834)

or like this:

"request-processing-thread-198" #1002 daemon prio=5 os_prio=0 cpu=293215.86ms elapsed=15260.95s tid=0x00007fa5bc01f000 nid=0x47b waiting on condition  [0x00007fa50d3fe000]
   java.lang.Thread.State: WAITING (parking)
        at jdk.internal.misc.Unsafe.park(java.base@11.0.5/Native Method)
        - parking to wait for  <0x0000001224306be8> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(java.base@11.0.5/LockSupport.java:194)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInterrupt(java.base@11.0.5/AbstractQueuedSynchronizer.java:885)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(java.base@11.0.5/AbstractQueuedSynchronizer.java:917)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(java.base@11.0.5/AbstractQueuedSynchronizer.java:1240)
        at java.util.concurrent.locks.ReentrantLock.lock(java.base@11.0.5/ReentrantLock.java:267)
        at org.eclipse.jetty.util.thread.AutoLock.lock(AutoLock.java:44)
        at org.eclipse.jetty.server.HttpChannelState.lock(HttpChannelState.java:158)
        at org.eclipse.jetty.server.HttpChannelState.commitResponse(HttpChannelState.java:270)
        at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:914)
        at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:1017)
        at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor$GzipBufferCB.process(GzipHttpOutputInterceptor.java:384)
        at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:232)
        at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:214)
        at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor.gzip(GzipHttpOutputInterceptor.java:127)
        at org.eclipse.jetty.server.handler.gzip.GzipHttpOutputInterceptor.write(GzipHttpOutputInterceptor.java:109)
        at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:270)
        at org.eclipse.jetty.server.HttpOutput.channelWrite(HttpOutput.java:254)
        at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:881)
        at java.io.OutputStream.write(java.base@11.0.5/OutputStream.java:122)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet.doProcessRequest(AbstractProcessingServlet.java:262)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet.doProcessRequestInScopeLog(AbstractProcessingServlet.java:194)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet.lambda$processRequest$1(AbstractProcessingServlet.java:177)
        at com.adpilot.rtb.ad.servlet.AbstractProcessingServlet$$Lambda$1373/0x00000017c1890040.run(Unknown Source)
        at com.rtbhouse.utils.executor.ThreadPoolRequestProcessingExecutor.lambda$execute$0(ThreadPoolRequestProcessingExecutor.java:47)
        at com.rtbhouse.utils.executor.ThreadPoolRequestProcessingExecutor$$Lambda$1374/0x00000017c1890440.run(Unknown Source)
        at java.util.concurrent.Executors$RunnableAdapter.call(java.base@11.0.5/Executors.java:515)
        at java.util.concurrent.FutureTask.run(java.base@11.0.5/FutureTask.java:264)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(java.base@11.0.5/ThreadPoolExecutor.java:1128)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(java.base@11.0.5/ThreadPoolExecutor.java:628)
        at java.lang.Thread.run(java.base@11.0.5/Thread.java:834)

This is with jetty at https://github.com/eclipse/jetty.project/tree/bf9318f2b8a53c8d8c1d572ad7f3e982e2613c82, without the latest commit 4ec51fb, I will retest the newest version...

@jaroslawr
Copy link
Contributor

(I meant to say without 4ec51fb, bf9318f was included in the tests)

@lorban
Copy link
Contributor

lorban commented Feb 15, 2021

@jaroslawr I just pushed what should be the final version in my PR with some cleanups.

@jaroslawr
Copy link
Contributor

@lorban Thanks, we are testing this version, it works stable so far, but this last issue is sporadic enough it will take a few days before it can be crossed off for good.

lorban added a commit that referenced this issue Feb 17, 2021
lorban added a commit that referenced this issue Feb 17, 2021
…d-threads

Jetty 10.0.x Fix #5605 Unblock non container Threads
@jaroslawr
Copy link
Contributor

@lorban Everything has been working great since the last fix, thank you!

RokLenarcic pushed a commit to RokLenarcic/zookeeper that referenced this issue Aug 31, 2022
…02 - CVE-2020-27218

Bump jetty.version to 9.4.35.v20201120.

The [release notes](https://github.com/eclipse/jetty.project/releases/tag/jetty-9.4.35.v20201120)
mention [issue 5605](jetty/jetty.project#5605):

> java.io.IOException: unconsumed input during http request parsing

which seems to match the description of
[CVE-2020-27218](http://cve.circl.lu/cve/CVE-2020-27218)

Author: Damien Diederen <dd@crosstwine.com>

Reviewers: Enrico Olivelli <eolivelli@apache.org>, Norbert Kalmar <nkalmar@apache.org>, Andor Molnar <anmolnar@apache.org>, Patrick D. Hunt <phunt@apache.org>

Closes apache#1552 from ztzg/jetty-upgrade-CVE-2020-27218
RokLenarcic pushed a commit to RokLenarcic/zookeeper that referenced this issue Aug 31, 2022
…02 - CVE-2020-27218

Bump jetty.version to 9.4.35.v20201120.

The [release notes](https://github.com/eclipse/jetty.project/releases/tag/jetty-9.4.35.v20201120)
mention [issue 5605](jetty/jetty.project#5605):

> java.io.IOException: unconsumed input during http request parsing

which seems to match the description of
[CVE-2020-27218](http://cve.circl.lu/cve/CVE-2020-27218)

Author: Damien Diederen <dd@crosstwine.com>

Reviewers: Enrico Olivelli <eolivelli@apache.org>, Norbert Kalmar <nkalmar@apache.org>, Andor Molnar <anmolnar@apache.org>, Patrick D. Hunt <phunt@apache.org>

Closes apache#1552 from ztzg/jetty-upgrade-CVE-2020-27218
RokLenarcic pushed a commit to RokLenarcic/zookeeper that referenced this issue Aug 31, 2022
…02 - CVE-2020-27218

Bump jetty.version to 9.4.35.v20201120.

The [release notes](https://github.com/eclipse/jetty.project/releases/tag/jetty-9.4.35.v20201120)
mention [issue 5605](jetty/jetty.project#5605):

> java.io.IOException: unconsumed input during http request parsing

which seems to match the description of
[CVE-2020-27218](http://cve.circl.lu/cve/CVE-2020-27218)

Author: Damien Diederen <dd@crosstwine.com>

Reviewers: Enrico Olivelli <eolivelli@apache.org>, Norbert Kalmar <nkalmar@apache.org>, Andor Molnar <anmolnar@apache.org>, Patrick D. Hunt <phunt@apache.org>

Closes apache#1552 from ztzg/jetty-upgrade-CVE-2020-27218
RokLenarcic pushed a commit to RokLenarcic/zookeeper that referenced this issue Sep 3, 2022
…02 - CVE-2020-27218

Bump jetty.version to 9.4.35.v20201120.

The [release notes](https://github.com/eclipse/jetty.project/releases/tag/jetty-9.4.35.v20201120)
mention [issue 5605](jetty/jetty.project#5605):

> java.io.IOException: unconsumed input during http request parsing

which seems to match the description of
[CVE-2020-27218](http://cve.circl.lu/cve/CVE-2020-27218)

Author: Damien Diederen <dd@crosstwine.com>

Reviewers: Enrico Olivelli <eolivelli@apache.org>, Norbert Kalmar <nkalmar@apache.org>, Andor Molnar <anmolnar@apache.org>, Patrick D. Hunt <phunt@apache.org>

Closes apache#1552 from ztzg/jetty-upgrade-CVE-2020-27218
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment