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

websocket: send callbacks are not all called if multiple messages are sent rapidly #698

Closed
jonathanperret opened this issue Feb 23, 2024 · 1 comment
Labels
bug Something isn't working
Milestone

Comments

@jonathanperret
Copy link
Contributor

Describe the bug

When using the websocket transport, if socket.send() is called multiple times in the same tick with a callback provided, some of the callbacks may not be called even though the messages were sent.

To Reproduce

Engine.IO server version: 6.5.4

Server

const engine = require("engine.io");
const server = engine.listen(3000, { transports: ["websocket"] });

server.on("connection", (socket) => {
  console.log("connection");

  socket.send("1", ()=>console.log("callback 1 called"));
  socket.send("2", ()=>console.log("callback 2 called"));
  socket.send("3", ()=>console.log("callback 3 called"));
  socket.send("4", ()=>console.log("callback 4 called"));

  socket.on("close", () => {
    console.log("close");
  });
});

Engine.IO client version: 6.5.0

Client

const socket = new (require("engine.io-client").Socket)("ws://localhost:3000", { transports:["websocket"] });

socket.on("open", () => {
  console.log("open");

  socket.on("message", (data) => {
    console.log("data", data);
  });

  socket.on("close", () => {
    console.log("close");
  });
});

Expected behavior

The server above should log:

connection
callback 1 called
callback 2 called
callback 3 called
callback 4 called

Instead it logs:

connection
callback 1 called
callback 2 called

It does log callback 3 called after about 25 seconds, and callback 4 called 25 seconds later — enabling debug logs shows that ping packets are triggering those late callbacks.

The client logs that the messages are all received immediately.

Platform:

  • Device: M1 MacBook Pro
  • OS: macOS Sonoma 14.2

Additional context

There is an existing test that is supposed to check this scenario. However it does not expose this bug, because it does not specify a transport and defaults to polling, which also makes it redundant with the next test. That first test also only sends two messages, when the test program above shows that only the third and further callbacks are delayed.

@jonathanperret jonathanperret added the bug Something isn't working label Feb 23, 2024
jonathanperret added a commit to jonathanperret/engine.io that referenced this issue Feb 23, 2024
jonathanperret added a commit to jonathanperret/engine.io that referenced this issue Feb 23, 2024
jonathanperret added a commit to jonathanperret/engine.io that referenced this issue Feb 23, 2024
jonathanperret added a commit to jonathanperret/engine.io that referenced this issue Feb 23, 2024
@jonathanperret jonathanperret changed the title websocket: send callbacks are not all called if multiple packets are sent rapidly websocket: send callbacks are not all called if multiple messages are sent rapidly Feb 23, 2024
darrachequesne pushed a commit that referenced this issue Jun 13, 2024
With the `websocket` transport, the callbacks which indicate that the
packets are actually written were not properly called.

Example:

```js
socket.send("hello", () => {
  // the message has been written to the underlying transport
});
```

The bug was caused by the `websocket` transport (and `webtransport` as
well) having its `supportsFraming` property set to `true`, despite
having been changed in [1] to emit a single `drain` event for each
batch of messages written to the transport like the `polling` transport
always did. Note that although [1] is partially reverted in [2], the
new `drain` event behavior is preserved as called out in that commit's
message.

The `supportsFraming` attribute was introduced in [3] (amended by [4])
as a way to distinguish transports that emit one `drain` per message
from those that emit one `drain` per batch. Since the delivery of
`send` callbacks depends on matching `drain` events with
`transport.send` calls, that distinction is vital to correct behavior.

However, now that all transports have converged to "one `drain` per
batch" behavior, this `supportsFraming` property can be retired (and
the code for calling callbacks simplified).

[1]: #618
[2]: a65a047
[3]: #130
[4]: #132

Related: #698
@darrachequesne
Copy link
Member

This should be fixed by fc21c4a, included in version 6.6.0. Thanks!

@darrachequesne darrachequesne added this to the 6.6.0 milestone Jun 22, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

2 participants