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

MaxListenersExceededWarning: Possible EventEmitter memory leak detected #694

Closed
shanshanzhu opened this issue Jan 7, 2019 · 12 comments
Closed
Assignees

Comments

@shanshanzhu
Copy link

shanshanzhu commented Jan 7, 2019

Problem description

Node warning observed
MaxListenersExceededWarning: Possible EventEmitter memory leak detected when retrying connection for serverStreaming.

Reproduction steps

  1. Set up grpc client connection without grpc server
  2. Receive 'Internal HTTP2 error' error when the grpc server is not available
  3. Create retry logic to reconnect to grpc server whenever there is an error emitted from the stream.
  4. After retrying for 11~15 times, we see this warning:
MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added. Use emitter.setMaxListeners() to increase limit
    at _addListener (events.js:280:19)
    at Http2Channel.addListener (events.js:297:10)
    at Http2Channel.once (events.js:341:8)
    at connecting.Promise (node_modules/@grpc/grpc-js/build/src/channel.js:248:26)
    at new Promise (<anonymous>)
    at Http2Channel.connect (node_modules/@grpc/grpc-js/build/src/channel.js:229:35)
    at Http2Channel._startHttp2Stream (node_modules/@grpc/grpc-js/build/src/channel.js:173:42)
    at Http2CallStream.sendMetadata (node_modules/@grpc/grpc-js/build/src/call-stream.js:325:22)
    at ServiceClientImpl.makeServerStreamRequest (node_modules/@grpc/grpc-js/build/src/client.js:171:14)
    at apply (node_modules/lodash/lodash.js:478:17)
    at ServiceClientImpl.wrapper (node_modules/lodash/lodash.js:5323:16)

Environment

  • MacOS 10.14 (18A391)
  • Node version [v8.12.0]
  • Node installation method [e.g. nvm]
  • Package name and version [grpc-js@0.3.2]

Additional context

Adding process.on('warning', e => console.warn(e.stack)); will show the stack trace.

Above this line of code

https://github.com/grpc/grpc-node/blob/master/packages/grpc-js/src/channel.ts#L340

If we add

                        console.log(this.listenerCount('connect'));
                        console.log(this.listenerCount('shutdown'));
                        this.removeListener('shutdown', onShutdown);

We see incrementing of connect listenerCount

Adding

 this.removeListener('connect', onConnect);

to onConnect function fix this incrementing, and also fix the error.

Also noted is that for the first 2 or 3 retry the listeners doesn't increment. It only increment after a couple retrials.

I tried to dig down the root cause of this issue but couldn't trace it down. The suggested removeListener fix is low risk and would your guys consider this fix?

@cjihrig
Copy link
Contributor

cjihrig commented Jan 8, 2019

Can you share runnable example code?

@murgatroid99
Copy link
Member

That really shouldn't happen. There should only be one of those listeners on each event at a time. The specific retry code might help pinpoint what's going wrong there.

@shanshanzhu
Copy link
Author

Here's some pseudo code before we figure out a runnable test case:

const callServerStream = (...args) => {
  const stream = client[rpcMethod](...args);
  stream.on('data', () => {})
  stream.on('error', () => {
      // this function triggers a callback to the browser, which then invoke `callServerStream` again.
      // In our test, we setup a fake port for the grpc client to connect to, and we end up retrying this loop very fast (no delay) for > 11 times before the error shows up.
  })
};

@murgatroid99 murgatroid99 self-assigned this Mar 4, 2019
@murgatroid99
Copy link
Member

I cannot figure out how to replicate this warning. I'm working on Linux but otherwise the environment is the same. I don't think I will be able to figure this out without specific code to reproduce it.

@shanshanzhu
Copy link
Author

Can you send an example of testable and reproducible code that you wanna see? It will help me to understand what you need.

@murgatroid99
Copy link
Member

I'm just looking for a script or program or whatever that triggers this warning when you run it.

@schmidt-sebastian
Copy link

I have received a user report in the @google-cloud/firestore repo about this issue (googleapis/nodejs-firestore#661). While I wasn't able to re-produce this issue myself, I dug around in the code a bit. My current theory is as follows:

It seems that every time _write is called, the client calls into the FilterStack. The DeadlineFilter then adds a connectivyStateChanged listener every time it is invoked. While I don't fully understand this codepath, it seems like this listener would only need be registered once.

@schmidt-sebastian
Copy link

schmidt-sebastian commented May 28, 2019

As an additional note, I can re-produce this reliably if I turn on package loss for my Wifi and run the following test: https://github.com/googleapis/nodejs-firestore/blob/master/dev/system-test/firestore.ts#L928

This test open 150 bidirectional streams over two HTTP2 channels, which I assume ends up calling _write 100 times for the first channel.

Stacktrace:

(node:42450) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connectivityStateChanged listeners added. Use emitter.setMaxListeners() to increase limit
MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connectivityStateChanged listeners added. Use emitter.setMaxListeners() to increase limit
    at _addListener (events.js:280:19)
    at Http2Channel.addListener (events.js:297:10)
    at connectionReady.Promise (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/deadline-filter.js:86:34)
    at new Promise (<anonymous>)
    at DeadlineFilter.sendMetadata (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/deadline-filter.js:70:36)
    at FilterStack.sendMetadata (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/filter-stack.js:26:38)
    at Http2Channel._startHttp2Stream (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/channel.js:188:50)
    at Http2CallStream.sendMetadata (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/call-stream.js:338:22)
    at ServiceClientImpl.makeBidiStreamRequest (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/client.js:195:14)
    at ServiceClientImpl.<anonymous> (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/@grpc/grpc-js/build/src/make-client.js:92:19)
    at /Users/mrschmidt/GitHub/googleapis/nodejs-firestore/dev/src/v1/firestore_client.js:198:39
    at /Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/google-gax/src/streamingCalls/streamingApiCaller.ts:81:19
    at /Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/google-gax/src/normalCalls/timeout.ts:69:13
    at StreamProxy.setStream (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/google-gax/src/streamingCalls/streaming.ts:178:20)
    at StreamingApiCaller.call (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/google-gax/src/streamingCalls/streamingApiCaller.ts:98:12)
    at funcPromise.then.then.apiCall (/Users/mrschmidt/GitHub/googleapis/nodejs-firestore/node_modules/google-gax/src/createApiCall.ts:114:26)
    at <anonymous>

@thertzelle
Copy link

I'm getting this error too, but since I need this working today, I'm going to change my plans from using the '@Google-Cloud' module. But here is my stacktrace:

(node:30808) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connectivityStateChanged listeners added. Use emitter.setMaxListeners() to increase limit at _addListener (events.js:255:17) at Http2Channel.addListener (events.js:271:10) at Promise (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/deadline-filter.js:80:30) at new Promise (<anonymous>) at DeadlineFilter.sendMetadata (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/deadline-filter.js:63:16) at FilterStack.sendMetadata (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/filter-stack.js:26:38) at Http2Channel._startHttp2Stream (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/channel.js:188:50) at Http2CallStream.sendMetadata (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/call-stream.js:338:22) at ServiceClientImpl.makeUnaryRequest (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/client.js:136:14) at ServiceClientImpl.<anonymous> (/Users/bgates/Development/windows-xp-api/node_modules/@google-cloud/kms/node_modules/@grpc/grpc-js/build/src/make-client.js:92:19)

@murgatroid99
Copy link
Member

@grpc/grpc-js version 0.4.1 is out with a fix for that latest reported warning.

@jmacedoit
Copy link

This happens with my firestore node server setup always on startup (where I begin listening to several collections) ever since i upgraded to @google-cloud/firestore": "^2.1.0". And the greater the number of listeners, the greater the number of messages. It looks like this message is output once for every 100 or so streams I'm listening.

@jakeleventhal
Copy link

Seeing something potentially related here googleapis/nodejs-firestore#768

@lock lock bot locked as resolved and limited conversation to collaborators Mar 10, 2020
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants