Environment
Java-WebSocket version: 1.6.0 (latest at time of writing)
- Used as the transport layer inside a third-party OCPP library (
eu.chargetime.ocpp /
WebSocketServer subclass), with a 4-thread WebSocketWorker pool (default configuration,
decodercount = 4)
- Server registers a single
Draft_6455 instance with a configured subprotocol list
(["ocpp2.0.1", ""]) and no custom extensions (library auto-adds DefaultExtension)
- JDK: Eclipse Temurin 24 (server-side), running in a Kubernetes pod behind a TLS-terminating
reverse proxy (Envoy) that forwards plaintext WebSocket traffic to the application
- Client: a Node.js
ws-based WebSocket client, connecting over TLS through the proxy above
Summary
We are intermittently seeing a connection get accepted, fully complete its WebSocket handshake
(including subprotocol negotiation), have onOpen fire and be handed off to our application code -
and then, roughly 100 microseconds later, get closed by the server with code 1002 and reason
"no draft matches", without any second HTTP handshake ever being parsed for that connection.
This happens for maybe 20-50% of connection attempts in our environment (highly variable, we have
not found a reliable way to force it on demand), and results in the client observing an abnormal
closure (code 1006) despite having just successfully connected.
What we've confirmed via TRACE-level logging
We instrumented org.java_websocket at TRACE level and captured the following sequence for a
single, real failing connection (headers/IDs redacted, timestamps in server-local time with
nanosecond precision from our own structured logging - not part of Java-WebSocket itself):
[WebSocketWorker-76] TRACE WebSocketImpl - process(759): (GET /ocpp2.0/<redacted> HTTP/1.1
host: <redacted>
sec-websocket-version: 13
sec-websocket-key: <redacted>
connection: Upgrade
upgrade: websocket
sec-websocket-extensions: permessage-deflate; client_max_window_bits
sec-websocket-protocol: ocpp2.0.1
...
)
[WebSocketWorker-76] TRACE Draft_6455 - acceptHandshakeAsServer - Matching extension found: DefaultExtension
[WebSocketWorker-76] TRACE Draft_6455 - acceptHandshake - Matching protocol found: ocpp2.0.1
[WebSocketWorker-76] TRACE WebSocketImpl - write(247): HTTP/1.1 101 Web Socket Protocol Handshake
Connection: Upgrade
...
Sec-WebSocket-Protocol: ocpp2.0.1
Server: TooTallNate Java-WebSocket
Upgrade: websocket
[WebSocketWorker-76] TRACE WebSocketImpl - open using draft: Draft_6455 extension: DefaultExtension protocol: ocpp2.0.1 max frame size: 2147483647
[WebSocketWorker-76] DEBUG (application) - On connection open (resource descriptor: /ocpp2.0/<redacted>)
[WebSocketWorker-76] INFO (application) - Creating new session ...
[WebSocketSelector-79] DEBUG (application) - On connection close (resource descriptor: /ocpp2.0/<redacted>, code: 1002, reason: no draft matches, remote: false)
[WebSocketSelector-79] TRACE WebSocketImpl - send frame: Framedata{ opcode:CLOSING, ... } code: 1000
[WebSocketSelector-79] TRACE Draft_6455 - afterEnconding(2): ...
[WebSocketSelector-79] TRACE WebSocketImpl - write(4): ...
Key observations:
- The handshake headers are valid (
Sec-WebSocket-Version: 13, Sec-WebSocket-Protocol: ocpp2.0.1), and Draft_6455.acceptHandshakeAsServer explicitly logs a successful match for
both extension and protocol.
open(...) is called, onOpen fires, and our application code receives and begins processing
the new session - all on thread WebSocketWorker-76.
- Approximately 100 microseconds later, a different thread -
WebSocketSelector-79, which by
naming convention (WebSocketServer.doSetupSelectorAndServerThread()) is the single NIO
selector thread, distinct from the WebSocketWorker pool that performs handshake
decoding/matching - closes the same connection (same resource descriptor) with code 1002
and reason "no draft matches".
- Critically,
WebSocketImpl.decode(ByteBuffer) unconditionally logs a "process(N): (...)" TRACE
line on every invocation (before even checking readyState). We only ever see one such
line for the connection above - meaning decodeHandshake() (the only code path that can produce
the "no draft matches" log message / InvalidDataException) was never invoked a second time
for this connection. Yet the close event carries exactly that reason string.
This rules out (at least in our case) a genuine second/duplicate handshake attempt for the same
socket, a multi-draft ambiguity (we only register one draft), and any application-level session
bookkeeping issue on our side (the handshake match is real and logged as such).
Suspected area (not confirmed as root cause)
We have not been able to pin this down to a single line with full confidence, and would appreciate
maintainer input, but the area we find most suspicious is the handoff between the selector thread
and the worker-thread pool in WebSocketServer:
doRead() reads bytes on the selector thread and calls queue(conn), which does
ws.getWorkerThread().put(ws) - handing the connection object itself to a WebSocketWorker's
BlockingQueue<WebSocketImpl>.
WebSocketWorker.run() does ws = iqueue.take(); buf = ws.inQueue.poll(); assert(buf != null); doDecode(ws, buf);. Note poll() is non-blocking and can return null, and assert is a no-op
in a production JVM (assertions disabled by default) - so if ws is ever queued to a worker
before (or without) a corresponding buffer being available in ws.inQueue, this would silently
proceed with buf == null into doDecode/decode.
We are not confident this is the actual mechanism (we were not able to correlate an exception/log
line matching this exact path in our captures), but it's the most plausible shared-state or
ordering issue we could identify between the selector thread and the worker pool for an
already-opened connection.
Reproduction
Unfortunately we have not been able to build a minimal, reliable, on-demand reproduction. It
occurs intermittently (20-50% of attempts) only in our real deployed environment (client connecting
over a WAN-ish network path through a TLS-terminating reverse proxy), and we were unable to
reproduce it at all in ~100 local attempts using a direct, unproxied, low-latency loopback
connection to the same server code, with various injected latency/TLS-termination conditions we
could simulate locally. This suggests some degree of network-timing sensitivity, but since the
defect appears to require a second, distinct decode-dispatch event that we can't find independent
evidence of, we suspect it may also depend on JIT warmup, GC pauses, or other JVM-level scheduling
jitter under the worker thread pool that are hard to force deterministically.
We're happy to test any proposed patch against our environment, understanding it may take several
attempts (dozens of connection attempts per test) to get a statistically meaningful signal, given
the intermittent nature.
Impact
For us, this causes charging station (IoT device) WebSocket connections to occasionally fail
immediately after what was, by all visible evidence, a fully successful handshake - requiring the
client to reconnect. We've mitigated the resulting NullPointerException and incorrect
online/offline status flapping on our own application side, but the underlying spurious
disconnect/reconnect itself can only be fixed in this library.
Any guidance on where else to look, or whether this rings a bell as a known issue, would be very
much appreciated.
Environment
Java-WebSocketversion: 1.6.0 (latest at time of writing)eu.chargetime.ocpp/WebSocketServersubclass), with a 4-threadWebSocketWorkerpool (default configuration,decodercount = 4)Draft_6455instance with a configured subprotocol list(
["ocpp2.0.1", ""]) and no custom extensions (library auto-addsDefaultExtension)reverse proxy (Envoy) that forwards plaintext WebSocket traffic to the application
ws-based WebSocket client, connecting over TLS through the proxy aboveSummary
We are intermittently seeing a connection get accepted, fully complete its WebSocket handshake
(including subprotocol negotiation), have
onOpenfire and be handed off to our application code -and then, roughly 100 microseconds later, get closed by the server with code
1002and reason"no draft matches", without any second HTTP handshake ever being parsed for that connection.This happens for maybe 20-50% of connection attempts in our environment (highly variable, we have
not found a reliable way to force it on demand), and results in the client observing an abnormal
closure (code
1006) despite having just successfully connected.What we've confirmed via TRACE-level logging
We instrumented
org.java_websocketat TRACE level and captured the following sequence for asingle, real failing connection (headers/IDs redacted, timestamps in server-local time with
nanosecond precision from our own structured logging - not part of Java-WebSocket itself):
Key observations:
Sec-WebSocket-Version: 13,Sec-WebSocket-Protocol: ocpp2.0.1), andDraft_6455.acceptHandshakeAsServerexplicitly logs a successful match forboth extension and protocol.
open(...)is called,onOpenfires, and our application code receives and begins processingthe new session - all on thread
WebSocketWorker-76.WebSocketSelector-79, which bynaming convention (
WebSocketServer.doSetupSelectorAndServerThread()) is the single NIOselector thread, distinct from the
WebSocketWorkerpool that performs handshakedecoding/matching - closes the same connection (same resource descriptor) with code
1002and reason
"no draft matches".WebSocketImpl.decode(ByteBuffer)unconditionally logs a"process(N): (...)"TRACEline on every invocation (before even checking
readyState). We only ever see one suchline for the connection above - meaning
decodeHandshake()(the only code path that can producethe
"no draft matches"log message /InvalidDataException) was never invoked a second timefor this connection. Yet the close event carries exactly that reason string.
This rules out (at least in our case) a genuine second/duplicate handshake attempt for the same
socket, a multi-draft ambiguity (we only register one draft), and any application-level session
bookkeeping issue on our side (the handshake match is real and logged as such).
Suspected area (not confirmed as root cause)
We have not been able to pin this down to a single line with full confidence, and would appreciate
maintainer input, but the area we find most suspicious is the handoff between the selector thread
and the worker-thread pool in
WebSocketServer:doRead()reads bytes on the selector thread and callsqueue(conn), which doesws.getWorkerThread().put(ws)- handing the connection object itself to aWebSocketWorker'sBlockingQueue<WebSocketImpl>.WebSocketWorker.run()doesws = iqueue.take(); buf = ws.inQueue.poll(); assert(buf != null); doDecode(ws, buf);. Notepoll()is non-blocking and can returnnull, andassertis a no-opin a production JVM (assertions disabled by default) - so if
wsis ever queued to a workerbefore (or without) a corresponding buffer being available in
ws.inQueue, this would silentlyproceed with
buf == nullintodoDecode/decode.We are not confident this is the actual mechanism (we were not able to correlate an exception/log
line matching this exact path in our captures), but it's the most plausible shared-state or
ordering issue we could identify between the selector thread and the worker pool for an
already-opened connection.
Reproduction
Unfortunately we have not been able to build a minimal, reliable, on-demand reproduction. It
occurs intermittently (20-50% of attempts) only in our real deployed environment (client connecting
over a WAN-ish network path through a TLS-terminating reverse proxy), and we were unable to
reproduce it at all in ~100 local attempts using a direct, unproxied, low-latency loopback
connection to the same server code, with various injected latency/TLS-termination conditions we
could simulate locally. This suggests some degree of network-timing sensitivity, but since the
defect appears to require a second, distinct decode-dispatch event that we can't find independent
evidence of, we suspect it may also depend on JIT warmup, GC pauses, or other JVM-level scheduling
jitter under the worker thread pool that are hard to force deterministically.
We're happy to test any proposed patch against our environment, understanding it may take several
attempts (dozens of connection attempts per test) to get a statistically meaningful signal, given
the intermittent nature.
Impact
For us, this causes charging station (IoT device) WebSocket connections to occasionally fail
immediately after what was, by all visible evidence, a fully successful handshake - requiring the
client to reconnect. We've mitigated the resulting NullPointerException and incorrect
online/offline status flapping on our own application side, but the underlying spurious
disconnect/reconnect itself can only be fixed in this library.
Any guidance on where else to look, or whether this rings a bell as a known issue, would be very
much appreciated.