Error "Closing a missing client" on connection

[dalisoft]

Screenshot

Expected Behaviour
Running like excepted

Actual Behaviour

[Server]: started successfully at [localhost:4000] in [4ms]
file:///Users/dalisoft/Desktop/Open_Source/nanoexpress/plugins/middlewares/packages/graphql/examples/node_modules/graphql-ws/lib/use/uWebSockets.mjs:103
                throw new Error('Closing a missing client');
                ^

Error: Closing a missing client
    at close (file:///Users/dalisoft/Desktop/Open_Source/nanoexpress/plugins/middlewares/packages/graphql/examples/node_modules/graphql-ws/lib/use/uWebSockets.mjs:103:23)
    at Object.close (file:///Users/dalisoft/Desktop/Open_Source/nanoexpress/plugins/middlewares/packages/graphql/examples/node_modules/graphql-ws/lib/use/uWebSockets.mjs:65:28)
    at Object.opened (file:///Users/dalisoft/Desktop/Open_Source/nanoexpress/plugins/middlewares/packages/graphql/examples/node_modules/graphql-ws/lib/server.mjs:37:24)
    at open (file:///Users/dalisoft/Desktop/Open_Source/nanoexpress/plugins/middlewares/packages/graphql/examples/node_modules/graphql-ws/lib/use/uWebSockets.mjs:57:36)
    at upgrade (file:///Users/dalisoft/Desktop/Open_Source/nanoexpress/plugins/middlewares/packages/graphql/examples/node_modules/graphql-ws/lib/use/uWebSockets.mjs:39:17)

Debug Information
OS: macOS Big Sur 11.4 (Intel x64)
Node: v16.2.0

Further Information
It sometimes work, sometimes don't

Minimal reproducible repository
https://github.com/nanoexpress/middlewares/tree/master/packages/graphql/examples

[enisdenjo]

Hey there! Thanks for reporting and testing uWebSockets. This seems like a bug, but through a brief look over the code - I dont know why.

Nevertheless, I will take a deeper look very soon and will report my findings. 😄

[dalisoft]

@enisdenjo Thank you. I also will try debug and find why it happens.

[enisdenjo]

The following part is the only one that deletes clients/sockets from the clients map and is the only place where that specific error can occur:

graphql-ws/src/use/uWebSockets.ts

Lines 140 to 151 in 5e37be8

	close(...args) {
	behavior.close?.(...args);
	const [socket, code, message] = args;
	const client = clients.get(socket);
	if (!client) throw new Error('Closing a missing client');
	if (client.pongWaitTimeout) clearTimeout(client.pongWaitTimeout);
	if (client.pingInterval) clearTimeout(client.pingInterval);
	client.closed(code, Buffer.from(message).toString());
	clients.delete(socket);
	},

Looks like it gets called multiple times for the same socket... The "why?" is what needs answering.

[dalisoft]

Or maybe socket opening does not happening

graphql-ws/src/use/uWebSockets.ts

Line 145 in 5e37be8

if (!client) throw new Error('Closing a missing client');

[enisdenjo]

Hmm, might happen. I add the client to the map once I prepared it:

graphql-ws/src/use/uWebSockets.ts

Line 121 in 5e37be8

clients.set(socket, client);

But, as JS is single threaded, and there is no async code in the open callback, I expect it to always be added.

However, since uWS is powered by C++, there could be some "magic" happening behind the curtains terminating open early or not calling it at all (the latter being more likely).

[dalisoft]

Yea, I’ll try debug in next two days or next week and maybe we fix it together or i let you know where has been bug

[enisdenjo]

Figured out why. It happens when you request a WebSocket upgrade with a wrong subprotocol (for example with subscriptions-transport-ws, which is the default for Altair).

Establishing a connection with a wrong subprotocol immediately closes the connection:

graphql-ws/src/use/uWebSockets.ts

Line 106 in 5e37be8

socket.end(code, reason);

The client is not added to the map since socket.end calls the close callback synchronously.

[dalisoft]

For me it started working after these actions:

1. Restarting machine
2. Go-to directory
3. rm -rf node_modules yarn.lock
4. yarn cache clean
5. yarn
6. Running script
7. Run Altair (protocol already have been "Websocket (graphql-ws)")

[dalisoft]

If it can be fixed, would be nice, currently seems no issue, but can happen in future

[enisdenjo]

It is definitely a bug, the server cant crash if a wrong subprotocol is requested - this needs fixing.

It started working for you since you're now using the correct subprotocol all around. Try switching the protocol back to "Websocket", it will fail constantly.

[dalisoft]

@enisdenjo Seems it is. I did choosed graphql-ws, but why before it not worked i don't know. Thank you for research it for me.
Now your library is preferred to use when using graphql on my framework.
You did great job

[enisdenjo]

Seems like a bug with Altair. Having selected "Websockets" once, even after changing it, it will try connecting with the legacy protocol automatically in the background (which is why it happened sometimes for you).

Glad you like graphql-ws and thank you for the kind words! 😄

[dalisoft]

If you need HTTP GraphQL, you can use this with framework, it's really fast. Here examples which uses graphql-ws when need to use Subscription and it's too really very very fast.

[enisdenjo]

Awesome! Nice to hear that the library can be speedy. I wanted to do some benchmarks; but honestly, dont know where to start. Any pointers? How'd you measure the speed over at nanoexpress?

[dalisoft]

Benchmark.js, console.time for any function compare or Websocket connection time compare.

wrk for http

[dalisoft]

Or you can try this as uWebSockets uses this way. I used it once, seems good way, but not easy to run

[enisdenjo]

🎉 This issue has been resolved in version 4.5.2 🎉

The release is available on:

• npm package (@latest dist-tag)
• GitHub release

Your semantic-release bot 📦🚀