Generic websocket error when connecting over WSS using UWP

[KallynGowdy]

Details

I've been having some issues making a secure websockets connection on the Hololens 2. In particular, this webpage (http://yeticgi.casualos.com/?story=test1&pagePortal=home) works fine over HTTP (and WS) but fails to work over HTTPS (and WSS).

All the HTTPS stuff seems to work fine - it's only initiating a connection over secure websockets that is failing. The error message is brief:

Error: websocket error

When I tried to build with --features js_backtrace to get some more info, I ran into some issues as documented here: #27042

I've also tried loading the same URL with a MacOS build and it worked fine so it seems to be Hololens 2 specific.

Runtime details

OS: Windows Holographic for Business

OS Build: 10.0.19041.1106

Servo Version: KallynGowdy@6a5a77a

Build details

OS: Windows 10 Pro

OS Version: 1903

OS Version: 18362.900

Servo Version: KallynGowdy@6a5a77a

Build Command:

C:\Python27\python.exe mach build -d --uwp --win-arm64

Reproduction steps

1. Make a build of Servo using this command:
   • path\to\python.exe mach build -d --uwp --win-arm64
2. (Optional) Replace the default URL in DefaultUrl.h with https://yeticgi.casualos.com/?story=test1&pagePortal=home.
3. Run on the Hololens 2 via Visual Studio.
4. Go to https://yeticgi.casualos.com/?story=test1&pagePortal=home
   • If you did step 2 then this will happen automatically.
5. A loading window should pop up on the right side of the browser window.
   • It is supposed to be centered, but there's some CSS issue that's causing it to be anchored to the right.
6. The debug log will show that the app starts up and tries to make a websockets connection but keeps erroring for some reason.

Some things to note:

• The app works by first loading all the JS/CSS/HTML it needs and starting a web worker that initiates the websocket connection.
• The websocket errors are being logged here.
• I tried to get extra debug information by enabling the js_backtrace feature as specified here but I ran into a separate runtime issue detailed here.
• Seems weird that two threads exit every time that the websocket connection errors. I'm guessing this is because Servo allocates another thread to handle the networking in this case and it exits because there's nothing else to do.

Logs

Debug Logs

RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
[globalThis-polyfill] load
THREE.WebGLRenderer: WEBGL_depth_texture extension not supported.
[AppManager] Starting init...
[AppManager] Fetching config...
TypeError: e.style is undefined
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
Unable to save config: 
MissingAPIError: indexedDB API not found. If using IE10+, make sure to run your code on a server URL (not locally). If using old Safari versions, make sure to include indexedDB polyfill.
Skipping Sentry Initialization
[AppManager] Setting primary simulation:
test1
Unable to get Username
MissingAPIError: indexedDB API not found. If using IE10+, make sure to run your code on a server URL (not locally). If using old Safari versions, make sure to include indexedDB polyfill.
[AppManager] Generating new login key...
Unable to save user to DB
MissingAPIError: indexedDB API not found. If using IE10+, make sure to run your code on a server URL (not locally). If using old Safari versions, make sure to include indexedDB polyfill.
Unable to save username
MissingAPIError: indexedDB API not found. If using IE10+, make sure to run your code on a server URL (not locally). If using old Safari versions, make sure to include indexedDB polyfill.
[BaseSimulation] init
[BaseSimulation] Status:
Starting...
RUST: WARN - script::timers - Resuming an already resumed timer.
RUST: WARN - constellation::browsingcontext - BrowsingContext BrowsingContextId { namespace_id: PipelineNamespaceId(2), index: BrowsingContextIndex(29) } iterated after closure.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - script::timers - Resuming an already resumed timer.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
RUST: WARN - media::media_thread - Tried to remove an unknown player
RUST: WARN - media::media_thread - Tried to remove an unknown player
The thread 0x1670 has exited with code 0 (0x0).
RUST: WARN - mozjs::rust - Warning at https://yeticgi.casualos.com/vendors.8e14baa88946c15832fc.js:0:0: asm.js type error: Disabled by lack of compiler support

RUST: WARN - net::http_loader - Failed to receive confirmation request was streamed without error.
[globalThis-polyfill] load
[IframeEntry] Listening for port...
[globalThis-polyfill] load
[AuxChannel.worker] Listening for port...
[IframeEntry] Got port, sending to worker instance.
RUST: WARN - script::dom::globalscope - maybe_add_pending_ports called on a global not managing any ports.
[AuxChannel.worker] Got port, exposing API
RUST: WARN - constellation::constellation - Unexpected messageport shipped received
[SocketManager] Starting...
The thread 0x760 has exited with code 0 (0x0).
The thread 0x380 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[BaseSimulation] Status:
Initialized.
[PlayerApp] Not authenticated:
undefined
[SocketManager] Connection error.
Error: websocket error
The thread 0x1774 has exited with code 0 (0x0).
The thread 0x764 has exited with code 0 (0x0).
The thread 0x1828 has exited with code 0 (0x0).
The thread 0x4a8 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1590 has exited with code 0 (0x0).
The thread 0x1ab8 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0x164c has exited with code 0 (0x0).
The thread 0x9cc has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1854 has exited with code 0 (0x0).
The thread 0x1ab4 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1b48 has exited with code 0 (0x0).
The thread 0x13f4 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x13a4 has exited with code 0 (0x0).
The thread 0x1130 has exited with code 0 (0x0).
The thread 0x1530 has exited with code 0 (0x0).
The thread 0x1aa4 has exited with code 0 (0x0).
The thread 0x1a50 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0x90c has exited with code 0 (0x0).
The thread 0xcc8 has exited with code 0 (0x0).
The thread 0xb70 has exited with code 0 (0x0).
The thread 0x1108 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x140c has exited with code 0 (0x0).
The thread 0x15c0 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0x113c has exited with code 0 (0x0).
The thread 0x16c4 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xf70 has exited with code 0 (0x0).
The thread 0x1ac0 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x10e0 has exited with code 0 (0x0).
The thread 0x1620 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1888 has exited with code 0 (0x0).
The thread 0x7f4 has exited with code 0 (0x0).
The thread 0x18f8 has exited with code 0 (0x0).
The thread 0x2b4 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0x14d0 has exited with code 0 (0x0).
The thread 0x11b0 has exited with code 0 (0x0).
'ServoApp.exe' (Win32): Unloaded 'C:\Windows\system32\minglobinputhost.dll'
'ServoApp.exe' (Win32): Unloaded 'C:\Windows\system32\Windows.Globalization.dll'
'ServoApp.exe' (Win32): Unloaded 'C:\Windows\system32\execmodelproxy.dll'
'ServoApp.exe' (Win32): Unloaded 'C:\Windows\system32\Windows.Shell.ServiceHostBuilder.dll'
The thread 0xd74 has exited with code 0 (0x0).
The thread 0x127c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0xe98 has exited with code 0 (0x0).
The thread 0x125c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x900 has exited with code 0 (0x0).
The thread 0x96c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xb14 has exited with code 0 (0x0).
The thread 0x1714 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x3f0 has exited with code 0 (0x0).
The thread 0x1518 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x16a0 has exited with code 0 (0x0).
The thread 0x390 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x834 has exited with code 0 (0x0).
The thread 0x954 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1ab8 has exited with code 0 (0x0).
The thread 0x1970 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x164c has exited with code 0 (0x0).
The thread 0x1a3c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xef0 has exited with code 0 (0x0).
The thread 0x1ac has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1b2c has exited with code 0 (0x0).
The thread 0xf44 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x894 has exited with code 0 (0x0).
The thread 0x1760 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1bb0 has exited with code 0 (0x0).
The thread 0x1b38 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1530 has exited with code 0 (0x0).
The thread 0x584 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xa4 has exited with code 0 (0x0).
The thread 0x748 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xe00 has exited with code 0 (0x0).
The thread 0xec0 has exited with code 0 (0x0).
The thread 0x8ac has exited with code 0 (0x0).
The thread 0x1a74 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0x1a8c has exited with code 0 (0x0).
The thread 0x8 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x9c4 has exited with code 0 (0x0).
The thread 0xe90 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x15a8 has exited with code 0 (0x0).
The thread 0x20c has exited with code 0 (0x0).
The thread 0x644 has exited with code 0 (0x0).
The thread 0xc4c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x71c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1b84 has exited with code 0 (0x0).
The thread 0x96c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xb14 has exited with code 0 (0x0).
The thread 0x634 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x220 has exited with code 0 (0x0).
The thread 0x1180 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x390 has exited with code 0 (0x0).
The thread 0x16a0 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x350 has exited with code 0 (0x0).
The thread 0x1590 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x9a0 has exited with code 0 (0x0).
The thread 0x10d8 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1ac has exited with code 0 (0x0).
The thread 0xef0 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1b2c has exited with code 0 (0x0).
The thread 0xc40 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x1978 has exited with code 0 (0x0).
The thread 0x1bf8 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xa3c has exited with code 0 (0x0).
The thread 0x91c has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0x584 has exited with code 0 (0x0).
The thread 0x1530 has exited with code 0 (0x0).
[SocketManager] Connection error.
Error: websocket error
The thread 0xed8 has exited with code 0 (0x0).
The thread 0x6dc has exited with code 0 (0x0).
The thread 0xe00 has exited with code 0 (0x0).
[SocketManager] Connection error.
The thread 0x868 has exited with code 0 (0x0).
Error: websocket error
[SocketManager] Connection error.
Error: websocket error
The thread 0xed4 has exited with code 0 (0x0).
The thread 0x550 has exited with code 0 (0x0).

[jdm]

An interesting experiment is whether this can be reproduced in a desktop UWP app. That would suggest the error lies somewhere in OpenSSL, since the version on macOS and the version used in UWP builds are not necessarily the same.

[jdm]

I have reproduced these errors in desktop UWP. Strangely, enabling the debug logs for websockets doesn't show any new logging output.

[jdm]

RUST: INFO - ws - Queuing connection to wss://yeticgi.casualos.com/socket.io/?EIO=3&transport=websocket
RUST: DEBUG - ws::handshake - Built request from URL:
GET /socket.io/?EIO=3&transport=websocket HTTP/1.1
Connection: Upgrade
Host: yeticgi.casualos.com:443
Sec-WebSocket-Version: 13
Sec-WebSocket-Key: c0bWBRppZzMv9ERToQagrQ==
Upgrade: websocket

RUST: TRACE - ws::io - Active connections 1
RUST: TRACE - ws::io - Waiting for event
RUST: TRACE - ws::io - Processing 1 events
RUST: TRACE - ws::connection - Ready to write handshake to UNKNOWN.
RUST: TRACE - ws::stream - Attempting to write ssl handshake.
RUST: TRACE - ws::io - Scheduling connection to UNKNOWN as Readable
RUST: TRACE - ws::io - Active connections 1
RUST: TRACE - ws::io - Waiting for event
RUST: TRACE - ws::io - Processing 1 events
RUST: TRACE - ws::connection - Performing TLS negotiation on UNKNOWN.
RUST: TRACE - ws::connection - Ready to write handshake to UNKNOWN.
RUST: TRACE - ws::stream - Attempting to write ssl handshake.
RUST: TRACE - ws::io - Encountered error while reading: None
RUST: DEBUG - net::websocket_loader - Error in WebSocket communication: WS Error <Io(Custom { kind: NotConnected, error: "None" })>

After adding --vslogger-level trace to this code I see more useful logging output that I expected.

[KallynGowdy]

Looks like there might be a related issue on the ws-rs github: housleyjk/ws-rs#51

[jdm]

Good find! Also ominous that people keep encountering it except the people best positioned to fix it, apparently :(

[KallynGowdy]

So I've been able to create a standalone repro for this issue in this repository.
It uses the ws-rs crate in a similar manner to servo and additionally confirms that it is an issue with an upstream dependency instead of with servo itself.

Extra stuff

After debugging, I've discovered the following:

According to the trace listed above and the digging below, it appears that ws-rs (and therefore mio) is unable to establish a working TCP connection in this specific scenario.

It follows this path:

1. A websocket connection is created
2. It is started
3. A socket is created and an event is received from the socket indicating the the stream is writable. (seems dubious - see below)
4. The event is processed and attempts to write pending data to it
5. The websocket realizes that the connection is being established and attempts to write the TLS handshake to it
6. The handshake fails but the error is not propogated
7. Another event is received from the socket indicating that the stream has available data. (once again this seems wrong because of the lack of packets)
8. The event is processed and attempts to read the pending data
9. The stream realizes it hasn't finished negotiating TLS and attempts to do that (Also see ws-rs connection.rs:512)
10. OpenSSL tries to perform the handshake but it fails
    • Actual OpenSSL API doc is here
    • Fails with a SSL_ERROR_WANT_READ (code 2) so it seems like no data is coming back.
11. Because the error is propagated this time, the socket disconnects.

One weird thing that I've noticed is that Wireshark doesn't show any additional TCP packets once the HTTP requests have completed. This would seem to indicate that maybe we're not connecting to the right place or that the connection could not be made. If that is the case, then the issue may lie in mio, which is the IO library that ws-rs uses for TCP Socket communication. It is worth noting that since ws-rs hasn't been updated in a while, it is using an old version of mio. (Version 0.6.22 instead of 0.7.x)

[jdm]

The next step for minimizing that testcase would probably be to use the vendored feature of openssl-sys to build openssl without requiring servo to be involved with the build at all.

[KallynGowdy]

I just updated the repro to use vcpkg to install OpenSSL without servo.

[jdm]

Fantastic write-up in the ws-rs issue. I suspect that mio 0.7 is currently incompatible with UWP, so we may need to switch to a different websocket client library in servo.

[KallynGowdy]

@jdm I was literally going to say the same thing! Any suggestions? This one looks kinda cool but I'm not sure what OpenSSL support is required. I'm also assuming that it'd be fine to use the standard library TCP stream API.

[jdm]

https://github.com/snapview/tungstenite-rs/blob/fd7de42347f6b39428bcdb0e7d6a4bf65ccecedb/src/stream.rs#L3-L5 suggests that tungstenite is probably our best choice and should be able to integrate with our existing openssl support in servo.

[jdm]

I've started work to integrate tungstenite in https://github.com/jdm/servo/tree/tungstenite. When attempting to write the code that would support reading and writing independently, I realized that we're going need to add an async layer on top of tungstenite. Possibilties include:

• tokio-tungstenite - depends on an older version, hasn't been updated since January
• async-tungstenite - maintained by our friend Sebastien Droge, actively kept up to date

Neither of these options have built-in support for openssl that I can see. While tungstenite works out of the box with any stream that wraps TLS, it looks like we need the equivalent of hyper_openssl to integrate openssl in the async tungstenite ecosystem. Fun times.

[jdm]

Then again, https://github.com/alexcrichton/tokio-openssl and https://gitlab.com/jrobsonchase/openssl-async/-/tree/master look like they might be important missing pieces?

[sdroege]

tokio-openssl is actively maintained it seems, so that seems like the best approach for the OpenSSL plumbing if you're using tokio in servo (and not async-std or your own futures runtime).

[jdm]

I have verified that the page loads as expected with #27164 applied.

[KallynGowdy]

I can also confirm that is fixed on the Hololens 2.