WebSocket connection drops during development [$300 bounty]

[taoeffect]

Problem

Sometimes during development the Trying to reconnect... banner appears:

          'reconnection-attempt' () {
            sbp('gi.ui/showBanner', L('Trying to reconnect...'), 'wifi')
          },

There isn't much logging that happens on the backend, but in the browser console I see this:

Sometimes it's able to reconnect quickly, and sometimes it takes much longer.

Here is that same error with the fields expanded:

Related issue: #1983

Solution

Find out why this is happening at all.

• If it isn't a real websocket errors, make it not display this banner
• If it is a real websocket error, find out why it's happening and fix. we shouldn't be having the websocket drop on localhost, right?

Bounty

$300 bounty for a clean solution to this (paid in cryptocurrency).

[taoeffect]

@snowteamer So I am 100% sure that this is not caused by a change to a file in shared/. Instead it happens sometimes shortly after the server comes online after running grunt dev, when no files have changed.

This is what it looks like in the browser console shortly after the white banner disappears:

Click the disclosure triangle ▶︎ to see the backend log:

Backend logging, search for ===== to see moment that reconnection happens that dismisses the white banner

``` GET /assets/js/chunk-532VGDFI-cached.js.map GET /assets/js/chunk-J377US6K-cached.js.map GET /assets/js/chunk-UPIIOHBL-cached.js.map GET /assets/js/chunk-YQG4TOGH-cached.js.map GET /assets/js/chunk-BG2GK6WO-cached.js.map GET /assets/js/chunk-SVT55KAR-cached.js.map GET /assets/js/chunk-36H52KEK-cached.js.map GET /assets/js/chunk-I5SGMZ3H-cached.js.map GET /assets/js/chunk-MO5E6FPS-cached.js.map GET /assets/js/chunk-PAGZWNAP-cached.js.map GET /assets/js/chunk-DAIYHGSF-cached.js.map GET /assets/js/chunk-V5SYTOO5-cached.js.map GET /assets/js/chunk-ZHYOMU6Z-cached.js.map GET /assets/js/chunk-XUAC7HLL-cached.js.map GET /assets/js/chunk-7QSFWYQ6-cached.js.map GET /assets/js/chunk-CWFLCS77-cached.js.map GET /assets/js/chunk-Z7BIU5U3-cached.js.map GET /assets/js/chunk-DNGVLISJ-cached.js.map GET /assets/js/main.js.map GET /assets/js/chunk-YQG4TOGH-cached.js.map [sbp] backend/db/lookupName [ 'u1' ] Debug: handler, error Error: Not Found at Object.backend/db/lookupName (group-income/backend/database.js:158:26) at processTicksAndRejections (node:internal/process/task_queues:95:5) at group-income/backend/routes.js:129:12 at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) GET /assets/images/group-income-icon-transparent.png GET /assets/images/group-income-icon-transparent.png GET /assets/fonts/Icons/fa-regular-400.woff2 GET /assets/js/SignupModal-MFC2DLCL-cached.js.map [sbp] backend/db/lookupName [ 'u1' ] Debug: handler, error Error: Not Found at Object.backend/db/lookupName (group-income/backend/database.js:158:26) at processTicksAndRejections (node:internal/process/task_queues:95:5) at group-income/backend/routes.js:129:12 at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [pubsub] Socket 0-fada1f connected. Total: 1 [pubsub] Socket 1-42e4bd connected. Total: 2 [pubsub] Socket 2-888291 connected. Total: 3 [pubsub] Received 'sub' on socket 0-fada1f {"type":"sub","dontBroadcast":true,"contractID":"21XWnNXTtmf3xoLcx9a2tust9KuWfhSXrJqMA6r4jkbcFW4Enp"} [pubsub] Already subscribed to 21XWnNXTtmf3xoLcx9a2tust9KuWfhSXrJqMA6r4jkbcFW4Enp [pubsub] Received 'sub' on socket 0-fada1f {"type":"sub","dontBroadcast":true,"contractID":"21XWnNVcpe4tCJoXXS8y4nFURZfTotdZShWNm9AMAiyk3XgQNn"} [pubsub] Already subscribed to 21XWnNVcpe4tCJoXXS8y4nFURZfTotdZShWNm9AMAiyk3XgQNn [pubsub] Received 'sub' on socket 0-fada1f {"type":"sub","dontBroadcast":true,"contractID":"21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt"} [pubsub] Already subscribed to 21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt [pubsub] Received 'sub' on socket 0-fada1f {"type":"sub","dontBroadcast":true,"contractID":"21XWnNVTbdD3LFcjivbhm8U5YoynbNbGSStJ61m1dJXES8VFVU"} [pubsub] Already subscribed to 21XWnNVTbdD3LFcjivbhm8U5YoynbNbGSStJ61m1dJXES8VFVU [pubsub] Received 'sub' on socket 0-fada1f {"type":"sub","dontBroadcast":true,"contractID":"21XWnNKgzbBxPjaDzwzT7xhx6PfUJvzLbd6fmaC2WchTFonWrj"} [pubsub] Already subscribed to 21XWnNKgzbBxPjaDzwzT7xhx6PfUJvzLbd6fmaC2WchTFonWrj [pubsub] Received 'sub' on socket 0-fada1f {"type":"sub","dontBroadcast":true,"contractID":"21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT"} [pubsub] Already subscribed to 21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT [pubsub] Received 'sub' on socket 2-888291 {"type":"sub","dontBroadcast":true,"contractID":"21XWnNShoeU4tAEHRL9c84avSeSyDyNakAAv4zmUzo5abbKzkP"} [pubsub] Already subscribed to 21XWnNShoeU4tAEHRL9c84avSeSyDyNakAAv4zmUzo5abbKzkP [pubsub] Received 'sub' on socket 2-888291 {"type":"sub","dontBroadcast":true,"contractID":"21XWnNK9ChRBNB6HcWxqKmRg9iwgomSPdQzy71m293pTuwCXkZ"} [pubsub] Already subscribed to 21XWnNK9ChRBNB6HcWxqKmRg9iwgomSPdQzy71m293pTuwCXkZ [pubsub] Received 'sub' on socket 2-888291 {"type":"sub","dontBroadcast":true,"contractID":"21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT"} [pubsub] Already subscribed to 21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT [pubsub] Received 'sub' on socket 2-888291 {"type":"sub","dontBroadcast":true,"contractID":"21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt"} [pubsub] Already subscribed to 21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt [backend] latestHash not found for 21XWnNXTtmf3xoLcx9a2tust9KuWfhSXrJqMA6r4jkbcFW4Enp Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNVcpe4tCJoXXS8y4nFURZfTotdZShWNm9AMAiyk3XgQNn Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNVTbdD3LFcjivbhm8U5YoynbNbGSStJ61m1dJXES8VFVU Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNKgzbBxPjaDzwzT7xhx6PfUJvzLbd6fmaC2WchTFonWrj Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNShoeU4tAEHRL9c84avSeSyDyNakAAv4zmUzo5abbKzkP Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNK9ChRBNB6HcWxqKmRg9iwgomSPdQzy71m293pTuwCXkZ Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) [backend] latestHash not found for 21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt Debug: handler, error Error: Not Found at group-income/backend/routes.js:143:19 at processTicksAndRejections (node:internal/process/task_queues:95:5) at exports.Manager.execute (group-income/node_modules/@hapi/hapi/lib/toolkit.js:60:28) at Object.internals.handler (group-income/node_modules/@hapi/hapi/lib/handler.js:46:20) at exports.execute (group-income/node_modules/@hapi/hapi/lib/handler.js:31:20) at Request._lifecycle (group-income/node_modules/@hapi/hapi/lib/request.js:372:32) at Request._execute (group-income/node_modules/@hapi/hapi/lib/request.js:280:9) GET /assets/js/chunk-JHX3YPDQ-cached.js.map GET /assets/js/chunk-JHX3YPDQ-cached.js.map GET /assets/js/sw-primary.js ============[pubsub] Socket 3-1ac32d connected. Total: 4 [pubsub] Received 'sub' on socket 3-1ac32d {"type":"sub","dontBroadcast":true,"contractID":"21XWnNHdWgCi6vtBjUsZMwBp9EYB8x1QZFHyMsLCjN7rjzNSZR"} [pubsub] Already subscribed to 21XWnNHdWgCi6vtBjUsZMwBp9EYB8x1QZFHyMsLCjN7rjzNSZR [pubsub] Received 'sub' on socket 3-1ac32d {"type":"sub","dontBroadcast":true,"contractID":"21XWnNKgzbBxPjaDzwzT7xhx6PfUJvzLbd6fmaC2WchTFonWrj"} [pubsub] Already subscribed to 21XWnNKgzbBxPjaDzwzT7xhx6PfUJvzLbd6fmaC2WchTFonWrj [pubsub] Received 'sub' on socket 3-1ac32d {"type":"sub","dontBroadcast":true,"contractID":"21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt"} [pubsub] Already subscribed to 21XWnNP642ozRLyXikqLnyYZ7qJfMXjePMvjzS5PX3okhMz3dt [pubsub] Received 'sub' on socket 3-1ac32d {"type":"sub","dontBroadcast":true,"contractID":"21XWnNVTbdD3LFcjivbhm8U5YoynbNbGSStJ61m1dJXES8VFVU"} [pubsub] Already subscribed to 21XWnNVTbdD3LFcjivbhm8U5YoynbNbGSStJ61m1dJXES8VFVU [pubsub] Received 'sub' on socket 3-1ac32d {"type":"sub","dontBroadcast":true,"contractID":"21XWnNVcpe4tCJoXXS8y4nFURZfTotdZShWNm9AMAiyk3XgQNn"} [pubsub] Already subscribed to 21XWnNVcpe4tCJoXXS8y4nFURZfTotdZShWNm9AMAiyk3XgQNn [pubsub] Received 'sub' on socket 3-1ac32d {"type":"sub","dontBroadcast":true,"contractID":"21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT"} [pubsub] Already subscribed to 21XWnNPLGagngHPo6oRW3CmH1ercpga7NRDA2RPkSFV1c8JSFT [backend] latestHash not found for 21XWnNHdWgCi6vtBjUsZMwBp9EYB8x1QZFHyMsLCjN7rjzNSZR Debug: handler, error ```

[taoeffect]

@snowteamer proof that this isn't a problem with browser sync! It still happens on port :8000!

[taoeffect]

@snowteamer Over on Slack I mentioned that I saw this in a previous backend log when the banner came up:

Debug: connection, client, error 
    Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:217:20)
Debug: request, error, abort 
Debug: response, error, aborted 

However today I briefly saw the banner come and go on port 8000 and didn't see these log messages... so, unclear whether that had anything to do with it.

[taoeffect]

If the web socket stuff isn't working well, we could consider also switching to EventSource...