Getting GOAWAY error about grpc-node

[mkamioner]

Any update on this?

[rdlowrey]

Apologies for reviving but I'm seeing this as well. I'm seeing it in my local development environment running against the cloud pubsub emulator. It looks like it happens at one hour of idle time with the the same topic publishers kept alive in-memory whether or not they've been actively used and a single long-lived topic subscription.

Will continue providing updates as I'd really like to see this code live in a GKE production environment in the next couple of weeks. Thanks in advance for your help.

Environment

• OS: Docker (FROM node:9)
• Node.js: v9.8.0
• npm: 5.7.1
• google-cloud/pubsub: 0.16.5
• grpc: 1.9.1

Trace

E0320 05:05:00.368889271      46 chttp2_transport.cc:1105]   Received a GOAWAY with error code ENHANCE_YOUR_CALM and debug data equal to "too_many_pings"
(node:46) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 channel.error listeners added. Use emitter.setMaxListeners() to increase limit
(node:46) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 channel.ready listeners added. Use emitter.setMaxListeners() to increase limit
events.js:165
      throw er; // Unhandled 'error' event
      ^

Error: Cancelled
    at StreamProxy.onConnectionStatus (/app/node_modules/@google-cloud/pubsub/src/connection-pool.js:267:21)
    at StreamProxy.emit (events.js:180:13)
    at ClientDuplexStream.<anonymous> (/app/node_modules/google-gax/lib/streaming.js:130:17)
    at ClientDuplexStream.emit (events.js:180:13)
    at ClientDuplexStream._emitStatusIfDone (/app/node_modules/grpc/src/client.js:273:10)
    at ClientDuplexStream._readsDone (/app/node_modules/grpc/src/client.js:236:8)
    at readCallback (/app/node_modules/grpc/src/client.js:296:12)
Emitted 'error' event at:
    at ConnectionPool.<anonymous> (/app/node_modules/@google-cloud/pubsub/src/subscription.js:1039:10)
    at ConnectionPool.emit (events.js:180:13)
    at StreamProxy.onConnectionStatus (/app/node_modules/@google-cloud/pubsub/src/connection-pool.js:269:14)
    at StreamProxy.emit (events.js:180:13)
    [... lines matching original stack trace ...]
    at readCallback (/app/node_modules/grpc/src/client.js:296:12)

UPDATE 1

I did an rm -rf node_modules && npm cache clean --force && npm install just to ensure all grpc deps were present ... will update if/when problem reoccurs.

UPDATE 2

Since ensuring all necessary deps were present with the npm operations above I've encountered no problems with the relevant code executing continuously over the last 24 hours or so. It seems like guaranteeing necessary dependencies solves the issue and it may not be a "grpc problem," though better internal validation and error messages from the grpc lib would help users encountering this problem actually diagnose the real underlying issue of missing deps (rather than assuming it's a grpc bug).

I'll update if I encounter the problem again with all deps installed ...

UPDATE 3

I still receive sporadic errors of the following form when I hold open a single pubsub topic subscription for several hours:

E0322 09:47:18.099168287      30 chttp2_transport.cc:1105]   Received a GOAWAY with error code ENHANCE_YOUR_CALM and debug data equal to "too_many_pings"

This feels like an error in the pubsub component because I doubt it should be pinging frequently enough to receive ENHANCE YOUR CALM when there's only a single active subscription and four or five long-lived topic publishers, but ... ¯\_(ツ)_/¯

^ FYI @murgatroid99

[mattxgreen]

Receiving the same

[wenbozhu]

Let's have the discussion at googleapis/nodejs-pubsub (which recently enabled grpc keep-alive).

[rvillane]

I'm getting the same with version 0.16.1

[murgatroid99]

We have published 1.8.4, which includes a ping related fix that may resolve this problem.

[theacodes]

Users are still experiencing this googleapis/nodejs-pubsub#27 (comment)

[murgatroid99]

Users are still experiencing this problem because pubsub has not upgraded to gRPC 1.8.4.

[baracoder]

For me the issue appeared when upgrading from 1.4 to 1.8, but keeping custom channel options. Removing the custom channel options seams to have solved it. I think it might have had something to do with the keep-alive or ping with no data settings.

[mkamioner]

@murgatroid99 see the comment - still not working even after upgrading to gRPC 1.8.4 - please advise.

[y-zeng]

@mkamioner Was the issue still observed after manually upgrading the pubsub gRPC dependency to 1.8.4?

@baracoder Could you please point me to the custom channel options?

[mkamioner]

@y-zeng - unfortunately yes. I double checked the version and the error continues

[murgatroid99]

@mkamioner Can you share the output of npm ls, either here or in a gist?

[murgatroid99]

We have published gRPC 1.10.1 with another potential fix for this problem.

[iMuFeng]

ERROR 88195 nodejs.unhandledRejectionError: 13 INTERNAL: GOAWAY received(api=ems.eMSAdapter.sync, code=13, INTERNAL)
    at GrpcSubClass._invokeRPC (/Users/mufeng/node_modules/egg-grpc/lib/base_grpc.js:113:17)
    at GrpcSubClass.BaseGrpc.(anonymous function) [as sync] (/Users/mufeng/node_modules/egg-grpc/lib/base_grpc.js:27:21)
    at DevController.sync_mailboxes (/Users/mufeng/app/controller/Users/mufeng.js:22:12)
    at Object.callFn (/Users/mufeng/node_modules/egg-core/lib/utils/index.js:36:21)
    at Object.classControllerMiddleware (/Users/mufeng/node_modules/egg-core/lib/loader/mixin/controller.js:84:20)
    at Object.callFn (/Users/mufeng/node_modules/egg-core/lib/utils/index.js:36:21)
    at wrappedController (/Users/mufeng/node_modules/egg-core/lib/utils/router.js:322:18)
    at dispatch (/Users/mufeng/node_modules/koa-router/node_modules/koa-compose/index.js:44:32)
    at next (/Users/mufeng/node_modules/koa-router/node_modules/koa-compose/index.js:45:18)
    at /Users/mufeng/node_modules/koa-router/lib/router.js:346:16
    at dispatch (/Users/mufeng/node_modules/koa-router/node_modules/koa-compose/index.js:44:32)
    at /Users/mufeng/node_modules/koa-router/node_modules/koa-compose/index.js:36:12
    at dispatch (/Users/mufeng/node_modules/koa-router/lib/router.js:351:31)
    at dispatch (/Users/mufeng/node_modules/koa-compose/index.js:42:32)
    at next (/Users/mufeng/node_modules/koa-compose/index.js:43:18)
code: 13
metadata: Metadata { _internal_repr: {} }
details: 'GOAWAY received'
name: 'unhandledRejectionError'
pid: 88195
hostname: mufengs MacBook-Pro.local

gRPC 1.10.1 also has this problem

[murgatroid99]

The fix mentioned was specifically for the "too_many_pings" error. In general, a server may choose to respond with a "GOAWAY" error for any number of reasons, and this is simply how that is surfaced.

[nicolasnoble]

The initial GOAWAY problem due to too many pings seems to have been fixed in the 1.10.1 release, and since we are now at 1.12.0, I am closing this one.