node:events once isn't working as expected in node-redis tests

sjpotter commented 3 weeks ago

Version

v18.19.1

Platform

Linux spotterT490 6.8.0-38-generic #38-Ubuntu SMP PREEMPT_DYNAMIC Fri Jun  7 15:25:01 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

node:events

What steps will reproduce the bug?

In node-redis we fire events (such as a connection being made to a server 'connect', the connection being ready 'ready', and the connection being shutdown, 'end') amongst others. In practice, these are proxied to the user from an underlying object.

see - https://github.com/redis/node-redis/blob/949b944b0f01fa207980b5aa925590d7c32f6073/packages/client/lib/client/index.ts#L438-L464

We have a test to make sure these fires correctly, but that test is failing at the moment in a manner that we can't figure out (but can play around with to get to work, which makes us scratch our head even more)

test - https://github.com/redis/node-redis/blob/949b944b0f01fa207980b5aa925590d7c32f6073/packages/client/lib/client/index.spec.ts#L119-L133

If I rewrite the test to be

    const p1 = once(client, 'connect');
    const p2 = once(client, 'ready');
    const p3 = once(client, 'end');

    await Promise.all([
      p1,
      p2,
      client.connect()
    ]);

    await Promise.all([
      p3,
      client.close()
    ]);

the test reliably passes as the once receives the 'end' event that it expects. However, if I rewrite it to be

    const p1 = once(client, 'connect');
    const p2 = once(client, 'ready');

    await Promise.all([
      p1,
      p2,
      client.connect()
    ]);

    const p3 = once(client, 'end');

    await Promise.all([
      p3,
      client.close()
    ]);

the test now reliably fails again.

In the code in index.ts (that I linked to above) where we listen and refire the events, for 'end' I stuck in a console.log to indicate that the event is being received, and it prints out as expected always, i just don't receive the 'end' event that should be fired unless the test is structured as noted above.

I'm very confused.

How often does it reproduce? Is there a required condition?

always as noted

What is the expected behavior? Why is that the expected behavior?

the promise that events.once() returns should be satisfied.

What do you see instead?

event promise not being satisfied.

Additional information

No response

sjpotter commented 3 weeks ago

I'm wondering if this is some sort of bug (i.e. why 2 very similar pieces of code behave very differently) or if I/we are doing something obviously (or not so obviously) wrong?

RedYetiDev commented 3 weeks ago

Hi! Can you create a reproduction that doesn't rely on node-redis? One that just uses Node.js (no dependencies)?

sjpotter commented 3 weeks ago

we've been trying, but haven't been able to reproduce it outside of our dev build of node-redis yet. Will update if we can.

lpinca commented 3 weeks ago

I honestly only briefly read the issue description but can it be that p3 is created after the 'end' event is emitted?

sjpotter commented 3 weeks ago

I honestly only briefly read the issue description but can it be that p3 is created after the 'end' event is emitted?

not that I can tell (unless somehow the once() before the Promises.all([p3, client.close()]) somehow executes the client.close() first (client.close() is what caueses 'end' to be emitted).

as I note if I do const p1, p2, p3 ...

then do client.connect(), then do a client.close(), they all resolve as expected, but if I do

const p1, p2, then client.connect() (p1/p2 resolve as expected) and then create p3 and then client.close(), p3 never gets resolved.

I was able to see the same in the node repl (i.e. it stringifies the promise and shows me if its pending or resolved) and if I do

const p1, p2, p3... and then client.open, I can see p1/p2 resolved, while p3 is pending, and then resolved after the client.close(), but not if I move it to after the client.open().

> client2=lib.createClient({RESP: 2})
Class {}
> p1=events.once(client2, 'connect');
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 214,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p2=events.once(client2, 'ready');
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 229,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p3=events.once(client2, 'end');
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 244,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p1
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 214,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p2
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 229,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p3
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 244,
  [Symbol(trigger_async_id_symbol)]: 6
}
> await client2.connect()
Class { _eventsCount: 2 }
> p1
Promise {
  [],
  [Symbol(async_id_symbol)]: 214,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p2
Promise {
  [],
  [Symbol(async_id_symbol)]: 229,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p3
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 244,
  [Symbol(trigger_async_id_symbol)]: 6
}
> await client2.close()
undefined
> p3
Promise {
  [],
  [Symbol(async_id_symbol)]: 244,
  [Symbol(trigger_async_id_symbol)]: 6
}

vs.

> client2=lib.createClient({RESP: 2})
Class {}
> p1=events.once(client2, 'connect');
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 200,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p2=events.once(client2, 'ready');
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 215,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p1
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 200,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p2
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 215,
  [Symbol(trigger_async_id_symbol)]: 6
}
> await client2.connect()
Class { _eventsCount: 0, _events: [Object: null prototype] {} }
> p1
Promise {
  [],
  [Symbol(async_id_symbol)]: 200,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p2
Promise {
  [],
  [Symbol(async_id_symbol)]: 215,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p3=events.once(client2, 'end');
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 343,
  [Symbol(trigger_async_id_symbol)]: 6
}
> p3
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 343,
  [Symbol(trigger_async_id_symbol)]: 6
}
> await client2.close()
undefined
> p3
Promise {
  <pending>,
  [Symbol(async_id_symbol)]: 343,
  [Symbol(trigger_async_id_symbol)]: 6
}

nodejs / node