Send callback may not be called if message is sent during upgrade window
jonathanperret opened this issue · 2 comments
Describe the bug
There is a 100-millisecond window starting with the emission of the upgrading
event where a message sent by the server will be correctly received by the client, but never trigger the callback passed to send
.
To Reproduce
Engine.IO server version: 6.5.4
Server
const engine = require("engine.io");
const server = engine.listen(3000, {});
server.on("connection", (socket) => {
console.log("connection");
// this callback would be called correctly:
// socket.send("hello", ()=>console.log("message sent"));
socket.on("upgrading", ()=>{
// the following callback is not called, even though the message is sent
socket.send("hello", ()=>console.log("message sent"));
// this callback would also fail to be called:
// setTimeout(() => { socket.send("hello", ()=>console.log("message sent")); }, 50);
// this callback would correctly be called:
// setTimeout(() => { socket.send("hello", ()=>console.log("message sent")); }, 150);
});
socket.on("message", (data) => {
console.log("data", data);
});
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");
socket.on("open", () => {
console.log("open");
socket.on("message", (data) => {
console.log("data", data);
});
socket.on("close", () => {
console.log("close");
});
});
Expected behavior
I expected the callback passed to send
to be called if the message was successfully sent. Instead what happens with the code above is:
- the client logs that the message was received;
- the server never logs that the callback was called.
If the message is sent before the upgrading
event (e.g. right upon the connection
event), the callback is correctly fired. Likewise, if the message is sent more than 100 milliseconds after receiving the upgrading
event, the callback is fired as well.
Platform:
- Device: M1 MacBook Pro
- OS: macOS Sonoma 14.2
Additional context
I hit upon this bug not because I specifically wanted to send messages right after the upgrading
event, but because the code I was integrating engine.io
into occasionnally ended up sending its first message within that window (which tends to start a few milliseconds after receiving the connection
event and lasts for 100 milliseconds as reported above).
It's only after investigating the bug that I identified that specific window. The duration of 100 milliseconds is related to the interval before the server sends its first noop
packet to speed up upgrading here (changing that interval in socket.ts
changes the duration of the problematic window).
I have created a branch that shows the bug as a failing test here: main...jonathanperret:engine.io:lost-callback-while-upgrading
Another observation is that once such a lost callback has occured, future callbacks do get fired but out of sync: the callback for message N
is only fired when message N+1
(or a ping
packet) is sent and so on.
@jonathanperret thanks a lot for all the details. This should be fixed by 362bc78, included in version 6.6.0. Could you please check?
I think this can be closed now. Please reopen if needed.