search

adamritter / nostr-relaypool-ts

A Nostr RelayPool implementation in TypeScript using only nostr-tools library as a dependency
https://www.npmjs.com/package/nostr-relaypool
MIT License
63 stars 17 forks source link

Relay: fix autoReconnect #45

Closed alexgleason closed 8 months ago

alexgleason commented 8 months ago

I am encountering the following error:

Feb 02 20:55:33 gleasonator deno[903762]: wss://relay.current.fyi/ reconnecting after 2s
Feb 02 20:55:33 gleasonator deno[903762]: Unhandled message from worker: { type: "error", err: "wss://relay.current.fyi/", relayUrl: undefined }
Feb 02 20:55:33 gleasonator deno[903762]: Unhandled message from worker: { type: "error", err: "wss://relay.current.fyi/", relayUrl: {} }
Feb 02 20:55:33 gleasonator deno[903762]: Unhandled message from worker: { type: "error", err: "wss://relay.current.fyi/", relayUrl: undefined }
Feb 02 20:55:33 gleasonator deno[903762]: error: Uncaught (in worker "") (in promise) ErrorEvent {
Feb 02 20:55:33 gleasonator deno[903762]:   bubbles: false,
Feb 02 20:55:33 gleasonator deno[903762]:   cancelable: false,
Feb 02 20:55:33 gleasonator deno[903762]:   composed: false,
Feb 02 20:55:33 gleasonator deno[903762]:   currentTarget: null,
Feb 02 20:55:33 gleasonator deno[903762]:   defaultPrevented: false,
Feb 02 20:55:33 gleasonator deno[903762]:   eventPhase: 0,
Feb 02 20:55:33 gleasonator deno[903762]:   srcElement: null,
Feb 02 20:55:33 gleasonator deno[903762]:   target: WebSocket {
Feb 02 20:55:33 gleasonator deno[903762]:     url: "wss://relay.current.fyi/",
Feb 02 20:55:33 gleasonator deno[903762]:     readyState: 3,
Feb 02 20:55:33 gleasonator deno[903762]:     extensions: "",
Feb 02 20:55:33 gleasonator deno[903762]:     protocol: "",
Feb 02 20:55:33 gleasonator deno[903762]:     binaryType: "blob",
Feb 02 20:55:33 gleasonator deno[903762]:     bufferedAmount: 0,
Feb 02 20:55:33 gleasonator deno[903762]:     onmessage: [Function: bound onmessage_fn] AsyncFunction,
Feb 02 20:55:33 gleasonator deno[903762]:     onerror: [Function (anonymous)],
Feb 02 20:55:33 gleasonator deno[903762]:     onclose: [Function: bound onclose_fn] AsyncFunction,
Feb 02 20:55:33 gleasonator deno[903762]:     onopen: [Function: bound onopen_fn]
Feb 02 20:55:33 gleasonator deno[903762]:   },
Feb 02 20:55:33 gleasonator deno[903762]:   returnValue: true,
Feb 02 20:55:33 gleasonator deno[903762]:   timeStamp: 0,
Feb 02 20:55:33 gleasonator deno[903762]:   type: "error",
Feb 02 20:55:33 gleasonator deno[903762]:   message: "NetworkError: failed to connect to WebSocket: Invalid status code: 400 Bad Request",
Feb 02 20:55:33 gleasonator deno[903762]:   filename: "",
Feb 02 20:55:33 gleasonator deno[903762]:   lineno: 0,
Feb 02 20:55:33 gleasonator deno[903762]:   colno: 0,
Feb 02 20:55:33 gleasonator deno[903762]:   error: DOMException: failed to connect to WebSocket: Invalid status code: 400 Bad Request
Feb 02 20:55:33 gleasonator deno[903762]:     at new DOMException (ext:deno_web/01_dom_exception.js:116:20)
Feb 02 20:55:33 gleasonator deno[903762]:     at DOMExceptionNetworkError (ext:runtime_main/js/99_main.js:405:12)
Feb 02 20:55:33 gleasonator deno[903762]:     at ext:core/00_infra.js:200:34
Feb 02 20:55:33 gleasonator deno[903762]:     at eventLoopTick (ext:core/01_core.js:63:7)
Feb 02 20:55:33 gleasonator deno[903762]: }
Feb 02 20:55:33 gleasonator deno[903762]: error: Uncaught (in promise) Error: Unhandled error in child worker.
Feb 02 20:55:33 gleasonator deno[903762]:     at Worker.#pollControl (ext:runtime/11_workers.js:167:19)
Feb 02 20:55:33 gleasonator deno[903762]:     at eventLoopTick (ext:core/01_core.js:63:7)
Feb 02 20:55:33 gleasonator deno[903762]: Watcher Process failed. Restarting on file change...

It's because in the reconnect code path, it calls connect() but does not catch it.

connect() can reject, because connectRelay() can reject, and in fact has specific places where it does it:

  async connectRelay(): Promise<void> {
    return new Promise((resolve, reject) => {
      try {
        const ws = new WebSocket(this.url);
        this.ws = ws;
      } catch (err) {
        reject(err);
        return;
      }

      this.ws.onopen = this.#onopen.bind(this, resolve);
      this.ws.onerror = (e) => {
        this.listeners.error.forEach((cb) => cb());
        reject(e);
      };
      this.ws.onclose = this.#onclose.bind(this);
      this.ws.onmessage = this.#onmessage.bind(this);
    });
  }

So if a relay tries to reconnect and then it encounters an error while opening the socket, it will not queue it to be reconnected again, and will instead kill the whole application.

The solution is to call this.#reconnect() again, letting the reconnectTimeout do its job.

alexgleason commented 8 months ago

I published nostr-relaypool2 on npm and now it does the correct thing:

Feb 02 22:50:28 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:28 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: {}, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:28 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:30 gleasonator deno[904365]: wss://relay.current.fyi/ reconnecting after 6s
Feb 02 22:50:30 gleasonator deno[904365]: wss://relay.current.fyi/ reconnecting after 18s
Feb 02 22:50:30 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:30 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:38 gleasonator deno[904365]: warning: Use of deprecated "Deno.writeSync()" API. This API will be removed in Deno 2. Run again with DENO_VERBOSE_WARNINGS=1 to get more details.
Feb 02 22:50:38 gleasonator deno[904365]: warning: Use of deprecated "Deno.close()" API. This API will be removed in Deno 2. Run again with DENO_VERBOSE_WARNINGS=1 to get more details.
Feb 02 22:50:48 gleasonator deno[904365]: wss://relay.current.fyi/ reconnecting after 54s
Feb 02 22:50:48 gleasonator deno[904365]: wss://relay.current.fyi/ reconnecting after 162s
Feb 02 22:50:48 gleasonator deno[904365]: wss://relay.current.fyi/ reconnecting after 486s
Feb 02 22:50:48 gleasonator deno[904365]: wss://relay.current.fyi/ reconnecting after 1458s
Feb 02 22:50:48 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:48 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:48 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
Feb 02 22:50:48 gleasonator deno[904365]: Unhandled message from worker: { type: "error", err: undefined, relayUrl: "wss://relay.current.fyi/" }
adamritter commented 8 months ago

Thanks!