Grpc-node: Error: No connection established

Created on 4 Oct 2019  Β·  91Comments  Β·  Source: grpc/grpc-node

Problem description

Since google-gax forced the grpc-js version to 0.6.4 (https://github.com/googleapis/gax-nodejs/commit/628db9e84c61017dfaba22ac7c2215e2c79c9745), I am having the following issue :

Error: No connection established
    at Http2CallStream.call.on (/usr/src/node_modules/@google-cloud/bigtable/node_modules/@grpc/grpc-js/build/src/call.js:68:41)
    at Http2CallStream.emit (events.js:203:15)
    at Http2CallStream.EventEmitter.emit (domain.js:448:20)
    at process.nextTick (/usr/src/node_modules/@google-cloud/bigtable/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22)
    at process._tickCallback (internal/process/next_tick.js:61:11)

Reproduction steps

The bug only happens after one hour. We are using grpc-js inside @google-cloud/bigtable and our bigtable instance is autoscaling.

picture apatora
👍45

Most helpful comment

@alexander-fenster I tried v0.6.5 and I still have the issue. Lots of Error: No connection established after an hour of runtime.

picture apatora on 5 Oct 2019
👍8

All 91 comments

Thank you for the report! Just to confirm, does that mean that the script should have an hour of idle time with no network requests to experience that, or just an hour of runtime?

alexander-fenster picture alexander-fenster on 4 Oct 2019

Similar issue on @google-cloud/[email protected]
After about 10 minutes of idle time with no network requests, any call to "publish" callbacks after 10 minutes (maxRetryDelayMillis) to say "Retry total timeout exceeded before any response was received"
To be able to find this error "No connection established", I had to add logs in the google-gax module

harscoet picture harscoet on 4 Oct 2019

We are seeing the exact same issues as @harscoet with @google-cloud/[email protected]

reichjustin picture reichjustin on 4 Oct 2019

It happens after an hour of runtime (I had this issue on our main API). Then it starts to throw those errors on separate processes progressively.

Capture d’écran 2019-10-04 aΜ€ 18 21 54

apatora picture apatora on 4 Oct 2019

Same issue when using @google-cloud/datastore which depends on google-gax

weipublic picture weipublic on 4 Oct 2019
👍3

We are looking into this and will either fix it ASAP, or release an update to google-gax that pins @grpc/grpc-js to an older version.

alexander-fenster picture alexander-fenster on 4 Oct 2019

Just to make sure I understand, are you making some requests that succeed, then going idle for a while, then making more requests and seeing these errors?

murgatroid99 picture murgatroid99 on 4 Oct 2019

Also, do you folks run your code on a physical machine, or in any kind of cloud e.g. cloud functions?

alexander-fenster picture alexander-fenster on 4 Oct 2019

@murgatroid99 we are seeing that our services are running fine for 10ish minutes and then we start dropping connections. At this time we see deadline exceeded errors. Once this happens we are unable to have successful requests with both google-cloud/pubsub and google-cloud/datastore

@alexander-fenster we are seeing this using with services running within GKE containers

reichjustin picture reichjustin on 4 Oct 2019
👍6

We downgraded @grpc/grpc-js to 0.5.4 and also other related google libraries to a version that don't depend on @grpc/[email protected]. The problem seems gone. It may related to #1062 & #1061

weipublic picture weipublic on 4 Oct 2019
👍3

If my fix is right, this problem was actually in #1015 but it was overshadowed by other problems.

murgatroid99 picture murgatroid99 on 4 Oct 2019

I have published version 0.6.5 of @grpc/grpc-js. You should pick it up if you update your dependencies. Please try that and see if it solves this problem.

murgatroid99 picture murgatroid99 on 4 Oct 2019

@apatora @harscoet @reichjustin @weipublic Could you folks please check if the fix in v0.6.5 works for you all, and let us know? Thank you!

alexander-fenster picture alexander-fenster on 5 Oct 2019

@alexander-fenster I tried v0.6.5 and I still have the issue. Lots of Error: No connection established after an hour of runtime.

apatora picture apatora on 5 Oct 2019
👍8

Same here, with DataStore and PubSub, 0.6.5 doesn't fix the issue

Vinceveve picture Vinceveve on 7 Oct 2019
😕4

Same issues for us when using @google-cloud/datastore which depends on google-gax

bendoran picture bendoran on 7 Oct 2019

Can someone seeing this issue with grpc-js 0.6.5 run with the environment variables GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG and share the log output? If you can't set environment variables the normal way you can set those on process.env before loading any libraries.

murgatroid99 picture murgatroid99 on 7 Oct 2019

I would also like to understand how exactly this problem is manifesting. Are you seeing one or a few errors and then later calls succeed? Or do you see this error and then all subsequent calls fail with the same error? Or something else?

murgatroid99 picture murgatroid99 on 7 Oct 2019

would be reasonable to suggest using pinned @grpc/grpc-js versions ? just to avoid a large impact when those sensitive dependencies run into issues.

rvillane picture rvillane on 7 Oct 2019
👍2

We have seen those errors starting to occur around 1 hour after a fresh pod creation. After those started, all subsequent calls were starting to fail. Pintpointing lib to previous working version (0.5.2) resolved the issue. (using google Firestore)

Meemaw picture Meemaw on 7 Oct 2019
👍2

I tried the trick suggested in #1027 and run npx npm-force-resolutions && npm install

  "resolutions": {
    "@grpc/grpc-js": "0.5.2",
    "google-gax": "1.6.2"
  }

however, I'm getting the following error:

Error: Cannot find module '@grpc/proto-loader'
    at Function.Module._resolveFilename (internal/modules/cjs/loader.js:636:15)
    at Function.Module._load (internal/modules/cjs/loader.js:562:25)
    at Module.require (internal/modules/cjs/loader.js:690:17)
    at require (internal/modules/cjs/helpers.js:25:18)
    at Object.<anonymous> (/dist/node_modules/@google-cloud/pubsub/node_modules/google-gax/build/src/grpc.js:34:25)
    at Module._compile (internal/modules/cjs/loader.js:776:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:787:10)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Module.require (internal/modules/cjs/loader.js:690:17)
    at require (internal/modules/cjs/helpers.js:25:18)
    at Object.<anonymous> (/dist/node_modules/@google-cloud/pubsub/node_modules/google-gax/build/src/index.js:33:16)
    at Module._compile (internal/modules/cjs/loader.js:776:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:787:10)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Module.require (internal/modules/cjs/loader.js:690:17)
    at require (internal/modules/cjs/helpers.js:25:18)
    at Object.<anonymous> (/dist/node_modules/@google-cloud/pubsub/build/src/v1/publisher_client.js:18:13)
    at Module._compile (internal/modules/cjs/loader.js:776:30)
    at Object.Module._extensions..js (internal/modules/cjs/loader.js:787:10)
    at Module.load (internal/modules/cjs/loader.js:653:32)
    at tryModuleLoad (internal/modules/cjs/loader.js:593:12)
    at Function.Module._load (internal/modules/cjs/loader.js:585:3)
    at Module.require (internal/modules/cjs/loader.js:690:17)
    at require (internal/modules/cjs/helpers.js:25:18)

any ideas ?

My app also uses other google cloud dependencies

"dependencies": {
"@google-cloud/storage": "3.2.1",
"@google-cloud/trace-agent": "3.6.1",
"@google-cloud/pubsub": "0.32.1"
},

rvillane picture rvillane on 7 Oct 2019

I have published 0.6.6 with another possible fix for this problem. If anyone is willing to try it out and report the result that would be helpful.

murgatroid99 picture murgatroid99 on 8 Oct 2019
👍1

@rvillane We normally don't pin dependencies since it makes it much harder to release patches. I understand the frustration caused by these issues, we'll definitely go ahead and pin the version to some v0.5.x if the problem is not fixed soon enough.

[updated: it said "0.4.x" originally, 0.5.x should be fine though]

alexander-fenster picture alexander-fenster on 8 Oct 2019

As far as I know there are no outstanding issues with 0.5.x

murgatroid99 picture murgatroid99 on 8 Oct 2019

Similar Error using @google-cloud/[email protected] which also depends on @grpc/[email protected]

jankrynauw picture jankrynauw on 8 Oct 2019

We have seen those errors starting to occur around 1 hour after a fresh pod creation. After those started, all subsequent calls were starting to fail. Pintpointing lib to previous working version (0.5.2) resolved the issue. (using google Firestore)

Same here, with PubSub and Datastore

Vinceveve picture Vinceveve on 8 Oct 2019

I have published 0.6.6 with another possible fix for this problem. If anyone is willing to try it out and report the result that would be helpful.

@murgatroid99 0.6.6 fix the issue, we see lot of disconnect in the log (with GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG it's very verbose) but it always retry successfully

Sample :

2019-10-08T08:07:18.731Z | resolving_load_balancer | datastore.googleapis.com:443 IDLE -> IDLE
2019-10-08T08:07:18.732Z | connectivity_state | datastore.googleapis.com:443 IDLE -> IDLE
2019-10-08T08:07:18.732Z | dns_resolver | Resolver constructed for target datastore.googleapis.com:443
2019-10-08T08:07:18.738Z | dns_resolver | Resolution update requested for target datastore.googleapis.com:443
2019-10-08T08:07:18.739Z | resolving_load_balancer | datastore.googleapis.com:443 IDLE -> CONNECTING
2019-10-08T08:07:18.739Z | connectivity_state | datastore.googleapis.com:443 IDLE -> CONNECTING
2019-10-08T08:07:18.758Z | dns_resolver | Resolved addresses for target datastore.googleapis.com:443: 172.217.22.138:443
2019-10-08T08:07:18.759Z | pick_first | IDLE -> IDLE
2019-10-08T08:07:18.759Z | resolving_load_balancer | datastore.googleapis.com:443 CONNECTING -> IDLE
2019-10-08T08:07:18.759Z | connectivity_state | datastore.googleapis.com:443 CONNECTING -> IDLE
2019-10-08T08:07:18.760Z | pick_first | Connect to address list 172.217.22.138:443
2019-10-08T08:07:18.760Z | pick_first | Start connecting to subchannel with address 172.217.22.138:443
2019-10-08T08:07:18.760Z | pick_first | IDLE -> CONNECTING
2019-10-08T08:07:18.760Z | resolving_load_balancer | datastore.googleapis.com:443 IDLE -> CONNECTING
2019-10-08T08:07:18.761Z | connectivity_state | datastore.googleapis.com:443 IDLE -> CONNECTING
2019-10-08T08:07:18.761Z | subchannel | 172.217.22.138:443 IDLE -> CONNECTING
2019-10-08T08:07:18.763Z | pick_first | CONNECTING -> CONNECTING
2019-10-08T08:07:18.764Z | resolving_load_balancer | datastore.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-08T08:07:18.764Z | connectivity_state | datastore.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-08T08:07:18.799Z | subchannel | 172.217.22.138:443 CONNECTING -> READY
2019-10-08T08:07:18.799Z | pick_first | Pick subchannel with address 172.217.22.138:443
2019-10-08T08:07:18.799Z | pick_first | CONNECTING -> READY
2019-10-08T08:07:18.799Z | resolving_load_balancer | datastore.googleapis.com:443 CONNECTING -> READY
2019-10-08T08:07:18.807Z | connectivity_state | datastore.googleapis.com:443 CONNECTING -> READY
2019-10-08T08:19:36.100Z | subchannel | 172.217.22.138:443 READY -> IDLE
2019-10-08T08:19:36.100Z | pick_first | READY -> IDLE
2019-10-08T08:19:36.100Z | resolving_load_balancer | datastore.googleapis.com:443 READY -> IDLE
2019-10-08T08:19:36.100Z | connectivity_state | datastore.googleapis.com:443 READY -> IDLE
2019-10-08T08:19:39.899Z | subchannel | 172.217.22.138:443 IDLE -> TRANSIENT_FAILURE
Vinceveve picture Vinceveve on 8 Oct 2019

Same error use firebase admin work with firestore "No connection estabilished"

cecon picture cecon on 8 Oct 2019
👍3 
  "dependencies": {
    "firebase-admin": "^8.2.0",
    "@google-cloud/firestore": "2.2.1",
    "firebase-functions": "^3.0.0"
  },

Having the same problem here also https://github.com/rxdi/firestore

It is a regression of somekind since i locked my version a while ago to 2.2.1 and i am getting this error NOW not before when i create this module. So i think someone push really bad PATCH instead of bumping the whole version...

When i leave my workstation for a few hours and return back i am refreshing client side application which creates a request which takes really long time to finish like 1 minute then it throws error 

{ Error: No connection established
    at Http2CallStream.call.on (/home/rampage/Desktop/work/bolt/monorepo/node_modules/@grpc/grpc-js/build/src/call.js:68:41)
    at Http2CallStream.emit (events.js:203:15)
    at process.nextTick (/home/rampage/Desktop/work/bolt/monorepo/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22)
    at process._tickCallback (internal/process/next_tick.js:61:11)
  code: 14,
  details: 'No connection established',
  metadata: Metadata { internalRepr: Map {}, options: {} } }

After starting and restarting again the application everything work as expected.

What is the problematic library ? What version should we use ? Does anyone knows ?

I am happy that this week i switched to Lambdas so it is not a real issue there since they are starting the server everytime.

Stradivario picture Stradivario on 8 Oct 2019

Not sure if this is related but I'm using Cloud Vision on a Compute Instance with a Firebase Admin Project Config and seeing similar issues only very recently:

{ Error: Retry total timeout exceeded before any response was received
at repeat (/home/user/api/node_modules/google-gax/build/src/normalCalls/retries.js:80:31)
at Timeout.setTimeout [as _onTimeout] (/home/user/api/node_modules/google-gax/build/src/normalCalls/retries.js:113:25)
at ontimeout (timers.js:436:11)
at tryOnTimeout (timers.js:300:5)
at listOnTimeout (timers.js:263:5)
at Timer.processTimers (timers.js:223:10) code: 4 }

This issue only appears _after some time_, e.g. not reproducible after a script reload and is very difficult to debug.

delta9 picture delta9 on 8 Oct 2019

@delta9 It's likely related but could you please clarify if you see this on @grpc/grpc-js v0.6.6 or on an older version?

npm ls @grpc/grpc-js
alexander-fenster picture alexander-fenster on 8 Oct 2019

@alexander-fenster

└─┬ @google-cloud/[email protected]
└─┬ [email protected]
└── @grpc/[email protected]

I'll update to v0.6.6 with debug trace and get back to you, thanks!

delta9 picture delta9 on 8 Oct 2019

@alexander-fenster Tested v0.6.6 and still seeing the same errors. BTW I had to force :

"resolutions": {
    "@grpc/grpc-js": "0.6.6"
}

since google-gax is still forcing v0.6.4.

apatora picture apatora on 8 Oct 2019

@apatora

since google-gax is still forcing v0.6.4.

It actually depends on ^0.6.4 so it should pull 0.6.6 unless you have a package-lock.json in place. Anyway, we are going to update that dependency and set it to ^0.6.6.

It's sad to see that you still have problems with 0.6.6 :( Did you have a chance to try it with tracing environment variables set?

export GRPC_TRACE=all
export GRPC_VERBOSITY=DEBUG

If you could do that, please post your log here. Thank you so much for helping us debug it!

alexander-fenster picture alexander-fenster on 8 Oct 2019

@alexander-fenster seems to be fixed for our use case (Cloud Vision / Content Moderation) with v0.6.6 tested @ 1 hour of uptime. Thanks!

delta9 picture delta9 on 8 Oct 2019

@alexander-fenster I tried again and you are right, I don't need to force the version to 0.6.6, but I still have the connection errors :/

I checked the version of grpc-js in a running container that has the errors, just to be sure :

# cat node_modules/@google-cloud/bigtable/node_modules/@grpc/grpc-js/package.json | grep "version"
  "version": "0.6.6",

I activated the logs, here is what I get :

2019-10-08T20:51:03.230Z | subchannel | 172.217.212.95:443 READY -> IDLE
2019-10-08T20:51:03.230Z | pick_first | READY -> IDLE
2019-10-08T20:51:03.230Z | resolving_load_balancer | bigtable.googleapis.com:443 READY -> IDLE
2019-10-08T20:51:03.231Z | connectivity_state | bigtable.googleapis.com:443 READY -> IDLE
2019-10-08T20:51:03.240Z | dns_resolver | Resolution update requested for target bigtable.googleapis.com:443
2019-10-08T20:51:03.241Z | pick_first | Connect to address list 172.217.212.95:443
2019-10-08T20:51:03.241Z | pick_first | Start connecting to subchannel with address 172.217.212.95:443
2019-10-08T20:51:03.241Z | pick_first | IDLE -> CONNECTING
2019-10-08T20:51:03.241Z | resolving_load_balancer | bigtable.googleapis.com:443 IDLE -> CONNECTING
2019-10-08T20:51:03.241Z | connectivity_state | bigtable.googleapis.com:443 IDLE -> CONNECTING
2019-10-08T20:51:03.241Z | subchannel | 172.217.212.95:443 IDLE -> CONNECTING
2019-10-08T20:51:03.241Z | pick_first | CONNECTING -> CONNECTING
2019-10-08T20:51:03.241Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-08T20:51:03.241Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-08T20:51:03.246Z | subchannel | 172.217.212.95:443 CONNECTING -> READY
2019-10-08T20:51:03.246Z | pick_first | Pick subchannel with address 172.217.212.95:443
2019-10-08T20:51:03.246Z | pick_first | CONNECTING -> READY
2019-10-08T20:51:03.246Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-08T20:51:03.246Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-08T20:51:03.255Z | dns_resolver | Resolved addresses for target bigtable.googleapis.com:443: 74.125.69.95:443
2019-10-08T20:51:03.255Z | pick_first | Connect to address list 74.125.69.95:443
2019-10-08T20:51:03.255Z | pick_first | Start connecting to subchannel with address 74.125.69.95:443
2019-10-08T20:51:03.255Z | pick_first | READY -> CONNECTING
2019-10-08T20:51:03.255Z | resolving_load_balancer | bigtable.googleapis.com:443 READY -> CONNECTING
2019-10-08T20:51:03.255Z | connectivity_state | bigtable.googleapis.com:443 READY -> CONNECTING
2019-10-08T20:51:03.256Z | subchannel | 74.125.69.95:443 IDLE -> CONNECTING
2019-10-08T20:51:03.260Z | subchannel | 74.125.69.95:443 CONNECTING -> READY
2019-10-08T20:51:03.260Z | pick_first | Pick subchannel with address 74.125.69.95:443
2019-10-08T20:51:03.260Z | pick_first | CONNECTING -> READY
2019-10-08T20:51:03.260Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-08T20:51:03.260Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-08T20:51:09.799Z | subchannel | 172.217.212.95:443 READY -> TRANSIENT_FAILURE

Thanks for working on a fix :)

apatora picture apatora on 8 Oct 2019

@apatora Is that the full log output?

murgatroid99 picture murgatroid99 on 9 Oct 2019

I have published grpc-js version 0.6.7 that should hopefully resolve this issue for the people who are still experiencing it. If you can update to it please try it out.

murgatroid99 picture murgatroid99 on 9 Oct 2019
👀1 ❤1

Hi @murgatroid99,
but it seems like the bug still exist
here is my bug log, and package.json

{ Error: No connection established
    at Http2CallStream.call.on (/srv/node_modules/@grpc/grpc-js/build/src/call.js:68:41)
    at emitOne (events.js:121:20)
    at Http2CallStream.emit (events.js:211:7)
    at process.nextTick (/srv/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22)
    at _combinedTickCallback (internal/process/next_tick.js:132:7)
    at process._tickDomainCallback (internal/process/next_tick.js:219:9)
  code: 14,
  details: 'No connection established',
  metadata: Metadata { internalRepr: Map {}, options: {} } }"  
 timestamp: "2019-10-09T02:42:21.582Z"  
 trace: "projects/myProject/traces/9645f5ec292d9cac6bff8430cc0437cd"  
}
  • package.json
functions@ /Users/myProject/functions
β”œβ”€β”¬ @google-cloud/[email protected]
β”‚ └─┬ [email protected]
β”‚   └── @grpc/[email protected]
└─┬ @google-cloud/[email protected]
  └─┬ @google-cloud/[email protected]
    └── @grpc/[email protected]
mis101247 picture mis101247 on 9 Oct 2019

After I update @google-cloud/firestore ,
It seems to be resolved

,observing
Thanks for working on a fix .

functions@ /Users/aiii-keyo/Projects/aiii-bot-platform/functions
β”œβ”€β”¬ @google-cloud/[email protected]
β”‚ └─┬ [email protected]
β”‚   └── @grpc/[email protected]
└─┬ @google-cloud/[email protected]
  └─┬ @google-cloud/[email protected]
    └── @grpc/[email protected]
mis101247 picture mis101247 on 9 Oct 2019

I have published grpc-js version 0.6.7 that should hopefully resolve this issue for the people who are still experiencing it. If you can update to it please try it out.

@murgatroid99 Bug is back on 0.6.7 (datastore and pubsub)

Vinceveve picture Vinceveve on 9 Oct 2019

If you are still experiencing this bug on 0.6.7 can you please share the log output from running with the environment variables GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG?

murgatroid99 picture murgatroid99 on 9 Oct 2019

google-gax now forces grpc-js version 0.6.6 which makes it hard to test the new versions. I had to force : 

"resolutions": {
    "@grpc/grpc-js": "0.6.7",
    "google-gax": "1.6.4"
}

Anyway I'm currently testing 0.6.7 and will tell you in several hours if it works for me !

apatora picture apatora on 9 Oct 2019

@apatora Yeah, we decided we'll pin the gRPC version in gax. The gax release with 0.6.7 is coming.

alexander-fenster picture alexander-fenster on 9 Oct 2019

Hi, on production with 0.6.7 I had same issue. But localy with it version sems to work correctly.

witem picture witem on 9 Oct 2019

I have been running 0.6.7 in production for a day now and it seems that the number of errors has decreased dramatically. However after several hours, I managed to get those errors back randomly. I am running this on hundreds of containers and sometimes on one of them I get the No connection established errors like before.

Here are the logs I could gather from those containers : 

2019-10-10T14:11:05.226Z | subchannel | 209.85.145.95:443 READY -> IDLE
2019-10-10T14:11:05.226Z | pick_first | READY -> IDLE
2019-10-10T14:11:05.226Z | resolving_load_balancer | bigtable.googleapis.com:443 READY -> IDLE
2019-10-10T14:11:05.226Z | connectivity_state | bigtable.googleapis.com:443 READY -> IDLE
2019-10-10T14:11:05.314Z | dns_resolver | Resolution update requested for target bigtable.googleapis.com:443
2019-10-10T14:11:05.314Z | pick_first | Connect to address list 209.85.145.95:443
2019-10-10T14:11:05.315Z | pick_first | Start connecting to subchannel with address 209.85.145.95:443
2019-10-10T14:11:05.315Z | pick_first | IDLE -> CONNECTING
2019-10-10T14:11:05.315Z | resolving_load_balancer | bigtable.googleapis.com:443 IDLE -> CONNECTING
2019-10-10T14:11:05.315Z | connectivity_state | bigtable.googleapis.com:443 IDLE -> CONNECTING
2019-10-10T14:11:05.315Z | subchannel | 209.85.145.95:443 IDLE -> CONNECTING
2019-10-10T14:11:05.316Z | pick_first | CONNECTING -> CONNECTING
2019-10-10T14:11:05.316Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-10T14:11:05.316Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-10T14:11:05.321Z | subchannel | 209.85.145.95:443 CONNECTING -> READY
2019-10-10T14:11:05.321Z | pick_first | Pick subchannel with address 209.85.145.95:443
2019-10-10T14:11:05.321Z | pick_first | CONNECTING -> READY
2019-10-10T14:11:05.321Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-10T14:11:05.321Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-10T14:11:05.331Z | dns_resolver | Resolved addresses for target bigtable.googleapis.com:443: 108.177.112.95:443
2019-10-10T14:11:05.331Z | pick_first | Connect to address list 108.177.112.95:443
2019-10-10T14:11:05.332Z | pick_first | Start connecting to subchannel with address 108.177.112.95:443
2019-10-10T14:11:05.332Z | subchannel | 108.177.112.95:443 IDLE -> CONNECTING
2019-10-10T14:11:05.343Z | subchannel | 108.177.112.95:443 CONNECTING -> READY
2019-10-10T14:11:05.343Z | pick_first | Pick subchannel with address 108.177.112.95:443
2019-10-10T14:11:05.343Z | pick_first | READY -> READY
2019-10-10T14:11:05.343Z | resolving_load_balancer | bigtable.googleapis.com:443 READY -> READY
2019-10-10T14:11:05.343Z | connectivity_state | bigtable.googleapis.com:443 READY -> READY
2019-10-10T14:11:12.333Z | subchannel | 209.85.145.95:443 READY -> TRANSIENT_FAILURE
apatora picture apatora on 10 Oct 2019

That log information looks like normal operation. Would it be possible to get logs from the containers that had those errors from around the time those errors occurred?

murgatroid99 picture murgatroid99 on 10 Oct 2019

When I go back to the first error of a container :

2019-10-10T15:11:05.387Z | subchannel | 108.177.112.95:443 READY -> IDLE
2019-10-10T15:11:05.387Z | pick_first | READY -> IDLE
2019-10-10T15:11:05.387Z | resolving_load_balancer | bigtable.googleapis.com:443 READY -> IDLE
2019-10-10T15:11:05.387Z | connectivity_state | bigtable.googleapis.com:443 READY -> IDLE
2019-10-10T15:11:05.390Z | dns_resolver | Resolution update requested for target bigtable.googleapis.com:443
2019-10-10T15:11:05.390Z | pick_first | Connect to address list 108.177.112.95:443
2019-10-10T15:11:05.390Z | pick_first | Start connecting to subchannel with address 108.177.112.95:443
2019-10-10T15:11:05.390Z | pick_first | IDLE -> CONNECTING
2019-10-10T15:11:05.390Z | resolving_load_balancer | bigtable.googleapis.com:443 IDLE -> CONNECTING
2019-10-10T15:11:05.390Z | connectivity_state | bigtable.googleapis.com:443 IDLE -> CONNECTING
2019-10-10T15:11:05.390Z | subchannel | 108.177.112.95:443 IDLE -> CONNECTING
2019-10-10T15:11:05.391Z | pick_first | CONNECTING -> CONNECTING
2019-10-10T15:11:05.391Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-10T15:11:05.391Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> CONNECTING
2019-10-10T15:11:05.395Z | subchannel | 108.177.112.95:443 CONNECTING -> READY
2019-10-10T15:11:05.395Z | pick_first | Pick subchannel with address 108.177.112.95:443
2019-10-10T15:11:05.395Z | pick_first | CONNECTING -> READY
2019-10-10T15:11:05.395Z | resolving_load_balancer | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-10T15:11:05.395Z | connectivity_state | bigtable.googleapis.com:443 CONNECTING -> READY
2019-10-10T15:11:05.397Z | subchannel | 108.177.112.95:443 READY -> TRANSIENT_FAILURE
2019-10-10T15:11:05.397Z | pick_first | READY -> IDLE
2019-10-10T15:11:05.397Z | resolving_load_balancer | bigtable.googleapis.com:443 READY -> IDLE
2019-10-10T15:11:05.397Z | connectivity_state | bigtable.googleapis.com:443 READY -> IDLE
2019-10-10T15:11:05.401Z | dns_resolver | Resolved addresses for target bigtable.googleapis.com:443: 108.177.112.95:443
2019-10-10T15:11:05.401Z | pick_first | Connect to address list 108.177.112.95:443
2019-10-10T15:11:05.401Z | pick_first | IDLE -> TRANSIENT_FAILURE
2019-10-10T15:11:05.401Z | resolving_load_balancer | bigtable.googleapis.com:443 IDLE -> TRANSIENT_FAILURE
2019-10-10T15:11:05.401Z | connectivity_state | bigtable.googleapis.com:443 IDLE -> TRANSIENT_FAILURE
unhandledRejection { Error: No connection established
    at Http2CallStream.call.on (/usr/src/node_modules/@google-cloud/bigtable/node_modules/@grpc/grpc-js/build/src/call.js:68:41)
    at Http2CallStream.emit (events.js:203:15)
    at Http2CallStream.EventEmitter.emit (domain.js:448:20)
    at process.nextTick (/usr/src/node_modules/@google-cloud/bigtable/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22)
    at process._tickCallback (internal/process/next_tick.js:61:11)
  code: 14,
  details: 'No connection established',
  metadata: Metadata { internalRepr: Map {}, options: {} } }
apatora picture apatora on 10 Oct 2019

That looks like an error that could always happen, bug or not. A connection got dropped or otherwise broke, and then when the channel tried to use it immediately after that, you got an error. This is why we recommend retrying when getting UNAVAILABLE errors.

This bug is about a channel staying in that broken state for an unreasonable amount of time.

EDIT: That log may actually indicate a slightly different bug than I was expecting. Stay tuned for a possible fix.

murgatroid99 picture murgatroid99 on 10 Oct 2019

I use node-pubsub, npm ls @grpc/grpc-js:

└─┬ @google-cloud/[email protected]
  β”œβ”€β”€ @grpc/[email protected] 
  └─┬ [email protected]
    └── @grpc/[email protected]  deduped

After server restart all works fine, but after some time when I call publish nothing not sends.
Latests debug info in logs:

Oct 10 07:05:03.554pm info app web.1 | subchannel | 172.217.13.74:443 READY -> IDLE
Oct 10 07:05:03.555pm info app web.1 | dns_resolver | Resolution update requested for target pubsub.googleapis.com:443
Oct 10 07:05:03.555pm info app web.1 | connectivity_state | pubsub.googleapis.com:443 READY -> CONNECTING
Oct 10 07:05:03.555pm info app web.1 | resolving_load_balancer | pubsub.googleapis.com:443 READY -> CONNECTING
Oct 10 07:05:03.555pm info app web.1 | pick_first | READY -> CONNECTING
Oct 10 07:05:03.555pm info app web.1 | pick_first | Start connecting to subchannel with address 172.217.13.74:443
Oct 10 07:05:03.555pm info app web.1 | pick_first | Connect to address list 172.217.13.74:443
Oct 10 07:05:03.557pm info app web.1 | subchannel | 172.217.13.74:443 IDLE -> CONNECTING
Oct 10 07:05:03.558pm info app web.1 | subchannel | 172.217.13.74:443 CONNECTING -> TRANSIENT_FAILURE
Oct 10 07:05:03.571pm info app web.1 | dns_resolver | Resolved addresses for target pubsub.googleapis.com:443: 172.217.13.74:443
Oct 10 07:05:03.572pm info app web.1 | connectivity_state | pubsub.googleapis.com:443 CONNECTING -> TRANSIENT_FAILURE
Oct 10 07:05:03.572pm info app web.1 | resolving_load_balancer | pubsub.googleapis.com:443 CONNECTING -> TRANSIENT_FAILURE
Oct 10 07:05:03.572pm info app web.1 | pick_first | CONNECTING -> TRANSIENT_FAILURE
Oct 10 07:05:03.572pm info app web.1 | pick_first | Connect to address list 172.217.13.74:443
Oct 10 07:05:04.558pm info app web.1 | subchannel | 172.217.13.74:443 TRANSIENT_FAILURE -> IDLE

And:

Oct 10 07:47:29.334pm info app web.1 10/10/2019, 7:47:29 PM - error: Error on add file to encoding queue: message=Retry total timeout exceeded before any response was received, stack=Error: Retry total timeout exceeded before any response was received
Oct 10 07:47:29.334pm info app web.1 at repeat (/app/node_modules/google-gax/build/src/normalCalls/retries.js:80:31)
Oct 10 07:47:29.334pm info app web.1 at Timeout.setTimeout [as _onTimeout] (/app/node_modules/google-gax/build/src/normalCalls/retries.js:113:25)
Oct 10 07:47:29.334pm info app web.1 at ontimeout (timers.js:436:11)
Oct 10 07:47:29.334pm info app web.1 at tryOnTimeout (timers.js:300:5)
Oct 10 07:47:29.334pm info app web.1 at listOnTimeout (timers.js:263:5)
Oct 10 07:47:29.334pm info app web.1 at Timer.processTimers (timers.js:223:10), code=4

And after some times(messagees still not sends to pubsub):

Oct 10 07:56:40.051pm info app web.1 | resolving_load_balancer | pubsub.googleapis.com:443 READY -> CONNECTING
Oct 10 07:56:40.051pm info app web.1 | pick_first | READY -> CONNECTING
Oct 10 07:56:40.051pm info app web.1 | pick_first | Start connecting to subchannel with address 172.217.13.74:443
Oct 10 07:56:40.051pm info app web.1 | pick_first | Connect to address list 172.217.13.74:443
Oct 10 07:56:40.051pm info app web.1 | subchannel | 172.217.13.74:443 READY -> IDLE
Oct 10 07:56:40.052pm info app web.1 | subchannel | 172.217.13.74:443 IDLE -> CONNECTING
Oct 10 07:56:40.052pm info app web.1 | dns_resolver | Resolution update requested for target pubsub.googleapis.com:443
Oct 10 07:56:40.052pm info app web.1 | connectivity_state | pubsub.googleapis.com:443 READY -> CONNECTING
Oct 10 07:56:40.054pm info app web.1 | subchannel | 172.217.13.74:443 CONNECTING -> TRANSIENT_FAILURE
Oct 10 07:56:40.062pm info app web.1 | resolving_load_balancer | pubsub.googleapis.com:443 CONNECTING -> CONNECTING
Oct 10 07:56:40.062pm info app web.1 | pick_first | CONNECTING -> CONNECTING
Oct 10 07:56:40.062pm info app web.1 | pick_first | Start connecting to subchannel with address 172.217.7.170:443
Oct 10 07:56:40.062pm info app web.1 | pick_first | Connect to address list 172.217.7.170:443
Oct 10 07:56:40.062pm info app web.1 | dns_resolver | Resolved addresses for target pubsub.googleapis.com:443: 172.217.7.170:443
Oct 10 07:56:40.063pm info app web.1 | subchannel | 172.217.7.170:443 IDLE -> CONNECTING
Oct 10 07:56:40.063pm info app web.1 | connectivity_state | pubsub.googleapis.com:443 CONNECTING -> CONNECTING
Oct 10 07:56:40.079pm info app web.1 | subchannel | 172.217.7.170:443 CONNECTING -> READY
Oct 10 07:56:40.080pm info app web.1 | connectivity_state | pubsub.googleapis.com:443 CONNECTING -> READY
Oct 10 07:56:40.080pm info app web.1 | resolving_load_balancer | pubsub.googleapis.com:443 CONNECTING -> READY
Oct 10 07:56:40.080pm info app web.1 | pick_first | CONNECTING -> READY
Oct 10 07:56:40.080pm info app web.1 | pick_first | Pick subchannel with address 172.217.7.170:443
Oct 10 07:56:41.052pm info app web.1 | subchannel | 172.217.13.74:443 TRANSIENT_FAILURE -> IDLE
witem picture witem on 10 Oct 2019
👍1

I have published grpc-js version 0.6.8 that contains more potential fixes for these errors.

murgatroid99 picture murgatroid99 on 11 Oct 2019
👍2

@murgatroid99 the most strange thing ever happen to me is that i was waiting for some kind of resolution for the problem so i decided not to update my packages until then.
But:

  1. From yesterday my development server is up and running more than 17 hours i left my home
  2. I return today and my server is up and running without this bug. Even it is faster like response time from Google api's
  3. I repeat no NPM, YARN, BOLT install has being made so i was thinking that the problem is maybe internal inside Google Cloud infrastructure ?!?
  4. What the actual 'cat' ?
Stradivario picture Stradivario on 11 Oct 2019

@murgatroid99 still testing 0.6.8 on my side. Haven't encountered any error yet but I will leave it in production for a day to be sure. Is it possible not to pin @grpc/[email protected] in @google-cloud/common-grpc ? It makes me push the 0.6.7 version by mistake. Thanks guys.

apatora picture apatora on 11 Oct 2019
👍1

Big thumbs up for not pinning it. I hate manually editing the package lock. If it's not pinned, one can simply add a version he wants as a direct dependency and dedupe. Much easier and no manual changes to the lock file πŸ‘

merlinnot picture merlinnot on 11 Oct 2019

Not sure if this is the same issue for Google Cloud Task Queues. I have a loop that create tasks for about 78 stores, I get this error Error: Deadline exceeded at Http2CallStream.<anonymous> for about 47 of the stores while 31 to of them get added to the queue; it varies slightly each time I purge the queue and reattempt.

I updated the google-sdk and the node client package @google-cloud/tasks both to the latest.

Currently I working locally, this will later get deployed as a google function.

I am not sure how to set the logs or debug for the google-cli.

Your thoughts are appreciated.
Steve

foozlereducer picture foozlereducer on 11 Oct 2019

In case it helps, this issue seems to be deeply related to https://github.com/googleapis/nodejs-pubsub/issues/770 and there are a couple of workarounds proposed that can be helpful:

https://github.com/googleapis/nodejs-pubsub/issues/770#issuecomment-541226361

rvillane picture rvillane on 12 Oct 2019

@rvillane thank you so much!

  1. I installed grpc like:
    npm i grpc --save > [email protected]
  2. in the code I bound it to the task client const client = new v2beta3.CloudTasksClient({grpc});

After doing so, it parses all the stores with no errors.

I really appreciate your help :)

Steve

foozlereducer picture foozlereducer on 12 Oct 2019

@murgatroid99 [email protected]` seems to have resolved all the issues on my side !

apatora picture apatora on 12 Oct 2019

In case it helps, this issue seems to be deeply related to googleapis/nodejs-pubsub#770 and there are a couple of workarounds proposed that can be helpful:

googleapis/nodejs-pubsub#770 (comment)

After a complete day running the workaround to use the C++ binding instead of native gRPC javascript implementation, the issues publishing messages to PubSub topics have stopped.

rvillane picture rvillane on 13 Oct 2019

I have now published grpc-js version 0.6.9 with some changes that appear to further improve this situation in certain cases.

murgatroid99 picture murgatroid99 on 14 Oct 2019
👍3

FYI this is also an issue with Firebase Scheduled Functions that are leveraging the gcp pub/sub service without giving you the option to configure the package version being used @murgatroid99

Error: No connection established at Http2CallStream.call.on (/srv/node_modules/@grpc/grpc-js/build/src/call.js:68:41) at emitOne (events.js:121:20) at Http2CallStream.emit (events.js:211:7) at process.nextTick (/srv/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22) at _combinedTickCallback (internal/process/next_tick.js:132:7) at process._tickDomainCallback (internal/process/next_tick.js:219:9)

mrmodelo picture mrmodelo on 18 Oct 2019

I have the bug for cloud vision, it only occurs when requesting multiple predictions at the same time in a large period of time(> 2 minutes)

Error: No connection established
at Http2CallStream. (/myspace/node_modules/@grpc/grpc-js/build/src/client.js:96:45)
at Http2CallStream.emit (events.js:215:7)
at /myspace/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22
at processTicksAndRejections (internal/process/task_queues.js:75:11) {
code: 14,
'No connection established',
Metadata { internalRepr: Map {}, options: {} }
2019-10-18 01:27:37.727 EDT

johnbalvin picture johnbalvin on 18 Oct 2019

@johnbalvin @mrmodelo would you be able to provide your dependency graph, so that we can confirm that you're on @grpc/[email protected], you can do so by running npm ls, in a project identical to the cold start of your project.

Assuming you are on @grpc/[email protected] for all dependencies, would you be able to run your workload with the following environment variables set:

GRPC_TRACE = 'all';
GRPC_VERBOSITY = 'DEBUG';

One easy way to do this is to set them before importing any gRPC dependencies:

process.env.GRPC_TRACE = 'all';
process.env.GRPC_VERBOSITY = 'DEBUG';
const {Clieint} = require('@google-cloud/pubsub');

If you could then share the logs with me, at the time of a failure occurring, my email is on GitHub (bencoe [at] google.com).

If you're working through customer support, you can also ask them to reach out to me; my goal is to get more detailed debugging information, if there is still an issue happening on newer @grpc/grpc-js releases.

bcoe picture bcoe on 18 Oct 2019

I had a rogue reference in my package-lock.json

After nuking that and starting from a clean slate I was able to get the correct grpc-js version. For those interested it was under google-gax as a required dependency

@grpc/grpc-js": "0.6.9"

I have since had three scheduled calls go off with no failures. Fingers crossed this is the one, thanks for the timely responses from all and the community support!

mrmodelo picture mrmodelo on 18 Oct 2019
🚀1 👍1

Still having this issue in November '19. It's hit and miss if the function fires which is application breaking for me and more or less makes my project unusable. The function needs to fire every time.

Failing to execute on functions.firestore.document('channels/{channel}/messages/{message}').onCreate

@grpc/grpc-js is 0.6.9

iShaymus picture iShaymus on 19 Nov 2019

@iShaymus Can you check npm ls and/or your package-lock.json to confirm that 0.6.9 is the only version of @grpc/grpc-js you have installed, or at least that it is the version that firestore is using?

In addition, can you share the stack trace of the error you are seeing from your error logs? Yours is the first report of this error on 0.6.9 so I need to know what the error looks like in that version.

murgatroid99 picture murgatroid99 on 19 Nov 2019

I'm also plagued at random intervals by this error when trying to do a simple Firestore get operation using firebase-admin (v 8.6.0) in a Firebase Cloud Function. I know I need to update to firebase admin 8.7.0, but still I'm going to create a workaround as this bug is breaking my checkout flow and crippling my site.

jwrunner picture jwrunner on 19 Nov 2019

Again, it would be helpful to see the confirmation of which version(s) of the library you have, as well as the stack trace of the errors you are getting.

In addition to that, as mentioned previously in this issue it would be helpful to see the output of running your code with the environment variables GRPC_TRACE=all and GRPC_VERBOSITY=DEBUG, particularly the log lines around when the error occurs.

murgatroid99 picture murgatroid99 on 19 Nov 2019

@murgatroid99 I will try. It becomes difficult since it is completely random if and when it happens.

iShaymus picture iShaymus on 19 Nov 2019

While I try and get a stack trace. Here is the error from the functions log

Error: No connection established at Http2CallStream.call.on (/srv/node_modules/@grpc/grpc-js/build/src/call.js:68:41) at emitOne (events.js:121:20) at Http2CallStream.emit (events.js:211:7) at process.nextTick (/srv/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22) at _combinedTickCallback (internal/process/next_tick.js:132:7) at process._tickDomainCallback (internal/process/next_tick.js:219:9)

iShaymus picture iShaymus on 19 Nov 2019 
"google-gax": {
      "version": "1.9.0",
      "resolved": "https://registry.npmjs.org/google-gax/-/google-gax-1.9.0.tgz",
      "integrity": "sha512-15hBX53yafuCCOXCVdahNuDpza0YNiNgrWY0iohav+ZuAcmSPb8WNcCufgNmYUTLJxyFxpEFSm/OKWm8MQxkEQ==",
      "optional": true,
      "requires": {
        "@grpc/grpc-js": "0.6.9",
        "@grpc/proto-loader": "^0.5.1",
        "@types/long": "^4.0.0",
        "abort-controller": "^3.0.0",
        "duplexify": "^3.6.0",
        "google-auth-library": "^5.0.0",
        "is-stream-ended": "^0.1.4",
        "lodash.at": "^4.6.0",
        "lodash.has": "^4.5.2",
        "node-fetch": "^2.6.0",
        "protobufjs": "^6.8.8",
        "retry-request": "^4.0.0",
        "semver": "^6.0.0",
        "walkdir": "^0.4.0"
      },
iShaymus picture iShaymus on 19 Nov 2019 
"@grpc/grpc-js": {
      "version": "0.6.9",
      "resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-0.6.9.tgz",
      "integrity": "sha512-r1nDOEEiYmAsVYBaS4DPPqdwPOXPw7YhVOnnpPdWhlNtKbYzPash6DqWTTza9gBiYMA5d2Wiq6HzrPqsRaP4yA==",
      "optional": true,
      "requires": {
        "semver": "^6.2.0"
      }
iShaymus picture iShaymus on 19 Nov 2019

npm ls returns 0.6.9 as the only version . How do I add the environment variables you specified with my functions hosted on firebase itself

iShaymus picture iShaymus on 19 Nov 2019

At the very beginning of your script, before imports, you can write process.env.GRPC_TRACE='all' and process.env.GRPC_VERBOSITY='DEBUG'.

murgatroid99 picture murgatroid99 on 19 Nov 2019

I am facing this issue and I am using Firebase admin
{ Error: No connection established
at Http2CallStream.call.on (/Users/XXXXXX/node_modules/@grpc/grpc-js/build/src/call.js:68:41)
at Http2CallStream.emit (events.js:194:15)
at process.nextTick (/Users/XXXXX/Work/XXXXX/node_modules/@grpc/grpc-js/build/src/call-stream.js:75:22)
at process._tickCallback (internal/process/next_tick.js:61:11)
code: 14,
details: 'No connection established',

kaushaldeck picture kaushaldeck on 20 Nov 2019

As mentioned above I am using Firebase and am getting the connection failure error. I added the proc.env settings and here is the log

2019-11-20T16:48:52.351Z | subchannel | 172.217.163.170:443 READY -> IDLE
2019-11-20T16:48:52.352Z | pick_first | Connect to address list 172.217.163.170:443
2019-11-20T16:48:52.353Z | pick_first | Start connecting to subchannel with address 172.217.163.170:443
2019-11-20T16:48:52.353Z | pick_first | READY -> CONNECTING
2019-11-20T16:48:52.353Z | resolving_load_balancer | firestore.googleapis.com:443 READY -> CONNECTING
2019-11-20T16:48:52.353Z | connectivity_state | firestore.googleapis.com:443 READY -> CONNECTING
2019-11-20T16:48:52.353Z | dns_resolver | Resolution update requested for target firestore.googleapis.com:443
2019-11-20T16:48:52.355Z | subchannel | 172.217.163.170:443 IDLE -> CONNECTING
2019-11-20T16:48:52.356Z | subchannel | 172.217.163.170:443 CONNECTING -> TRANSIENT_FAILURE
2019-11-20T16:48:52.403Z | dns_resolver | Resolved addresses for target firestore.googleapis.com:443: 172.217.163.170:443
2019-11-20T16:48:52.403Z | pick_first | Connect to address list 172.217.163.170:443
2019-11-20T16:48:52.403Z | pick_first | CONNECTING -> TRANSIENT_FAILURE
2019-11-20T16:48:52.403Z | resolving_load_balancer | firestore.googleapis.com:443 CONNECTING -> TRANSIENT_FAILURE
2019-11-20T16:48:52.403Z | connectivity_state | firestore.googleapis.com:443 CONNECTING -> TRANSIENT_FAILURE
2019-11-20T16:48:53.362Z | subchannel | 172.217.163.170:443 TRANSIENT_FAILURE -> IDLE

kaushaldeck picture kaushaldeck on 20 Nov 2019

@kaushaldeck Can you also confirm what version of @grpc/grpc-js you are using?

murgatroid99 picture murgatroid99 on 20 Nov 2019

Hope this helps

npm ls @grpc/grpc-js
[email protected] /Users/kaushalc/XXXX
└─┬ [email protected]
  └─┬ @google-cloud/[email protected]
    └─┬ [email protected]
      └── @grpc/[email protected]
kaushaldeck picture kaushaldeck on 21 Nov 2019

Yes. That trace log shows a bug that was fixed in @grpc/grpc-js version 0.6.7. I suggest upgrading your dependencies so that you have at least version 0.6.9, and if you can't, I suggest filing an issue against firebase-admin.

murgatroid99 picture murgatroid99 on 21 Nov 2019

I had this problem for few months. My issue is, the port 8080 is closed on my Mac. I opened the port and everything worked perfectly.

ravi8x picture ravi8x on 22 Dec 2019

I'm experiencing sustained CPU spikes to 100% after an hour since a pod is started. I've created a debug pod which doesn't handle any traffic and it still manifests the same way. After profiling the CPU I've found that calls to startCallStream consistently fail which causes the whole tryPick function to be called again basically blocking the node process:

Screenshot 2020-02-25 at 14 50 06

Is it intended for this code: https://github.com/grpc/grpc-node/pull/1251/files#diff-a96b991cf71efa63f54e0313d45cf39cR234-R257 to create a loop like the one I described?

I'm currently using these versions of google libraries:

    "@google-cloud/connect-datastore": "^4.0.0",
    "@google-cloud/datastore": "^5.0.6",
    "@google-cloud/firestore": "^3.5.1",
    "@google-cloud/pubsub": "^1.5.0",

The libraries are using "@grpc/[email protected]", "@grpc/grpc-js@^0.6.12"
I will update this post with logs from GRPC_TRACK in an hour or so.

alexandrugheorghe picture alexandrugheorghe on 25 Feb 2020

@alexandrugheorghe That looks like the same bug as reported in googleapis/nodejs-pubsub#890, and that user says that the problem was fixed in @grpc/grpc-js version 0.6.18.

murgatroid99 picture murgatroid99 on 25 Feb 2020

@murgatroid99 I'll update now and check it again in an hour.

alexandrugheorghe picture alexandrugheorghe on 25 Feb 2020

@murgatroid99 Sorry for the late reply. Pods have been stable, version 0.6.18 has fixed my issues.
Thanks again for the quick reply and the fix.

alexandrugheorghe picture alexandrugheorghe on 26 Feb 2020
👍1

I'm hoping this issue hasn't resurfaced, but I did encounter the same error in a project that had been idle for some time. I recycled the pod so I should have an idea of the timeout being the cause in the future, but it impacted all our instances in a test environment.

The error:

err:
    message: '14 UNAVAILABLE: No connection established'
    name: Error
    stack: >
        Error: 14 UNAVAILABLE: No connection established
            at Object.callErrorFromStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/call.ts:81:24)
            at Object.onReceiveStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/client.ts:334:36)
            at Object.onReceiveStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/client-interceptors.ts:434:34)
            at Object.onReceiveStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/client-interceptors.ts:397:48)
            at Http2CallStream.outputStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/call-stream.ts:230:22)
            at Http2CallStream.maybeOutputStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/call-stream.ts:280:14)
            at Http2CallStream.endCall (/app/packages/animus/node_modules/@grpc/grpc-js/src/call-stream.ts:263:12)
            at Http2CallStream.cancelWithStatus (/app/packages/animus/node_modules/@grpc/grpc-js/src/call-stream.ts:597:10)
            at ChannelImplementation.tryPick (/app/packages/animus/node_modules/@grpc/grpc-js/src/channel.ts:387:22)
            at ChannelImplementation._startCallStream (/app/packages/animus/node_modules/@grpc/grpc-js/src/channel.ts:433:10)
            at Http2CallStream.start (/app/packages/animus/node_modules/@grpc/grpc-js/src/call-stream.ts:573:18)
            at BaseUnaryInterceptingCall.start (/app/packages/animus/node_modules/@grpc/grpc-js/src/client-interceptors.ts:374:15)
            at BaseUnaryInterceptingCall.start (/app/packages/animus/node_modules/@grpc/grpc-js/src/client-interceptors.ts:437:11)
            at ServiceClientImpl.makeUnaryRequest (/app/packages/animus/node_modules/@grpc/grpc-js/src/client.ts:315:10)
            at ServiceClientImpl.<anonymous> (/app/packages/animus/node_modules/@grpc/grpc-js/src/make-client.ts:174:15)
            at args (/app/packages/animus/node_modules/dialogflow/src/v2beta1/sessions_client.js:175:35)
            at /app/packages/animus/node_modules/google-gax/src/normalCalls/timeout.ts:54:13
            at OngoingCallPromise.call (/app/packages/animus/node_modules/google-gax/src/call.ts:82:23)
            at NormalApiCaller.call (/app/packages/animus/node_modules/google-gax/src/normalCalls/normalApiCaller.ts:46:15)
            at funcPromise.then.then (/app/packages/animus/node_modules/google-gax/src/createApiCall.ts:103:26)
            at Object.dynatraceOnServiceExecutionIndicator [as doInvoke] (/opt/dynatrace/oneagent/agent/bin/1.195.54.20200529-113801/any/nodejs/nodejsagent.js:1803:20)
            at Object.a.safeInvoke (/opt/dynatrace/oneagent/agent/bin/1.195.54.20200529-113801/any/nodejs/nodejsagent.js:1854:29)
            at /opt/dynatrace/oneagent/agent/bin/1.195.54.20200529-113801/any/nodejs/nodejsagent.js:7079:25
            at process._tickCallback (internal/process/next_tick.js:68:7)"
    code: 14

We install dependencies from the package-lock.json, which has @grpc/grpc-js locked in at 1.0.4.

{
  // deps...
  "@grpc/grpc-js": {
    "version": "1.0.4",
    "resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.0.4.tgz",
    "integrity": "sha512-Qawt6HUrEmljQMPWnLnIXpcjelmtIAydi3M9awiG02WWJ1CmIvFEx4IOC1EsWUWUlabOGksRbpfvoIeZKFTNXw==",
    "requires": {
      "google-auth-library": "^6.0.0",
      "semver": "^6.2.0"
    },
    "dependencies": { /** deps... */ }
  }
}

Will have another issue opened if this has resurfaced. I'll be back with more if it's an issue we come across again.

tcarrio picture tcarrio on 5 Jun 2020
👍5

Hello everyone, I've been trying to create a secret in the GCP from running the GCP APIs from AWS lambda. I tried setting the environment variable at the run time like process.env.GOOGLE_APPLICATION_CREDENTIALS = '/tmp/serviceAccountCreds.json'; . The GCP API for secret manager was running fine till DEC 29th on my environment. But from then on the API is throwing below error 

Error: 14 UNAVAILABLE: No connection established
    at Object.callErrorFromStatus (/home/akhil/onboard/node_modules/@grpc/grpc-js/src/call.ts:81:24)
    at Object.onReceiveStatus /home/akhil/onboard/node_modules/@grpc/grpc-js/src/client.ts:334:36)
    at Object.onReceiveStatus /home/akhil/onboard/node_modules/@grpc/grpc-js/src/client-interceptors.ts:434:34)
    at Object.onReceiveStatus (/home/akhil/onboard/node_modules/@grpc/grpc-js/src/client-interceptors.ts:397:48)
    at /home/akhil/onboard/node_modules/@grpc/grpc-js/src/call-stream.ts:237:24
    at processTicksAndRejections (internal/process/task_queues.js:79:11) {
  code: 14,
  details: 'No connection established',
  metadata: Metadata { internalRepr: Map(0) {}, options: {} }
  ```
  `@grpc/grpc-js` version installed is 1.1.8
  ```
  {
  "_from": "@grpc/grpc-js@~1.1.1",
  "_id": "@grpc/[email protected]",
  "_inBundle": false,
  "_integrity": "sha1-KEXw/D0b+7FQ7Xp4p2vfQbEm02c=",
  "_location": "/@grpc/grpc-js",
  "_phantomChildren": {
    "@types/long": "4.0.1",
    "lodash.camelcase": "4.3.0",
    "long": "4.0.0",
    "protobufjs": "6.10.2",
    "yargs": "15.4.1"
  },

The secrets manager's version is 3.2.3

 "dependencies": {
    "@google-cloud/secret-manager": "^3.2.3",
    "aws-sdk": "^2.445.0",
    "aws4": "^1.8.0",
AkhilA4 picture AkhilA4 on 3 Jan 2021

I am facing the same issue again:
package.json:

"@google-cloud/pubsub": "^1.1.6",
    "@grpc/grpc-js": "^1.1.7",

package-lock.json

"@google-cloud/pubsub": {
      "version": "1.7.3",
      "resolved": "https://registry.npmjs.org/@google-cloud/pubsub/-/pubsub-1.7.3.tgz",
...
"@grpc/grpc-js": {
          "version": "1.0.5",
          "resolved": "https://registry.npmjs.org/@grpc/grpc-js/-/grpc-js-1.0.5.tgz",
          "integrity": "sha512-Hm+xOiqAhcpT9RYM8lc15dbQD7aQurM7ZU8ulmulepiPlN7iwBXXwP3vSBUimoFoApRqz7pSIisXU8pZaCB4og==",
          "requires": {
            "semver": "^6.2.0"
          }
        }
sidcool1234 picture sidcool1234 on 4 Jan 2021

@sidcool1234 i'm too.
I'm use dialogflow, it doesn't usually happen
"@google-cloud/storage": "^2.5.0",
"@google-cloud/vision": "^1.8.0",
"actions-on-google": "^1.8.0",
"body-parser": "^1.18.3",
"config": "^3.0.1",
"dialogflow": "^1.2.0",
"dialogflow-fulfillment": "^0.6.1",

ducvu91 picture ducvu91 on 4 Jan 2021

@sidcool1234 , @ducvu91 did you guys find any work-around or still persisting with this issue ? Please let me know if you guys found any work-around.

AkhilA4 picture AkhilA4 on 7 Jan 2021

@AkhilA4 not yet, Sometimes it happens and it's random, there's no specific case so I can't find where the cause is.

ducvu91 picture ducvu91 on 7 Jan 2021

OK @ducvu91. Since last week, I'm encountering this issue every time I run the createSecret GCP API. Will try to create a new issue to get some attention for the issue. Not sure what needs to be done from dev end if this gets encountered in production environment.

AkhilA4 picture AkhilA4 on 7 Jan 2021
Was this page helpful?
0 / 5 - 0 ratings

Related issues

badoet picture badoet  Β·  4Comments
lucavallin picture lucavallin  Β·  5Comments
tvk-codecraft picture tvk-codecraft  Β·  3Comments
ozt88 picture ozt88  Β·  3Comments
Harmonickey picture Harmonickey  Β·  6Comments