libp2p handle resulting in MaxListenersExceededWarning, potentially blocking other connections in the dial queue

[haydenyoung]

We have been building an RPC server using libp2p protocols with handlers (e.g. libp2p.handle('my/protocol', ...). Clients connect and disconnect from this RPC server, each time opening a stream, transferring data then closing the stream. I have monitored the stream status and can confirm that streams are closing once data has completed transferring.

One problem I'm experiencing is the timeout of streams after repeated connections. Over time, I begin to see MaxListener warnings, which eventually leads to connection timeouts and, ultimately, the server crashing.

In particular, I'm seeing the warning:

(node:320595) MaxListenersExceededWarning: Possible EventTarget memory leak detected. 11 abort listeners added to [AbortSignal]. Use events.setMaxListeners() to increase limit
    at [kNewListener] (node:internal/event_target:572:17)
    at [kNewListener] (node:internal/abort_controller:241:24)
    at EventTarget.addEventListener (node:internal/event_target:685:23)
    at anySignal (file:///~/orbitdb/voyager/node_modules/any-signal/dist/src/index.js:21:20)
    at DialQueue.createDialAbortController (file:///~/orbitdb/voyager/node_modules/libp2p/dist/src/connection-manager/dial-queue.js:200:24)
    at queue.add.peerId.peerId [as fn] (file:///~/orbitdb/voyager/node_modules/libp2p/dist/src/connection-manager/dial-queue.js:126:33)
    at Job.run (file:///~/orbitdb/voyager/node_modules/@libp2p/utils/dist/src/queue/job.js:56:50)
    at Queue.tryToStartAnother (file:///~/orbitdb/voyager/node_modules/@libp2p/utils/dist/src/queue/index.js:79:17)
    at Queue.add (file:///~/orbitdb/voyager/node_modules/@libp2p/utils/dist/src/queue/index.js:121:14)
    at DialQueue.dial (file:///~/orbitdb/voyager/node_modules/libp2p/dist/src/connection-manager/dial-queue.js:123:27)

These warnings increase in number the more times I connect a client.

However, I can't work out what is causing this issue.

I believe this is what is causing the timeouts and server crash but it is difficult to confirm. To start, I guess I could increase the max listeners to see if it delays the problem? If so, how would I implement such a fix?

The max listeners exceeded issue would indicate something else is causing problems, maybe streams left open (although monitoring them suggests they get closed once the data has been fully transferred).

[Edit]

What's interesting is I've also noticed I'm getting listener warnings for subscription-change too:

(node:416599) MaxListenersExceededWarning: Possible EventTarget memory leak detected. 11 subscription-change listeners added to GossipSub. Use events.setMaxListeners() to increase limit

[haydenyoung]

Further investigation points to inconsistent firing of the libp2p.pubsub's subscription-change event.

To replicate the problem:

Clone the repo and set up the node project:

git clone https://github.com/orbitdb/orbit-db-pinner.git
git checkout pinner/new-refactor-2
npm i

Launch the server from the command line:

cd /path/to/orbit-db-pinner
npm run start:orbiter1

Place the attached file into ./test/ and rename as lander-test.js:

lander-test.js.txt

Launch another terminal and run the lander-test:

cd /path/to/orbit-db-pinner/test
node lander-test.js

If you re-run the lander-test.js a few times, eventually it will eventually hang. This is because pubsub's "subscription-change" event is not fired. The problem is the event being fired/not fired is inconsistent. Because I was receiving listener warnings, I suspected that this could be the problem.

Firstly, it is worth pointing out that both peers successfully connect. This can be witnessed by using the peer:connect/disconnect on both peers.

The subscription-change listener is registered on line 280 in /path/to/orbit-db-pinner/node_modules/@orbitdb/core/src/sync.js.

The line that calls pubsub.subscribe which should trigger the subscription-change event is line 284 in /path/to/orbit-db-pinner/node_modules/@orbitdb/core/src/sync.js.

The subscribe is always successfully called on the server (pinner). However, this doesn't necessarily result in the subscription-change event being called within the client. Sometimes it fires, sometimes it doesn't. What is the best way to diagnose an event listener which inconsistently fails?

[Edit]

I've tracked the problem to here. It seems that sometimes the stream is not ready in time and so source is empty. Could this be related to this?

[haydenyoung]

As suggested in the js-libp2p maintainers call, I have opened an issue.