search

eclipse-ee4j / tyrus

Tyrus
Other
114 stars 36 forks source link

Tyrusclient handles same 401 not authorize response twice #608

Open glassfishrobot opened 8 years ago

glassfishrobot commented 8 years ago

Looks like Tyrus client handles same 401 not authorize response twice.

Socket acquisition is protected with OAuth2 on server side.

Firs time client tries to obtain web socket server returns "401 not Authorized". Client sends another request with token. Server returns "101 protocol change" but sometimes client handles the same 401 response that was sent previously and closes connection

See logs from client and Wirwshark capture in attach

Affected Versions

[1.13]

glassfishrobot commented 6 years ago
glassfishrobot commented 8 years ago

@glassfishrobot Commented Reported by Dmytro_Mrachkovskyi

glassfishrobot commented 8 years ago

@glassfishrobot Commented dmytro_mrachkovskyi said: Client Logs

2016-09-14 17:42:59:451 [http-nio-7080-exec-2] INFO o.g.tyrus.client.ClientManager - Provider class loaded: org.glassfish.tyrus.container.grizzly.client.GrizzlyClientContainer 2016-09-14 17:42:59:504 [http-nio-7080-exec-2] DEBUG o.g.t.c.g.client.GrizzlyClientSocket - Not using proxy for URI 'ws://10.47.114.11:8086/websocket/sample-websocket/'. 2016-09-14 17:42:59:656 [http-nio-7080-exec-2] INFO o.g.t.c.g.client.GrizzlyClientSocket - Connecting to 'ws://10.47.114.11:8086/websocket/sample-websocket/' (no proxy). 2016-09-14 17:42:59:879 [http-nio-7080-exec-2] INFO o.g.t.c.g.client.GrizzlyClientSocket - Connected to '/10.47.114.11:8086'. 2016-09-14 17:43:00:051 [Grizzly(1)] DEBUG o.g.t.c.g.client.GrizzlyClientFilter - handleRead websocket: null content-size=102 headers= HttpResponsePacket ( status=401 reason=Unauthorized protocol=HTTP/1.1 content-length=-1 committed=false headers=[ date=Wed, 14 Sep 2016 14:42:59 GMT x-content-type-options=nosniff x-xss-protection=1; mode=block cache-control=no-cache, no-store, max-age=0, must-revalidate pragma=no-cache expires=Thu, 01 Jan 1970 00:00:00 GMT x-frame-options=SAMEORIGIN set-cookie=JSESSIONID=qn1oo42i28l11m3xsis0daeff;Path=/ www-authenticate=Bearer realm="vos", error="unauthorized", error_description="Full authentication is required to access this resource" content-type=application/json;charset=UTF-8 transfer-encoding=chunked server=Jetty(9.3.z-SNAPSHOT)] ) 2016-09-14 17:43:00:059 [Grizzly(1)] DEBUG o.g.t.c.g.client.GrizzlyClientSocket - Not using proxy for URI 'ws://10.47.114.11:8086/websocket/sample-websocket/'. 2016-09-14 17:43:00:064 [Grizzly(1)] INFO o.g.t.c.g.client.GrizzlyClientSocket - Connecting to 'ws://10.47.114.11:8086/websocket/sample-websocket/' (no proxy). 2016-09-14 17:43:00:194 [Grizzly(1)] INFO o.g.t.c.g.client.GrizzlyClientSocket - Connected to '/10.47.114.11:8086'. 2016-09-14 17:43:00:196 [Grizzly(1)] DEBUG o.g.t.c.g.client.GrizzlyClientFilter - handleRead websocket: null content-size=0 headers= HttpResponsePacket ( status=401 reason=Unauthorized protocol=HTTP/1.1 content-length=-1 committed=false headers=[ date=Wed, 14 Sep 2016 14:42:59 GMT x-content-type-options=nosniff x-xss-protection=1; mode=block cache-control=no-cache, no-store, max-age=0, must-revalidate pragma=no-cache expires=Thu, 01 Jan 1970 00:00:00 GMT x-frame-options=SAMEORIGIN set-cookie=JSESSIONID=qn1oo42i28l11m3xsis0daeff;Path=/ www-authenticate=Bearer realm="vos", error="unauthorized", error_description="Full authentication is required to access this resource" content-type=application/json;charset=UTF-8 transfer-encoding=chunked server=Jetty(9.3.z-SNAPSHOT)] ) 2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - * Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [11 ms]: Redirect enabled: false 2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - > Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [22 ms]: Sending handshake request:

GET ws://10.47.114.11:8086/websocket/sample-websocket/ Connection: Upgrade Host: 10.47.114.11:8086 Origin: 10.47.114.11:8086 Sec-WebSocket-Key: 0xknu45JGZSHo7wCoQvOYA== Sec-WebSocket-Version: 13 Upgrade: websocket

2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - < Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [574 ms]: Received handshake response: < 401 < cache-control: no-cache, no-store, max-age=0, must-revalidate, no-store < content-type: application/json;charset=UTF-8 < date: Wed, 14 Sep 2016 14:42:59 GMT < expires: Thu, 01 Jan 1970 00:00:00 GMT < pragma: no-cache, no-cache < server: Jetty(9.3.z-SNAPSHOT) < set-cookie: JSESSIONID=qn1oo42i28l11m3xsis0daeff;Path=/ < transfer-encoding: chunked < www-authenticate: Bearer realm="vos", error="unauthorized", error_description="Full authentication is required to access this resource" < x-content-type-options: nosniff < x-frame-options: SAMEORIGIN < x-xss-protection: 1; mode=block

2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - > Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [574 ms]: Using authentication config: AuthConfig

{Bearer->client.OAuthAuthenticator, Digest->org.glassfish.tyrus.client.auth.DigestAuthenticator}

2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - > Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [574 ms]: Using authentication scheme: Bearer 2016-09-14 17:43:00:202 [Grizzly(1)] INFO o.g.tyrus.client.TyrusClientEngine - > Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [577 ms]: Using authenticator: client.OAuthAuthenticator 2016-09-14 17:43:00:202 [Grizzly(1)] INFO o.g.tyrus.client.TyrusClientEngine - > Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [577 ms]: Using credentials: null 2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - > Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [577 ms]: Sending handshake request:

GET ws://10.47.114.11:8086/websocket/sample-websocket/ Authorization: ***** Connection: Upgrade Host: 10.47.114.11:8086 Origin: 10.47.114.11:8086 Sec-WebSocket-Key: 0xknu45JGZSHo7wCoQvOYA== Sec-WebSocket-Version: 13 Upgrade: websocket

2016-09-14 17:43:00:202 [Grizzly(1)] DEBUG o.g.tyrus.client.TyrusClientEngine - < Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [715 ms]: Received handshake response: < 401 < cache-control: no-cache, no-store, max-age=0, must-revalidate, no-store < content-type: application/json;charset=UTF-8 < date: Wed, 14 Sep 2016 14:42:59 GMT < expires: Thu, 01 Jan 1970 00:00:00 GMT < pragma: no-cache, no-cache < server: Jetty(9.3.z-SNAPSHOT) < set-cookie: JSESSIONID=qn1oo42i28l11m3xsis0daeff;Path=/ < transfer-encoding: chunked < www-authenticate: Bearer realm="vos", error="unauthorized", error_description="Full authentication is required to access this resource" < x-content-type-options: nosniff < x-frame-options: SAMEORIGIN < x-xss-protection: 1; mode=block

2016-09-14 17:43:00:205 [http-nio-7080-exec-2] ERROR o.a.c.c.C.[.[.[.[dispatcherServlet] - Servlet.service() for servlet [dispatcherServlet] in context with path [/client] threw exception [Request processing failed; nested exception is java.lang.RuntimeException: javax.websocket.DeploymentException: Handshake error.] with root cause org.glassfish.tyrus.client.auth.AuthenticationException: Authentication failed. at org.glassfish.tyrus.client.TyrusClientEngine.handleAuth(TyrusClientEngine.java:353) at org.glassfish.tyrus.client.TyrusClientEngine.processResponse(TyrusClientEngine.java:286) at org.glassfish.tyrus.container.grizzly.client.GrizzlyClientFilter.handleHandshake(GrizzlyClientFilter.java:346) at org.glassfish.tyrus.container.grizzly.client.GrizzlyClientFilter.handleRead(GrizzlyClientFilter.java:315) at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:591) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:571) at java.lang.Thread.run(Thread.java:745) 2016-09-14 17:43:00:334 [Grizzly(2)] DEBUG o.g.t.c.g.client.GrizzlyClientFilter - handleRead websocket: null content-size=0 headers= HttpResponsePacket ( status=101 reason=Switching Protocols protocol=HTTP/1.1 content-length=-1 committed=false headers=[ date=Wed, 14 Sep 2016 14:43:00 GMT x-content-type-options=nosniff x-xss-protection=1; mode=block cache-control=no-cache, no-store, max-age=0, must-revalidate pragma=no-cache expires=Thu, 01 Jan 1970 00:00:00 GMT x-frame-options=SAMEORIGIN set-cookie=JSESSIONID=zp3l248c5uedr11erqoymkgi;Path=/ connection=Upgrade sec-websocket-accept=u0hHR9I3Mt5Ye0ZA9//08ICXExw= server=Jetty(9.3.z-SNAPSHOT) upgrade=WebSocket] ) 2016-09-14 17:43:00:334 [Grizzly(2)] DEBUG o.g.tyrus.client.TyrusClientEngine - < Session a21a3e32-988f-44d1-b9cb-72f2423f1260 [853 ms]: Received handshake response: < 101 < cache-control: no-cache, no-store, max-age=0, must-revalidate < connection: Upgrade < date: Wed, 14 Sep 2016 14:43:00 GMT < expires: Thu, 01 Jan 1970 00:00:00 GMT < pragma: no-cache < sec-websocket-accept: u0hHR9I3Mt5Ye0ZA9//08ICXExw= < server: Jetty(9.3.z-SNAPSHOT) < set-cookie: JSESSIONID=zp3l248c5uedr11erqoymkgi;Path=/ < upgrade: WebSocket < x-content-type-options: nosniff < x-frame-options: SAMEORIGIN < x-xss-protection: 1; mode=block

2016-09-14 17:43:00:344 [Grizzly(2)] WARN o.g.g.filterchain.DefaultFilterChain - GRIZZLY0013: Exception during FilterChain execution java.lang.IllegalStateException: null at org.glassfish.tyrus.client.TyrusClientEngine.processResponse(TyrusClientEngine.java:331) at org.glassfish.tyrus.container.grizzly.client.GrizzlyClientFilter.handleHandshake(GrizzlyClientFilter.java:346) at org.glassfish.tyrus.container.grizzly.client.GrizzlyClientFilter.handleRead(GrizzlyClientFilter.java:315) at org.glassfish.grizzly.filterchain.ExecutorResolver$9.execute(ExecutorResolver.java:119) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeFilter(DefaultFilterChain.java:283) at org.glassfish.grizzly.filterchain.DefaultFilterChain.executeChainPart(DefaultFilterChain.java:200) at org.glassfish.grizzly.filterchain.DefaultFilterChain.execute(DefaultFilterChain.java:132) at org.glassfish.grizzly.filterchain.DefaultFilterChain.process(DefaultFilterChain.java:111) at org.glassfish.grizzly.ProcessorExecutor.execute(ProcessorExecutor.java:77) at org.glassfish.grizzly.nio.transport.TCPNIOTransport.fireIOEvent(TCPNIOTransport.java:536) at org.glassfish.grizzly.strategies.AbstractIOStrategy.fireIOEvent(AbstractIOStrategy.java:112) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.run0(WorkerThreadIOStrategy.java:117) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy.access$100(WorkerThreadIOStrategy.java:56) at org.glassfish.grizzly.strategies.WorkerThreadIOStrategy$WorkerThreadRunnable.run(WorkerThreadIOStrategy.java:137) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.doWork(AbstractThreadPool.java:591) at org.glassfish.grizzly.threadpool.AbstractThreadPool$Worker.run(AbstractThreadPool.java:571) at java.lang.Thread.run(Thread.java:745)

glassfishrobot commented 8 years ago

@glassfishrobot Commented dmytro_mrachkovskyi said: unable to attach Wireshrak capture but from what I see there is only one 401 response is send, when client first time tries to obtain web-socket without Authorization header. Than 101 is returned.

This issue is not constantly reproduces

glassfishrobot commented 7 years ago

@glassfishrobot Commented This issue was imported from java.net JIRA TYRUS-431

vikinghawk commented 6 years ago

I ran into this as well. The problem is when the server returns the original 401 response with "transfer-encoding: chunked" header. After the 2nd request with a valid authz header, tyrus reads the first 401 response again and then reads the new 101 response and throws an IllegalStateException. This was easily reproducible for me and I fixed by changing my server side code to always return an accurate "Content-Length" header and never "transfer-encoding: chunk".

Note: this was with the grizzly client. The jdk client did not have the same issue.