Heartbeat timeout after update 4.8.1 -> 4.11.1

[buhln]

After updating the package on the client side to version 4.11.1, I get all the time a heartbeat timeout. It happens in version 4.10.0, too.

Here my heartbeat config which is working fine in 4.8.1:

    heartbeat: {
        message: 'ping',
        returnMessage: 'pong',
        timeout: 30000,
        interval: 20000,
      },

On the server side I am running python websockets in version 13.1:

The heartbeat reply is solved as follows:

if message == 'ping':
  await websocket.send('pong')
  continue

Downgrading to 4.8.1 removes the issue.

Edit: A short investigation with wireshark showed that in version 4.11.1 the ping message is not send to the backend. Therefore it timeouts. In version 4.8.1 the incoming (from backend side seen) ping text message is shown and the reply from the backend with text message "pong" happens.

On question: My understanding of the source code is, that the timer for the heartbeat is set on webSocketInstance.onopen and defined in heartbeat.ts. Therefore the first heartbeat ping is sent after the defined intervall in the heartbeat-options? I ask this question because when the websocket connection is established to my backend tokens were exchanged to check if the connection is authenticated. If the first message the client sends an heartbeat-ping this message will be dropped.

[nbran]

I'm experiencing the same issue after upgrading to 4.11.1 from 4.9.0.

Perhaps @w666 can help us investigate as it seems related to #250

[w666]

Hi there, I will try to have a look on this issue this week.

[w666]

@buhln @nbran

Yes, that is correct, first ping from client is sent after interval. here is a small test I used to confirm that

test.each([false, true])('Options#heartbeat, first ping is send after interval', async (shareOption) => {
  options.heartbeat = {
    message: 'ping',
    timeout: 1000,
    interval: 500, // <--- interval 500 millis
  };
  options.share = shareOption;

  const {
    result,
  } = renderHook(() => useWebSocket(URL, options));

  if (shareOption) {
    renderHook(() => useWebSocket(URL, options));
  }

  await server.connected;
  expect(server).toHaveReceivedMessages([]);
  await sleep(100)
  expect(server).toHaveReceivedMessages([]);
  await sleep(100)
  expect(server).toHaveReceivedMessages([]);
  await sleep(100)
  expect(server).toHaveReceivedMessages([]); // after 300 millis ping is not send
  await sleep(200)
  expect(server).toHaveReceivedMessages(["ping"]); // but send after 500 millis
  server.send('pong')
  expect(result.current.readyState).toBe(WebSocket.OPEN); // websocket is still open
});

Are you authenticating your client using WS messages or some other way?
If over WS messages then I would assume that onmessage event is not triggered maybe.

Could you please briefly describe your message flow? For example:

1. connection is open
2. connection authenticated (after 15 seconds)
3. client did not send an pings
4. no other messages sent from client or server?
5. connection terminated by timeout after ~39 seconds

Something else that might be important?

[buhln]

@w666: Sorry for the late reply.

The authentication is happening by sending a WS message with a token to the backend in the onOpen callback. The reply from the backend takes only a fraction of a second. If the sent message contains a wrong token, the backend is closing the connection with an response code 1008 "unauthorized". In this case the frontend the onClose callback gets this response code and stops additional conntection efforts and a modal in the frontend is shown. This is hardly simplyfied but important is, that onOpen a message is sent and if the message contains the correct content the backend accepts the connection. If not it is closed by the backend.

All of this happens before the first intervall of the hardbeat function is elapsed.

A short investigation with Wireshark showed, that the client/frontend is not sending the ping message. Therefore the backend is not sending the reply and this caused the timeout and triggers a reconnect.

[w666]

Hi @buhln,

Thanks for the detailed info. I will try to write a test to replicate the issue. Will reply here when I have something.

[w666]

Hi @buhln @nbran,

I was trying to replicate the problem but could not, well, I managed to get a scenario when I got very similar behavior, but one bit is not quite the same. You mentioned that your browser sends token almost immediately after connection is established and reply from server takes just takes a fraction of the second, but looking on your configuration I can assume that your token was sent a bit later. Unfortunately, I don't have enough information to confirm that (no network dump).

Anyway, I think the issue is refactored code and your config, I mean this bit

        timeout: 30000,
        interval: 20000,

timeout is very close to interval, I think it should be something like interval = timeout / 3.

I created a test that has similar config and managed to get behavior that looks like your issue. I decided to improve heartbeat so such configurations should not cause such issues and created a PR. Could you please review it and provide feedback if you agree or not with the design decision.

The test in that PR was failing before my changes but pass now. I think it should resolve your issue as well.

Thanks.

[buhln]

I appreciate our effort and I like to test your changes. After installing the package with the changes direct from git my react project is not able to resolve the module longer. It is missing it in the src folder of the project: Module not found: Error: Can't resolve 'react-use-websocket' in '/home/username/appname/src'. It is definitly offtopic but after some hours of googleing and try & error I am not able to motivate it to work. Any ideas/hints?

The entry in the package.json of the project looks like "react-use-websocket": "github:w666/react-use-websocket".

[w666]

There is a workaround how to get changes locally.

In you web app project:

1. You just set latest version of react-use-websocket in package.json and run npm i

    "react-use-websocket": "^4.11.1"

In separate temp directory:

1. Clone git repo from git clone https://github.com/w666/react-use-websocket
2. Switch to branch git checkout feature-255-improve-heartbeat
3. Install dependencies and build project npm i && npm run compile
4. Copy compiled heartbeat.* files to node_modiles in your project, for example (assuming you use linux or macos)

cp ${CLONED_PROJECT_DIR}/dist/lib/heartbeat.* ${YOUR_WEB_APP_DIR}/node_modules/react-use-websocket/dist/lib/

Now you can run your app locally in dev mode and you will get patched heartbeat.

Hopefully it helps.

[buhln]

Nice! Sometime the simplest solutions are the best. I tested the changes successful and updated the PR with my results.

[robtaussig]

@w666 Thank you for your time and for submitting the PR! I added some comments, but have limited time these days with a baby daughter, so I apologize if I missed anything:)

[w666]

@buhln

I need to refactor code a bit to avoid unnecessary ping messages in shared mode. Was planning to have a look today but there was accident at my neighbor house so lost entire evening. Will try have a look later this week.

@robtaussig thanks for taking a look and feedback.

[buhln]

Thanks. As soon as you are ready I will test it again.