JDK-8236859 : WebSocket over authenticating proxy fails with NPE
- Type: Bug
- Component: core-libs
- Sub-Component: java.net
- Affected Version: 11
- Priority: P4
- Status: Resolved
- Resolution: Fixed
- OS: generic
- CPU: x86_64
- Submitted: 2020-01-08
- Updated: 2022-10-14
- Resolved: 2020-01-17
The Version table provides details related to the release that this issue/RFE will be addressed.
Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.
To download the current JDK release, click here.
Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.
To download the current JDK release, click here.
| JDK 11 | JDK 13 | JDK 15 |
|---|---|---|
| 11.0.12Fixed | 13.0.6Fixed | 15 b07Fixed  |
Related Reports
|
Duplicate :
|
|
|
Relates :
|
|
|
Relates :
|
Description
ADDITIONAL SYSTEM INFORMATION :
Platform independent, tested on Windows 10, Debian, Centos 8, Fedora 30
openjdk version "11.0.5" 2019-10-15
Tested with version 11, 12, 13, 14 EA and and 15 EA
A DESCRIPTION OF THE PROBLEM :
When using java.net.httpclient to connect to WebSocket via proxy that requires authentication it fails with NPE when handling 407 (Proxy Authentication Required)
It looks like problem is in handshake handling code that tries to do debug logging with object that is null.
Even after patching RawChanelTube.java to prevent NPE, it still fails with different error
"CheckFailedException: Unexpected HTTP response status code 407"
STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
When you try to connect to websocket via proxy that requires authentication, http client fails to properly handle 407 (proxy auth required) response as result fails to retry with properly set auth headers.
EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Socket is opened and works.
ACTUAL -
with debug enabled this is the log
DEBUG: [HttpClient-1-SelectorManager] [2s 254ms] PlainHttpConnection(SocketTube(4)) ConnectEvent: finishing connect
DEBUG: [HttpClient-1-SelectorManager] [2s 254ms] PlainHttpConnection(SocketTube(4)) ConnectEvent: connect finished: true Local addr: /192.168.42.39:56565
DEBUG: [pool-2-thread-3] [2s 255ms] PlainHttpConnection(SocketTube(4)) finishConnect, setting connected=true
DEBUG: [pool-2-thread-3] [2s 255ms] PlainTunnelingConnection(SocketTube(4)) sending HTTP/1.1 CONNECT
DEBUG: [pool-2-thread-3] [2s 255ms] Exchange establishing exchange for socket://ws-feed.pro.coinbase.com:443/ CONNECT,
proxy=null
DEBUG: [pool-2-thread-3] [2s 255ms] ExchangeImpl get: HTTP/1.1: new Http1Exchange
DEBUG: [pool-2-thread-3] [2s 255ms] Exchange checkFor407: all clear
DEBUG: [pool-2-thread-3] [2s 255ms] Http1Exchange Sending headers only
DEBUG: [pool-2-thread-3] [2s 255ms] Http1AsyncReceiver(SocketTube(4)) Subscribed pending jdk.internal.net.http.Http1Response$HeadersReader@6bc9a6dd queue.isEmpty: true
DEBUG: [pool-2-thread-3] [2s 255ms] Http1AsyncReceiver(SocketTube(4)) delegate is now jdk.internal.net.http.Http1Response$HeadersReader@6bc9a6dd, demand=1, canRequestMore=true, queue.isEmpty=true
DEBUG: [pool-2-thread-3] [2s 255ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1
DEBUG: [pool-2-thread-3] [2s 255ms] Http1AsyncReceiver(SocketTube(4)) checkRequestMore: canRequestMore=true, hasDemand=true
DEBUG: [pool-2-thread-3] [2s 255ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1
DEBUG: [pool-2-thread-3] [2s 255ms] Http1AsyncReceiver(SocketTube(4)) checkRequestMore: canRequestMore=true, hasDemand=true
DEBUG: [pool-2-thread-3] [2s 255ms] Http1Exchange response created in advance
DEBUG: [pool-2-thread-3] [2s 255ms] Http1Exchange SocketTube(4) connecting flows
DEBUG: [pool-2-thread-3] [2s 255ms] SocketTube(4) connecting flows
DEBUG: [pool-2-thread-3] [2s 255ms] SocketTube(4) read publisher got subscriber
DEBUG: [pool-2-thread-3] [2s 255ms] SocketTube(4) registering subscribe event
DEBUG: [pool-2-thread-3] [2s 255ms] SocketTube(4) leaving read.subscribe: Reading: [ops=0, demand=0, stopped=false], Writing: [ops=0, demand=0]
DEBUG: [pool-2-thread-3] [2s 255ms] Http1Publisher(SocketTube(4)) got subscriber: SocketTube(4)
DEBUG: [HttpClient-1-SelectorManager] [2s 255ms] SocketTube(4) subscribe event raised
DEBUG: [pool-2-thread-3] [2s 256ms] SocketTube(4) subscribed for writing
DEBUG: [pool-2-thread-3] [2s 256ms] SocketTube(4) write: registering startSubscription event
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) handling pending subscription for jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@58d43ff8
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) read demand reset to 0
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Exchange requestAction.headers
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) calling onSubscribe
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] Http1AsyncReceiver(SocketTube(4)) Received onSubscribed from upstream
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) onSubscribe called
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) pending subscriber subscribed
DEBUG: [pool-2-thread-1] [2s 256ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) write: starting subscription
DEBUG: [pool-2-thread-1] [2s 256ms] Http1AsyncReceiver(SocketTube(4)) checkRequestMore: canRequestMore=true, hasDemand=true
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Exchange setting outgoing with headers
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SocketTube(4) write: offloading requestMore
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=85 cap=85]], throwable=null]
DEBUG: [pool-2-thread-1] [2s 256ms] Http1AsyncReceiver(SocketTube(4)) Http1TubeSubscriber: requesting one more from upstream
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Publisher(SocketTube(4)) WriteTask
DEBUG: [pool-2-thread-2] [2s 256ms] SocketTube(4) write: requesting more...
DEBUG: [pool-2-thread-1] [2s 256ms] SocketTube(4) got some demand for reading
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Publisher(SocketTube(4)) hasOutgoing = true
DEBUG: [pool-2-thread-1] [2s 256ms] SocketTube(4) resuming read event
DEBUG: [pool-2-thread-2] [2s 256ms] Http1Publisher(SocketTube(4)) subscription request(1), demand=1
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Exchange initiating completion of headersSentCF
DEBUG: [pool-2-thread-1] [2s 256ms] SocketTube(4) leaving request(1): Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [pool-2-thread-3] [2s 256ms] Http1Publisher(SocketTube(4)) onNext with 85 bytes
DEBUG: [pool-2-thread-2] [2s 256ms] SocketTube(4) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [HttpClient-1-SelectorManager] [2s 256ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@1b4a4034 for 1 (true)
DEBUG: [pool-2-thread-3] [2s 257ms] SocketTube(4) trying to write: 85
DEBUG: [pool-2-thread-3] [2s 257ms] SocketTube(4) wrote: 85
DEBUG: [pool-2-thread-3] [2s 257ms] SocketTube(4) write: requesting more...
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Publisher(SocketTube(4)) subscription request(1), demand=1
DEBUG: [pool-2-thread-3] [2s 257ms] SocketTube(4) leaving requestMore: Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [pool-2-thread-3] [2s 257ms] SocketTube(4) leaving w.onNext Reading: [ops=1, demand=1, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Publisher(SocketTube(4)) WriteTask
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Publisher(SocketTube(4)) hasOutgoing = false
DEBUG: [pool-2-thread-3] [2s 257ms] Exchange checkFor407: all clear
DEBUG: [pool-2-thread-3] [2s 257ms] Exchange sendRequestBody
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Exchange sendBodyAsync
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Exchange bodySubscriber is null
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Exchange appending to outgoing DataPair [data=[java.nio.HeapByteBuffer[pos=0 lim=0 cap=0]], throwable=null]
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Publisher(SocketTube(4)) WriteTask
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Publisher(SocketTube(4)) hasOutgoing = true
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Exchange initiating completion of bodySentCF
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Publisher(SocketTube(4)) completed, stopping jdk.internal.net.http.common.SequentialScheduler@5dbf8a63
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Exchange sendBodyAsync completed successfully
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Exchange reading headers
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Response(id=8, PlainHttpConnection(SocketTube(4))) Reading Headers: (remaining: 0) READING_HEADERS
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Response(id=8, PlainHttpConnection(SocketTube(4))) First time around
DEBUG: [pool-2-thread-3] [2s 257ms] Http1Response(id=8, PlainHttpConnection(SocketTube(4))) headersReader is not yet completed
DEBUG: [HttpClient-1-SelectorManager] [2s 300ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@1b4a4034 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [2s 300ms] SocketTube(4) read bytes: 3628
DEBUG: [HttpClient-1-SelectorManager] [2s 300ms] Http1AsyncReceiver(SocketTube(4)) Putting 3628 bytes into the queue
DEBUG: [HttpClient-1-SelectorManager] [2s 300ms] SocketTube(4) resuming read event
DEBUG: [HttpClient-1-SelectorManager] [2s 300ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@1b4a4034 for 1 (false)
DEBUG: [pool-2-thread-1] [2s 300ms] Http1AsyncReceiver(SocketTube(4)) Got 3628 bytes for delegate jdk.internal.net.http.Http1Response$HeadersReader@6bc9a6dd
DEBUG: [HttpClient-1-SelectorManager] [2s 300ms] SocketTube(4) leaving read() loop after onNext: Reading: [ops=1, demand=0, stopped=false], Writing: [ops=0, demand=1]
DEBUG: [pool-2-thread-1] [2s 301ms] Http1AsyncReceiver(SocketTube(4)) downstream subscription demand is 1
DEBUG: [pool-2-thread-1] [2s 301ms] Http1AsyncReceiver(SocketTube(4)) Forwarding 3628 bytes to delegate jdk.internal.net.http.Http1Response$HeadersReader@6bc9a6dd
DEBUG: [pool-2-thread-1] [2s 301ms] Http1Response(id=8, PlainHttpConnection(SocketTube(4))) Sending 3628/3628 bytes to header parser
DEBUG: [pool-2-thread-1] [2s 301ms] Http1Response(id=8, PlainHttpConnection(SocketTube(4))) Parsing headers completed. bytes=406
DEBUG: [pool-2-thread-1] [2s 301ms] Http1AsyncReceiver(SocketTube(4)) Unsubscribed jdk.internal.net.http.Http1Response$HeadersReader@6bc9a6dd
DEBUG: [pool-2-thread-1] [2s 301ms] Http1Response(id=8, PlainHttpConnection(SocketTube(4))) Reading Headers: creating Response object; state is now READING_BODY
DEBUG: [pool-2-thread-1] [2s 302ms] Http1Exchange getResponseAsync completed successfully
DEBUG: [pool-2-thread-1] [2s 302ms] PlainTunnelingConnection(SocketTube(4)) got response: 407
DEBUG: [pool-2-thread-1] [2s 302ms] PlainHttpConnection(SocketTube(4)) Closing channel: channel registered with selector, key.interestOps=1, sa.interestOps=1
DEBUG: [pool-2-thread-1] [2s 302ms] SocketTube(4) got read error: java.io.IOException: connection closed locally
DEBUG: [pool-2-thread-1] [2s 302ms] SocketTube(4) pausing read event
DEBUG: [pool-2-thread-1] [2s 303ms] SocketTube(4) Sending error java.io.IOException: connection closed locally to subscriber jdk.internal.net.http.Http1AsyncReceiver$Http1TubeSubscriber@58d43ff8
DEBUG: [pool-2-thread-1] [2s 303ms] SocketTube(4) forwarding error to subscriber: java.io.IOException: connection closed locally
DEBUG: [pool-2-thread-1] [2s 303ms] Http1AsyncReceiver(SocketTube(4)) onError: java.io.IOException: connection closed locally
DEBUG: [HttpClient-1-SelectorManager] [2s 303ms] SelectorAttachment Registering jdk.internal.net.http.SocketTube$InternalReadPublisher$ReadEvent@1b4a4034 for 0 (false)
DEBUG: [HttpClient-1-SelectorManager] [2s 303ms] SocketTube(4) abort: java.nio.channels.ClosedChannelException
DEBUG: [HttpClient-1-SelectorManager] [2s 303ms] HttpClientImpl(1) Got java.io.IOException while handling registration events
DEBUG: [pool-2-thread-1] [2s 303ms] Http1AsyncReceiver(SocketTube(4)) recorded java.io.IOException: connection closed locally
delegate: null queue.isEmpty: false java.io.IOException: connection closed locally
DEBUG: [HttpClient-1-SelectorManager] [2s 303ms] SocketTube(4) abort: java.io.IOException: Channel closed
java.io.IOException: connection closed locally
at java.net.http/jdk.internal.net.http.SocketTube.signalClosed(SocketTube.java:157)
at java.net.http/jdk.internal.net.http.PlainHttpConnection.close(PlainHttpConnection.java:277)
at java.net.http/jdk.internal.net.http.Http1Response.ignoreBody(Http1Response.java:264)
at java.net.http/jdk.internal.net.http.Http1Exchange.ignoreBody(Http1Exchange.java:383)
at java.net.http/jdk.internal.net.http.Exchange.ignoreBody(Exchange.java:187)
at java.net.http/jdk.internal.net.http.PlainTunnelingConnection.lambda$connectAsync$2(PlainTunnelingConnection.java:84)
at java.base/java.util.concurrent.CompletableFuture$UniCompose.tryFire(CompletableFuture.java:1146)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.postFire(CompletableFuture.java:610)
at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:649)
at java.base/java.util.concurrent.CompletableFuture$Completion.run(CompletableFuture.java:478)
at java.net.http/jdk.internal.net.http.HttpClientImpl$DelegatingExecutor.execute(HttpClientImpl.java:155)
at java.base/java.util.concurrent.CompletableFuture$UniCompletion.claim(CompletableFuture.java:568)
at java.base/java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:638)
at java.base/java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:506)
at java.base/java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:2144)
at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.handle(Http1Response.java:686)
at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.handle(Http1Response.java:612)
at java.net.http/jdk.internal.net.http.Http1Response$Receiver.accept(Http1Response.java:603)
at java.net.http/jdk.internal.net.http.Http1Response$HeadersReader.tryAsyncReceive(Http1Response.java:659)
at java.net.http/jdk.internal.net.http.Http1AsyncReceiver.flush(Http1AsyncReceiver.java:233)
at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SynchronizedRestartableTask.run(SequentialScheduler.java:175)
at java.net.http/jdk.internal.net.http.common.SequentialScheduler$CompleteRestartableTask.run(SequentialScheduler.java:147)
at java.net.http/jdk.internal.net.http.common.SequentialScheduler$SchedulableTask.run(SequentialScheduler.java:198)
at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:830)
---------- BEGIN SOURCE ----------
var httpClient = HttpClient.newBuilder()
.proxy(...) // use proxy that requires auth
.authenticator(new java.net.Authenticator() {
public PasswordAuthentication getPasswordAuthentication() {
return this.getRequestorType() == RequestorType.PROXY ? new PasswordAuthentication("proxyUser", "proxyPass".toCharArray()) : null;
})
.build();
var webSocket = httpClient.newWebSocketBuilder()
.buildAsync(URI.create("wss://url-to-webSocket"), new WebSocket.Listener() {
@Override
public void onOpen(WebSocket webSocket) {
webSocket.request(1);
System.out.println("Socket opened");
}
})
.join();
---------- END SOURCE ----------
FREQUENCY : always
Comments
|