Skip to content

Add more information on "Retry total timeout exceeded before any response was received" error. #410

New issue
New issue
Closed
googleapis/gax-nodejs
#839
Closed
Add more information on "Retry total timeout exceeded before any response was received" error.#410
googleapis/gax-nodejs
#839
Assignees
xiaozhenliu-gg5
Labels
priority: p2Moderately-important priority. Fix may not be included in next release.type: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.
@tanishiking

Description

@tanishiking
tanishiking
opened on Mar 7, 2020

Hi, gax-nodejs team, I'd like to propose to add some more information on error message for "Retry total timeout error" so that GCP users can easily debug which GCP library and which API calls are hitting "retry total timeout" error.

(I've already contacted GCP Support Team, they created an issue on public issue tracker, and suggested me to create an issue here).

Is your feature request related to a problem? Please describe. (background)

We are running Google Cloud Function with node10, and we occasionally hit the "Retry total timeout exceeded before any response was received" error.

FYI my piece of yarn.lock related to google-gax 
"@google-cloud/datastore@^4.5.2":
  version "4.5.2"
  resolved "https://registry.yarnpkg.com/@google-cloud/datastore/-/datastore-4.5.2.tgz#b1f9300ca2de91bcfd5783f54354411ece1446bc"
  integrity sha512-dILePgHiA14/6l47XrsTjQqGhZVtznrqg3Q3ent5jOhL+0QGGokY+Y3OtYTQ1yCAfUg/ZcwjLY1s2MBbrHqnog==
  dependencies:
    "@google-cloud/projectify" "^1.0.0"
    "@google-cloud/promisify" "^1.0.0"
    "@grpc/grpc-js" "0.6.11"
    "@types/duplexify" "^3.6.0"
    "@types/long" "^4.0.0"
    arrify "^2.0.1"
    concat-stream "^2.0.0"
    extend "^3.0.2"
    google-auth-library "^5.0.0"
    google-gax "^1.7.5"
    is "^3.3.0"
    split-array-stream "^2.0.0"
    stream-events "^1.0.5"

"@google-cloud/logging@^7.0.0":
  version "7.2.3"
  resolved "https://registry.yarnpkg.com/@google-cloud/logging/-/logging-7.2.3.tgz#499f04bb57c607e28c426566853e632eab13b8cf"
  integrity sha512-MLAlYVBihCs0e581n9VUYOPJcrSpwSdL7KAjy2wgQidmRD9aWjvg97F22JMCtvrUiFBmAjiJVtn1JyNIXlv0Yw==
  dependencies:
    "@google-cloud/common" "^2.2.2"
    "@google-cloud/paginator" "^2.0.0"
    "@google-cloud/projectify" "^1.0.0"
    "@google-cloud/promisify" "^1.0.0"
    "@opencensus/propagation-stackdriver" "0.0.20"
    arrify "^2.0.0"
    dot-prop "^5.1.0"
    eventid "^1.0.0"
    extend "^3.0.2"
    gcp-metadata "^3.1.0"
    google-auth-library "^5.2.2"
    google-gax "^1.11.0"
    is "^3.3.0"
    on-finished "^2.3.0"
    pumpify "^2.0.0"
    snakecase-keys "^3.0.0"
    stream-events "^1.0.4"
    through2 "^3.0.0"
    type-fest "^0.11.0"

"@google-cloud/pubsub@^1.5.0":
  version "1.5.0"
  resolved "https://registry.yarnpkg.com/@google-cloud/pubsub/-/pubsub-1.5.0.tgz#0ce5a60a90c87af9e9dcd28433a0da74c223007b"
  integrity sha512-SCuNClo/xDGjYmciExxVjX78WPY1Ul6MK5Qn5eX2tsILqxXpf5Lan+XU/jnL53pirAIFgcxt8I2CWibSdSqRww==
  dependencies:
    "@google-cloud/paginator" "^2.0.0"
    "@google-cloud/precise-date" "^1.0.0"
    "@google-cloud/projectify" "^1.0.0"
    "@google-cloud/promisify" "^1.0.0"
    "@types/duplexify" "^3.6.0"
    "@types/long" "^4.0.0"
    arrify "^2.0.0"
    async-each "^1.0.1"
    extend "^3.0.2"
    google-auth-library "^5.5.0"
    google-gax "^1.7.5"
    is-stream-ended "^0.1.4"
    lodash.snakecase "^4.1.1"
    p-defer "^3.0.0"
    protobufjs "^6.8.1"

"@google-cloud/vision@^1.7.2":
  version "1.9.0"
  resolved "https://registry.yarnpkg.com/@google-cloud/vision/-/vision-1.9.0.tgz#3dd9708a2d87c5a2ab46c104f2a320ee99cd51fb"
  integrity sha512-6ka0MggI8u4WgGJe1wAIdxIAKE9gRp1CQ5ADXNM+JmSUniEZfbeNwOG8twFCxyWBlUqC+cQJaG4Amd6SLXzk/w==
  dependencies:
    "@google-cloud/promisify" "^1.0.0"
    google-gax "^1.7.5"
    is "^3.2.1"

gaxios@^2.0.1, gaxios@^2.1.0:
  version "2.3.1"
  resolved "https://registry.yarnpkg.com/gaxios/-/gaxios-2.3.1.tgz#52bd832b5d6a252072783b9afd9742bde835b2f4"
  integrity sha512-DQOesWEx59/bm63lTX0uHDDXpGTW9oKqNsoigwCoRe2lOb5rFqxzHjLTa6aqEBecLcz69dHLw7rbS068z1fvIQ==
  dependencies:
    abort-controller "^3.0.0"
    extend "^3.0.2"
    https-proxy-agent "^5.0.0"
    is-stream "^2.0.0"
    node-fetch "^2.3.0"

gcp-metadata@^3.0.0, gcp-metadata@^3.1.0, gcp-metadata@^3.4.0:
  version "3.4.0"
  resolved "https://registry.yarnpkg.com/gcp-metadata/-/gcp-metadata-3.4.0.tgz#dfcbb6abe2c262c86c8eb01e4729d46b44e21484"
  integrity sha512-fizmBtCXHp8b7FZuzbgKaixO8DzsSYoEVmMgZIna7x8t6cfBF3eqirODWYxVbgmasA5qudCAKiszfB7yVwroIQ==
  dependencies:
    gaxios "^2.1.0"
    json-bigint "^0.3.0"

google-auth-library@^5.0.0, google-auth-library@^5.2.2, google-auth-library@^5.5.0, google-auth-library@^5.6.1, google-auth-library@^5.9.0:
  version "5.10.1"
  resolved "https://registry.yarnpkg.com/google-auth-library/-/google-auth-library-5.10.1.tgz#504ec75487ad140e68dd577c21affa363c87ddff"
  integrity sha512-rOlaok5vlpV9rSiUu5EpR0vVpc+PhN62oF4RyX/6++DG1VsaulAFEMlDYBLjJDDPI6OcNOCGAKy9UVB/3NIDXg==
  dependencies:
    arrify "^2.0.0"
    base64-js "^1.3.0"
    ecdsa-sig-formatter "^1.0.11"
    fast-text-encoding "^1.0.0"
    gaxios "^2.1.0"
    gcp-metadata "^3.4.0"
    gtoken "^4.1.0"
    jws "^4.0.0"
    lru-cache "^5.0.0"

google-gax@^1.11.0, google-gax@^1.7.5:
  version "1.14.2"
  resolved "https://registry.yarnpkg.com/google-gax/-/google-gax-1.14.2.tgz#ce4f9a42c1bc2ca4a4ed8e8cc70c6f7a3548b790"
  integrity sha512-Nde+FdqALbV3QgMA4KlkxOHfrj9busnZ3EECwy/1gDJm9vhKGwDLWzErqRU5g80OoGSAMgyY7DWIfqz7ina4Jw==
  dependencies:
    "@grpc/grpc-js" "^0.6.18"
    "@grpc/proto-loader" "^0.5.1"
    "@types/fs-extra" "^8.0.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"

googleapis-common@^3.2.0:
  version "3.2.1"
  resolved "https://registry.yarnpkg.com/googleapis-common/-/googleapis-common-3.2.1.tgz#1c81dfce74876948fb1e68a2a99f842da6123877"
  integrity sha512-lPAJXYpZLvY4AZp57RWj1eUXS2D5LxS3y6W0n9Jbl6eKOWmyLgz99f84XVCxVnyq8DcgV/ZAxt1lpFEzGZkVvQ==
  dependencies:
    extend "^3.0.2"
    gaxios "^2.0.1"
    google-auth-library "^5.6.1"
    qs "^6.7.0"
    url-template "^2.0.8"
    uuid "^3.3.2"

gtoken@^4.1.0:
  version "4.1.4"
  resolved "https://registry.yarnpkg.com/gtoken/-/gtoken-4.1.4.tgz#925ff1e7df3aaada06611d30ea2d2abf60fcd6a7"
  integrity sha512-VxirzD0SWoFUo5p8RDP8Jt2AGyOmyYcT/pOUgDKJCK+iSw0TMqwrVfY37RXTNmoKwrzmDHSk0GMT9FsgVmnVSA==
  dependencies:
    gaxios "^2.1.0"
    google-p12-pem "^2.0.0"
    jws "^4.0.0"
    mime "^2.2.0"

I believe this error happens when google cloud library (technically its underlying library, "gax-nodejs") tries to access GCP API and didn't get a response from the server within the deadline here https://github.com/googleapis/gax-nodejs/blob/4b9a35e509c5f617de3e2212cfa66aa75192f98a/src/normalCalls/retries.ts#L82-L89

I tried to debug which API call and which library emit this error message, but I couldn't because the error message and stack trace don't provide any information other than 'Retry total timeout exceeded before any response was received'.

Here's the full stack-trace when we hit the error.

Error: Retry total timeout exceeded before any response was received
    at repeat (/srv/functions/node_modules/google-gax/build/src/normalCalls/retries.js:65:31)
    at Timeout.setTimeout [as _onTimeout] (/srv/functions/node_modules/google-gax/build/src/normalCalls/retries.js:100: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)

Describe the solution you'd like

Therefore, I'd like to propose that gax shows some more information on DEADLINE_EXCEEDED error so that the GCP users can easily debug and where's the root cause of this issue.

For example:

  • Which library, or API didn't respond within the deadline.
  • How long the API call took.
  • What is the retry settings?

Unfortunately, since I'm not familiar with GRPC and GCP internal endpoints, I'm not sure is it possible.

Additional context

I guess an informative error message would be helpful for a lot of GCP users because as far as I know, there're quite a few people who are suffering from this issue:

Anyway, thank you so much for maintaining this fundamental library for GCP, you always save my days :)

Metadata

Metadata

Assignees

Labels

priority: p2Moderately-important priority. Fix may not be included in next release.type: bugError or flaw in code with unintended results or allowing sub-optimal usage patterns.

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

Development

No branches or pull requests

Issue actions