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.

Sign up for GitHub

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

Jump to bottom

Renovatebot logs continuously shows 'external-host-error' #12576

Closed
MartijnVisser opened this issue Nov 9, 2021 · 22 comments
Closed

Renovatebot logs continuously shows 'external-host-error' #12576

MartijnVisser opened this issue Nov 9, 2021 · 22 comments
Labels
status:requirements Full requirements are not yet known, so implementation should not be started type:bug Bug fix of existing functionality

Comments

@MartijnVisser
Copy link

How are you running Renovate?

WhiteSource Renovate hosted app on github.com

If you're self-hosting Renovate, tell us what version of Renovate you run.

No response

Please select which platform you are using if self-hosting.

github.com

If you're self-hosting Renovate, tell us what version of the platform you run.

No response

Describe the bug

Since a couple of weeks, the Renovatebot has stopped generating new PRs with available dependency updates. When checking the Renovate Dashboard, all the displayed logs show as a result 'external-host-error'. I'll paste the logs in the debug logs. The repo can be found at https://github.com/MartijnVisser/flink/

Relevant debug logs

Logs 
WARN: Host error
{
  "hostType": "npm",
  "lookupName": "@angular/common",
  "err": {
    "name": "TimeoutError",
    "code": "ETIMEDOUT",
    "timings": {
      "start": 1636458986122,
      "socket": 1636458986122,
      "lookup": 1636458986124,
      "connect": 1636458988229,
      "secureConnect": 1636458988244,
      "upload": 1636458988246,
      "response": 1636458990505,
      "error": 1636459050111,
      "abort": 1636459057253,
      "phases": {
        "wait": 0,
        "dns": 2,
        "tcp": 2105,
        "tls": 15,
        "request": 2,
        "firstByte": 2259,
        "total": 71131
      }
    },
    "event": "request",
    "message": "Timeout awaiting 'request' for 60000ms",
    "stack": "RequestError: Timeout awaiting 'request' for 60000ms\n    at ClientRequest.<anonymous> (/home/ubuntu/renovateapp/node_modules/got/dist/source/core/index.js:956:65)\n    at Object.onceWrapper (events.js:520:26)\n    at ClientRequest.emit (events.js:412:35)\n    at ClientRequest.emit (domain.js:470:12)\n    at ClientRequest.origin.emit (/home/ubuntu/renovateapp/node_modules/@szmarczak/http-timer/dist/source/index.js:43:20)\n    at TLSSocket.socketErrorListener (_http_client.js:475:9)\n    at TLSSocket.emit (events.js:400:28)\n    at TLSSocket.emit (domain.js:470:12)\n    at emitErrorNT (internal/streams/destroy.js:106:8)\n    at emitErrorCloseNT (internal/streams/destroy.js:74:3)\n    at processTicksAndRejections (internal/process/task_queues.js:82:21)\n    at Timeout.timeoutHandler [as _onTimeout] (/home/ubuntu/renovateapp/node_modules/got/dist/source/core/utils/timed-out.js:36:25)\n    at listOnTimeout (internal/timers.js:559:11)\n    at processTimers (internal/timers.js:500:7)",
    "options": {
      "headers": {
        "user-agent": "Renovate Bot (GitHub App 2740)",
        "accept": "application/json",
        "accept-encoding": "gzip, deflate, br"
      },
      "url": "https://registry.npmjs.org/@angular%2Fcommon",
      "hostType": "npm",
      "username": "",
      "password": "",
      "method": "GET",
      "http2": false
    },
    "response": {
      "statusCode": 200,
      "statusMessage": "OK",
      "body": "ar-core+npm@google.com\"}],\"_npmOperationalInternal\":{\"host\":\"s3://npm-registry-packages\",\"tmp\":\"tmp/common-4.3.5.tgz_1502908206268_0.10931240511126816\"},\"directories\":{}},\"5.0.0-beta.4\":{\"name\":\"@angular/common\",\"version\":\"5.0.0-beta.4\",\"description\":\"Angular - commonly needed directives and services\",\"main\":\"./bundles/common.umd.js\",\"module\":\"./@angular/common.es5.js\",\"es2015\":\"./@angular/common.js\",\"typings\":\"./common.d.ts\",\"author\":{\"name\":\"angular\"},\"license\":\"MIT\",\"dependencies\":{\"tslib\":\"^1.7.1\"},\"peerDependencies\":{\"@angular/core\":\"5.0.0-beta.4\"},\"repository\":{\"type\":\"git\",\"url\":\"git+https://github.com/angular/angular.git\"},\"bugs\":{\"url\":\"https://github.com/angular/angular/issues\"},\"homepage\":\"https://github.com/angular/angular#readme\",\"_id\":\"@angular/common@5.0.0-beta.4\",\"scripts\":{},\"_shasum\":\"ceba2a572f7733206a292ca18b7ad8d7d0030e43\",\"_from\":\"dist/packages-dist/common\",\"_resolved\":\"file:dist/packages-dist/common\",\"_npmVersion\":\"3.10.10\",\"_nodeVersion\":\"6.10.2\",\"_npmUser\":{\"name\":\"angular\",\"email\":\"angular-core+npm@google.com\"},\"dist\":{\"shasum\":\"ceba2a572f7733206a292ca18b7ad8d7d0030e43\",\"tarball\":\"https://registry.npmjs.org/@angular/common/-/common-5.0.0-beta.4.tgz\"},\"maintainers\":[{\"name\":\"angular\",\"email\":\"angular-core+npm@google.com\"}],\"_npmOperationalInternal\":{\"host\":\"s3://npm-registry-packages\",\"tmp\":\"tmp/common-5.0.0-beta.4.tgz_1502914368350_0.7648596335202456\"},\"directories\":{}},\"4.3.6\":{\"name\":\"@angular/common\",\"version\":\"4.3.6\",\"description\":\"Angular - commonly needed directives and services\",\"main\":\"./bundles/common.umd.js\",\"module\":\"./@angular/common.es5.js\",\"es2015\":\"./@angular/common.js\",\"typings\":\"./common.d.ts\",\"author\":{\"name\":\"angular\"},\"license\":\"MIT\",\"dependencies\":{\"tslib\":\"^1.7.1\"},\"peerDependencies\":{\"@angular/core\":\"4.3.6\"},\"repository\":{\"type\":\"git\",\"url\":\"git+https://github.com/angular/angular.git\"},\"bugs\":{\"url\":\"https://github.com/angular/angular/issues\"},\"homepage\":\"https://github.com/angular/angular#readme\",\"_id\":\"@angular/common@4.3.6\",\"scripts\":{},\"_shasum\":\"ed37e9307c7506dd834797c1a6cf675e52b5b6ee\",\"_from\":\"dist/packages-dist/common\",\"_resolved\":\"file:dist/packages-dist/common\",\"_npmVersion\":\"3.10.9\",\"_nodeVersion\":\"6.9.2\",\"_npmUser\":{\"name\":\"angular\",\"email\":\"angular-core+npm@google.com\"},\"dist\":{\"shasum\":\"ed37e9307c7506dd834797c1a6cf675e52b5b6ee\",\"tarball\":\"https://registry.npmjs.org/@angular/common/-/common-4.3.6.tgz\"},\"maintainers\":[{\"name\":\"angular\",\"email\":\"angular-core+npm@google.com\"}],\"_npmOperationalInternal\":{\"host\":\"s3://npm-registry-packages\",\"tmp\":\"tmp/common-4.3.6.tgz_1503520208612_0.5090164702851325\"},\"directories\":{}},\"5.0.0-beta.5\":{\"name\":\"@angular/common\",\"version\":\"5.0.0-beta.5\",\"description\":\"Angular - commonly needed directives and services\",\"main\":\"./bundles/common.umd.js\",\"module\":\"./@angular/common.es5.js\",\"es2015\":\"./@angular/common.js\",\"typings\":\"./common.d.ts\",\"author\":{\"name\":\"angular\"},\"license\":\"MIT\",\"dependencies\":{\"tslib\":\"^1.7.1\"},\"peerDependencies\":{\"@angular/core\":\"5.0.0-beta.5\"},\"repository\":{\"type\":\"git\",\"url\":\"git+https://github.com/angular/angular.git\"},\"bugs\":{\"url\":\"https://github.com/angular/angular/issues\"},\"homepage\":\"https://github.com/angular/angular#readme\",\"_id\":\"@angular/common@5.0.0-beta.5\",\"scripts\":{},\"_shasum\":\"21c13bd4ca852c751e09e6e99c8418896d1e6752\",\"_from\":\"dist/packages-dist/common\",\"_resolved\":\"file:dist/packages-dist/common\",\"_npmVersion\":\"3.10.10\",\"_nodeVersion\":\"6.9.5\",\"_npmUser\":{\"name\":\"angular\",\"email\":\"angular-core+npm@google.com\"},\"dist\":{\"shasum\":\"21c13bd4ca852c751e09e6e99c8418896d1e6752\",\"tarball\":\"https://registry.npmjs.org/@angular/common/-/common-5.0.0-beta.5.tgz\"},\"maintainers\":[{\"name\":\"angular\",\"email\":\"angular-core+npm@google.com\"}],\"_npmOperationalInternal\":{\"host\":\"s3://npm-registry-packages\",\"tmp\":\"tmp/common-5.0.0-beta.5.tgz_1503962350364_0.6856481751892716\"},\"directories\":{}},\"4.4.0-RC.0\":{\"name\":\"@angular/common\",\"version\":\"4.4.0-RC.0\",\"description\":\"Angular - commonly needed directives and services\",\"main\":\"./bundles/common.umd.js\",\"module\":\"./@angular/common.es5.js\",\"es2015\":\"./@angular/common.js\",\"typings\":\"./common.d.ts\",\"author\":{\"name\":\"angular\"},\"license\":\"MIT\",\"dependencies\":{\"tslib\":\"^1.7.1\"},\"peerDependencies\":{\"@angular/core\":\"4.4.0-RC.0\"},\"repository\":{\"type\":\"git\",\"url\":\"git+https://github.com/angular/angular.git\"},\"bugs\":{\"url\":\"https://github.com/angular/angular/issues\"},\"homepage\":\"https://github.com/angular/angular#readme\",\"_id\":\"@angular/common@4.4.0-RC.0\",\"scripts\":{},\"_shasum\":\"ad2d0853a62d2e87bba0bdd6588da6fa5f2dabb8\",\"_from\":\"dist/packages-dist/common\",\"_resolved\":\"file:dist/packages-dist/common\",\"_npmVersion\":\"3.10.7\",\"_nodeVersion\":\"6.9.5\",\"_npmUser\":{\"name\":\"angular\",\"email\":\"npm@angular.io",
      "headers": {
        "date": "Tue, 09 Nov 2021 11:56:28 GMT",
        "content-type": "application/json",
        "transfer-encoding": "chunked",
        "connection": "close",
        "cf-ray": "6ab6dba48848602e-SEA",
        "age": "200",
        "cache-control": "public, max-age=300",
        "etag": "W/\"57f909c4d98afe82615ddc5113553604\"",
        "last-modified": "Wed, 03 Nov 2021 20:58:51 GMT",
        "vary": "accept-encoding, accept",
        "cf-cache-status": "HIT",
        "expect-ct": "max-age=604800, report-uri=\"https://report-uri.cloudflare.com/cdn-cgi/beacon/expect-ct\"",
        "x-amz-replication-status": "PENDING",
        "server": "cloudflare",
        "content-encoding": "gzip"
      },
      "httpVersion": "1.1"
    }
  }
}

Have you created a minimal reproduction repository?

I have linked to a minimal reproduction repository in the bug description
@MartijnVisser MartijnVisser added priority-5-triage status:requirements Full requirements are not yet known, so implementation should not be started type:bug Bug fix of existing functionality labels Nov 9, 2021
@rarkins
Copy link
Collaborator

rarkins commented Nov 9, 2021

As you can see in the logs, it appears to be because of a 60s timeout on an angular package. Is it the same package timing out every run?

@MartijnVisser
Copy link
Author

No, it differs. Some examples:

"lookupName": "@angular/animations"
"lookupName": "@angular/common"
"lookupName": "@angular/core"
"lookupName": "@angular/compiler"

@rarkins
Copy link
Collaborator

rarkins commented Nov 9, 2021

This repo has a very heavy request load when I ran against a fork locally, mainly to maven central:

       "hostStats": {
         "api.github.com": {"requestCount": 6, "requestAvgMs": 699, "queueAvgMs": 0},
         "auth.docker.io": {"requestCount": 1, "requestAvgMs": 507, "queueAvgMs": 0},
         "clojars.org": {"requestCount": 283, "requestAvgMs": 1022, "queueAvgMs": 0},
         "index.docker.io": {"requestCount": 5, "requestAvgMs": 1005, "queueAvgMs": 0},
         "packages.confluent.io": {
           "requestCount": 271,
           "requestAvgMs": 249,
           "queueAvgMs": 0
         },
         "pypi.org": {"requestCount": 14, "requestAvgMs": 534, "queueAvgMs": 0},
         "registry.npmjs.org": {
           "requestCount": 58,
           "requestAvgMs": 2004,
           "queueAvgMs": 0
         },
         "repo.maven.apache.org": {
           "requestCount": 26473,
           "requestAvgMs": 303,
           "queueAvgMs": 0
         },
         "repository.apache.org": {
           "requestCount": 12,
           "requestAvgMs": 182,
           "queueAvgMs": 0
         }
       },
       "totalRequests": 27123

npmjs is not so bad, but the angular packages are probably "big".

Here's the repo's job history, from most recent to oldest: https://gist.github.com/rarkins/93b640c79af31d6243b09e071a76668a

In general, it went from done to external-host-error to done and then now has stuck on external-host-error.

@rarkins
Copy link
Collaborator

rarkins commented Nov 9, 2021

@zharinov this touches a couple of areas you've worked on before, e.g. it's a 200 OK:

    "response": {
      "statusCode": 200,
      "statusMessage": "OK",

But also timed out

@MartijnVisser
Copy link
Author

It's definitely a really big project. I can totally understand if it's too big for a non-commercial version. I mainly wanted to flag it to you in case you were unaware and/or if it causes undesirable side-effects on your end.

@rarkins
Copy link
Collaborator

rarkins commented Nov 9, 2021

It runs OK for me locally but in production it looks like it's tripping a bug due to too many concurrent large requests, probably in the got library we use. Cc @szmarczak

@szmarczak
Copy link

Got doesn't alter any logic (nor it does implement its own) in terms of concurrency. Either it doesn't receive the last chunk or it's a Node.js bug. Please use Wireshark or a similar tool to see if the response is received in full.

@rarkins
Copy link
Collaborator

rarkins commented Nov 9, 2021

@szmarczak is any of the above logs of use for your question? It looks like the response is missing the start. FYI we're running on Node 14, which I'd hope is pretty stable by now.

image

@szmarczak
Copy link

Seems like a flashback from sindresorhus/got#1062 (comment) will investigate this.

@rarkins
Copy link
Collaborator

rarkins commented Nov 9, 2021

Yeah, it reminds me of that too. Both times it was triggered by repos with multiple concurrent GETs of npm libraries with 10s of MB each.

This was referenced Nov 10, 2021
Merged
Merged
Merged
@szmarczak
Copy link

I ran locally 100k+ requests to npm and all were successful 🤔 Does it happen only with npm?

@MartijnVisser
Copy link
Author

Yes, nothing in the logs outside of NPM

@szmarczak
Copy link

From the logs, it skipped the first 114688 bytes, saved the next 4726 bytes, and paused before the next 1212171 bytes (total: 1331585). Having in mind no there's no keepAlive, this is a very unusual bug. I went through the source code (v11.8.2) again and can't see how it would leak. A tcpdump of the request would help (maybe).

Can you try setting decompress to false?

@MartijnVisser
Copy link
Author

@szmarczak Can I do that in the Github hosted app? I can't find that option in the documentation at https://docs.renovatebot.com/configuration-options/ ?

@rarkins
Copy link
Collaborator

rarkins commented Nov 16, 2021

This requires code changes from us and affects most requests we send, right?

image

@szmarczak
Copy link

szmarczak commented Nov 16, 2021 •
edited
Loading

Yes. I guess this could be an experimental env option, right?

@rarkins
Copy link
Collaborator

rarkins commented Nov 17, 2021

We've greatly reduced the Maven Central request load but still seeing the npmjs timeouts in this repo, so they seem related.

@szmarczak are there any code snippets for converting from decompress=true to decompress=false? e.g. receiving a compressed Buffer.

@MartijnVisser
Copy link
Author

Since 3 hours ago, it suddenly appears to work again. Not sure if you've done anything on your end, but it is now progressing again:

image

@szmarczak
Copy link

are there any code snippets for converting from decompress=true to decompress=false? e.g. receiving a compressed Buffer.

Well, you can set the accept-encoding header manually and set responseType to buffer.

@rarkins
Copy link
Collaborator

rarkins commented Nov 18, 2021

And then also call a function like gzip too?

@szmarczak
Copy link

Correct. I'd try getting uncompressed data though, then when it happens I'm pretty sure that would be a Node.js bug.

@szmarczak
Copy link

Related: nodejs/node#10358

@rarkins rarkins closed this as completed Nov 25, 2022
@github-actions github-actions bot locked as resolved and limited conversation to collaborators Dec 26, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
status:requirements Full requirements are not yet known, so implementation should not be started type:bug Bug fix of existing functionality
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@MartijnVisser @rarkins @szmarczak