Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

New WS api blocking after closing connection #7457

Closed
MarcDwyer opened this issue Sep 14, 2020 · 16 comments
Closed

New WS api blocking after closing connection #7457

MarcDwyer opened this issue Sep 14, 2020 · 16 comments
Assignees
Labels
bug Something isn't working correctly cli related to cli/ dir

Comments

@MarcDwyer
Copy link

import { delay } from "https://deno.land/[email protected]/async/delay.ts";

const ws = new WebSocket("wss://irc-ws.chat.twitch.tv:443");

ws.onopen = () => console.log("connection opened");

ws.onclose = () => console.log("conn closed");

await delay(5000);

ws.close();

Issue is when closing a WS connection something appears to be stuck in the event loop (just a guess), preventing the program from terminating. To replicate this issue, just create a ws connection and close it.

@crowlKats
Copy link
Member

from a bit of testing it seems it gets stuck on the eventloop;

.poll_next_unpin(cx)

This behaviour seems only to happen when setTimeout or setInterval are in play.

@lucacasonato lucacasonato added bug Something isn't working correctly cli related to cli/ dir labels Sep 14, 2020
@bartlomieju bartlomieju self-assigned this Sep 14, 2020
@bartlomieju
Copy link
Member

I did some investigation and it seems the problem is in op_ws_next_event which never finishes. Probably need to add task tracking to it and notify the future to error out when op_ws_close is called.

@lucacasonato
Copy link
Member

I did some investigation and it seems the problem is in op_ws_next_event which never finishes. Probably need to add task tracking to it and notify the future to error out when op_ws_close is called.

This was an issue with the initial PR already - did that never get fixed before landing?

@bartlomieju
Copy link
Member

bartlomieju commented Sep 15, 2020

I did some investigation and it seems the problem is in op_ws_next_event which never finishes. Probably need to add task tracking to it and notify the future to error out when op_ws_close is called.

This was an issue with the initial PR already - did that never get fixed before landing?

I does look like it CC @crowlKats @ry

EDIT: PR demonstrating hang with some debug output at #7493

@kryptish
Copy link

kryptish commented Sep 16, 2020

I'm experiencing the opposite behaviour at the moment, for some reason my connection (maybe?) is closed pretty quickly after opening it, I can't figure out what's going on, no error or close events are ever triggered, but the script simply exits...

This particular ws server sends pings in a (I believe) 3 minute interval, can't see those either (while I can with the old way of implementing a ws client trough the std-ws module, maybe some code speaks better words than I can write...

I'm on the Deno 1.4.0

import {
	connectWebSocket,
	isWebSocketCloseEvent,
	isWebSocketPingEvent,
	isWebSocketPongEvent,
} from 'https://deno.land/[email protected]/ws/mod.ts';


const ws = new WebSocket('wss://stream.binance.com:9443/ws');

const status = new Map([
	[0, 'CONNECTING'],
	[1, 'OPEN'],
	[2, 'CLOSING'],
	[3, 'CLOSED'],
]);

ws.onopen = function(...args) {
	console.log('ws opened', args, {
		readyState: status.get(ws.readyState),
		url: ws.url,
		extensions: ws.extensions,
		protocol: ws.protocol,
		binaryType: ws.binaryType,
		bufferedAmount: ws.bufferedAmount,
	});
	
}

ws.onmessage = function(...args) {
	console.log('ws message', args);
}

ws.onclose = function(...args) {
	console.log('ws closed', args);
	console.table(Deno.resources());
	console.table(Deno.metrics());
}

ws.onerror = function(...args) {
	console.log('ws error', args);
}

// this will keep the script running, without it, it will just exit pretty quickly
// let elapsed = 0;
// setInterval(function() {
// 	elapsed += 10000;
// 	console.log(`ws.readyState after ${elapsed/1000}s`, status.get(ws.readyState));
// }, 10000);


// the "old" (but working) way of doing a simple ws client
// this will also keep the new ws running, without it, it will exit pretty quickly
// furthermore with this implementation the ping messages are visible,
// but there is nothing logged with the new ws, is that supposed to be the case?
/*const wsold = await connectWebSocket('wss://stream.binance.com:9443/ws');

for await (const ev of wsold) {
	try {
		if ( typeof ev === 'string' || ev instanceof Uint8Array ) {
			console.log('wsold message', ev);
		} else if ( isWebSocketPingEvent(ev) ) {
			console.log('wsold ping', ev);
		} else if ( isWebSocketPongEvent(ev) ) {
			console.log('wsold pong', ev);
		} else if ( isWebSocketCloseEvent(ev) ) {
			console.log('wsold closed', ev);
			console.table(Deno.resources());
			console.table(Deno.metrics());
		}
	} catch (err) {
		console.log('wsold error', err);
	}
	// just to see if the new ws is still running => and yes, it will be, I assume because of the loop,
	// still no ping messages coming in
	console.log(`ws.readyState`, status.get(ws.readyState));
}*/

probably I am doing something wrong here... any ideas?

@MarcDwyer
Copy link
Author

const ws = new WebSocket('wss://stream.binance.com:9443/ws');

const status = new Map([
	[0, 'CONNECTING'],
	[1, 'OPEN'],
	[2, 'CLOSING'],
	[3, 'CLOSED'],
]);

ws.onopen = function(...args) {
	console.log('ws opened', args, {
		readyState: status.get(ws.readyState),
		url: ws.url,
		extensions: ws.extensions,
		protocol: ws.protocol,
		binaryType: ws.binaryType,
		bufferedAmount: ws.bufferedAmount,
	});
	
}

ws.onmessage = function(...args) {
	console.log('ws message', args);
}

ws.onclose = function(...args) {
	console.log('ws closed', args);
	console.table(Deno.resources());
	console.table(Deno.metrics());
}

ws.onerror = function(...args) {
	console.log('ws error', args);
}

It stays alive for me.

@notfilippo
Copy link

const sock = new WebSocket("ws://localhost:8080");
sock.onclose = () => {
  console.log("onclose");
}

const online = await new Promise((resolve) => {
  sock.onopen = () => resolve(true);
  sock.onerror = () => resolve(false);
});

console.log("socket is online:", online);

sock.close();

Getting the same issue. I should note that when online is resolved to false the script exists correctly. It will hang only when the connection is actually available.

I circumvented the issue performing a fetch request on the host.

  const online = await fetch("http://localhost:8080")
    .then(() => true)
    .catch(() => false);

This is by no means a correct solution but could work while we wait for a fix. 🔨

@kryptish
Copy link

It stays alive for me.

@MarcDwyer now that's interesting... no sudden exiting of the script without any close or error events emitted? It's also noteworthy that with other similar ws endpoints I don't have that problem (neither with this one if I subscribe to a topic and then data comes in) but those send regular messages for "heartbeat", no ping events, not sure if it even has anything to do with those... can anybody else run that script quickly, maybe I'm the only one with this issue...

@exside
Copy link
Contributor

exside commented Sep 23, 2020

Not sure if any of the issues in this discussion is related, but I'm (again) able to somehow create a panic:

thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: AlreadyClosed', cli/ops/websocket.rs:210:36
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

what I potentially did here is to call socket.close() after I received an "error" event in the onerror listener of the socket (because it didn't seem to close the socket)... IMHO this should probably not cause a panic =)...I mean, if the socket is already closed, ok, just do nothing, but crash the entire program is probably not too helpful, even if I'm doing something kinda "wrong"...

technically I'm checking if the socket is still open before trying to close it:

		if ( socket.readyState === WebSocket.OPEN ) {
			console.log('closing socket from close()', socket);
			socket.close();
		}

that code got triggered and with high likelihood caused the panic above, which seems strange to me that it then says AlreadyClosed because if that was the case, how would it then get trough that check?

it's tricky to reproduce (still trying to figure out why I'm getting an error event from the socket), will update if I find out more.

Could this potentially fix it? #7606
And maybe my issue is more closely related to #7604

@timonson
Copy link
Contributor

timonson commented Nov 18, 2020

Another case:

Although the onerror listener is executed (on connection loss), the promise won't be rejected correctly.

async function connect(url: string): Promise<WebSocket> {
  return new Promise((resolve, reject) => {
    const socket = new WebSocket(url);
    socket.onopen = () => resolve(socket);
    socket.onerror = (err) => {
      reject(
        new BadServerDataError(
          "An error event occured on the WebSocket connection.",
          32005,
        ),
      );
    };
  });
}

const socket = await connect(url)

@Soremwar
Copy link
Contributor

Tried the original example with several delays under latest canary, WebSocket no longer hangs.

@lucacasonato
Copy link
Member

Before closing, lets add a test to prevent regressions.

@bartlomieju
Copy link
Member

@Soremwar thanks for checking, can you add some small test case?

@Andrepuel
Copy link

On the mentioned issue above I've managed to reproduce the issue using Deno 1.6.3.
The problem does not happen when I use separated processes for the server and the client.

@crowlKats
Copy link
Member

I cant reproduce this anymore, so i assume it got fixed sometime

@bartlomieju
Copy link
Member

I cant reproduce this anymore, so i assume it got fixed sometime

Then closing as resolved :)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working correctly cli related to cli/ dir
Projects
None yet
Development

No branches or pull requests

10 participants