connect ETIMEDOUT 185.199.111.154:443 when downloading a feature

[Chuxel]

From Dave Syer (@dsyer) devcontainers/features#228

There appears to potentially be some sort of networking issue going on when using a feature locally. Possibly with GHCR? //cc John Keech (@jkeech) Edmundo Gonzalez (@edgonmsft) Samruddhi Khandale (@samruddhikhandale) joshspicer

---

Can someone help with some more detailed instructions on how to use this? I tried adding the feature and getting a lot of errors. Different errors, no obvious pattern. This one is common:

[2022-11-11T11:59:37.210Z] Start: Run: tar --no-same-owner -x -f -
[2022-11-11T11:59:37.228Z] Stop (18 ms): Run: tar --no-same-owner -x -f -
[2022-11-11T11:59:37.237Z] * Processing feature: ghcr.io/devcontainers/features/nix
[2022-11-11T11:59:37.744Z] * Processing feature: ghcr.io/devcontainers/features/docker-in-docker
[2022-11-11T11:59:38.329Z] * Fetching feature: nix_1_oci
[2022-11-11T12:01:48.847Z] error: Error: connect ETIMEDOUT 185.199.111.154:443
[2022-11-11T12:01:48.847Z] (!) ERR: Failed to fetch feature: Failed to download package for ghcr.io/devcontainers/features/nix 
[2022-11-11T12:01:48.849Z] Error: Failed to download package for ghcr.io/devcontainers/features/nix
[2022-11-11T12:01:48.850Z]     at vw (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:155:6485)
[2022-11-11T12:01:48.850Z]     at processTicksAndRejections (node:internal/process/task_queues:96:5)
[2022-11-11T12:01:48.850Z]     at async yS (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:186:6943)
[2022-11-11T12:01:48.851Z]     at async na (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:186:2444)
[2022-11-11T12:01:48.851Z]     at async oo (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:186:12686)
[2022-11-11T12:01:48.852Z]     at async sa (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:186:11651)
[2022-11-11T12:01:48.852Z]     at async bu (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:254:2847)
[2022-11-11T12:01:48.852Z]     at async Jw (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:254:1779)
[2022-11-11T12:01:48.853Z]     at async JS (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:260:2006)
[2022-11-11T12:01:48.853Z]     at async co (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js:260:3110)
[2022-11-11T12:01:48.857Z] Stop (131867 ms): Run: /nix/store/nrdmbm43k7xyc9nvg741zcqpi7i72rvn-vscode-1.70.2/lib/vscode/code /home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js up --user-data-folder /home/dsyer/.config/Code/User/globalStorage/ms-vscode-remote.remote-containers/data --workspace-folder /home/dsyer/dev/scratch/hello-as --workspace-mount-consistency cached --id-label devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as --log-level debug --log-format json --config /home/dsyer/dev/scratch/hello-as/.devcontainer/devcontainer.json --default-user-env-probe loginInteractiveShell --mount type=volume,source=vscode,target=/vscode,external=true --skip-post-create --update-remote-user-uid-default on --mount-workspace-git-root true
[2022-11-11T12:01:48.858Z] Exit code 1
[2022-11-11T12:01:48.871Z] Command failed: /nix/store/nrdmbm43k7xyc9nvg741zcqpi7i72rvn-vscode-1.70.2/lib/vscode/code /home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.247.0/dist/spec-node/devContainersSpecCLI.js up --user-data-folder /home/dsyer/.config/Code/User/globalStorage/ms-vscode-remote.remote-containers/data --workspace-folder /home/dsyer/dev/scratch/hello-as --workspace-mount-consistency cached --id-label devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as --log-level debug --log-format json --config /home/dsyer/dev/scratch/hello-as/.devcontainer/devcontainer.json --default-user-env-probe loginInteractiveShell --mount type=volume,source=vscode,target=/vscode,external=true --skip-post-create --update-remote-user-uid-default on --mount-workspace-git-root true
[2022-11-11T12:01:48.871Z] Exit code 1

---

From Chuck Lantz (@Chuxel)

Dave Syer (@dsyer) Would you mind raising an issue with your specifics? In particular the base image you are using, OS, architecture, etc. Possible there's a scenario where things are not working as expected. That particular error though sounds like its actually having a hard time downloading the feature itself which could be connectivity related. devcontainers/features#275 is very specific to the universal image, for example.

---

From Dave Syer (@dsyer)

That's it really, for the specifics. The JSON is just the default if you add ubuntu and nix. My network connectivity is generally good here locally. Maybe there was a DNS glitch out there somewhere? 185.199.111.154 looks like Github (not gcr.io).

[Chuxel]

Dave Syer (@dsyer) Are you behind a proxy at all? Very odd.

[dsyer]

No proxy here. It definitely was intermittent. I eventually got it to work, but it still fails sometimes.

[dsyer]

Here's a complete log if it helps when I tried to add another feature. This happens about 90% of the time to me when I change the JSON.

[2022-11-13T17:14:41.371Z] Dev Containers 0.263.0 in VS Code 1.73.1 (6261075646f055b99068d3688932416f2346dd3b).
[2022-11-13T17:14:41.371Z] Start: Resolving Remote
[2022-11-13T17:14:41.377Z] Setting up container for folder or workspace: /home/dsyer/dev/scratch/hello-as
[2022-11-13T17:14:41.384Z] Start: Check Docker is running
[2022-11-13T17:14:41.384Z] Start: Run: docker version --format {{.Server.APIVersion}}
[2022-11-13T17:14:41.426Z] Stop (42 ms): Run: docker version --format {{.Server.APIVersion}}
[2022-11-13T17:14:41.427Z] Server API version: 1.41
[2022-11-13T17:14:41.427Z] Stop (43 ms): Check Docker is running
[2022-11-13T17:14:41.427Z] Start: Run: docker volume ls -q
[2022-11-13T17:14:41.458Z] Stop (31 ms): Run: docker volume ls -q
[2022-11-13T17:14:41.464Z] Start: Run: docker ps -q -a --filter label=vsch.local.folder=/home/dsyer/dev/scratch/hello-as --filter label=vsch.quality=stable
[2022-11-13T17:14:41.494Z] Stop (30 ms): Run: docker ps -q -a --filter label=vsch.local.folder=/home/dsyer/dev/scratch/hello-as --filter label=vsch.quality=stable
[2022-11-13T17:14:41.494Z] Start: Run: /nix/store/0clacs5vkmcns9p5fi3b7kbiix6mqwjk-vscode-1.73.1/lib/vscode/code --ms-enable-electron-run-as-node /home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js up --user-data-folder /home/dsyer/.config/Code/User/globalStorage/ms-vscode-remote.remote-containers/data --workspace-folder /home/dsyer/dev/scratch/hello-as --workspace-mount-consistency cached --id-label devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as --log-level debug --log-format json --config /home/dsyer/dev/scratch/hello-as/.devcontainer/devcontainer.json --default-user-env-probe loginInteractiveShell --remove-existing-container --mount type=volume,source=vscode,target=/vscode,external=true --skip-post-create --update-remote-user-uid-default on --mount-workspace-git-root true
[2022-11-13T17:14:41.756Z] (node:3443815) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
[2022-11-13T17:14:41.756Z] (Use `code --trace-deprecation ...` to show where the warning was created)
[2022-11-13T17:14:41.758Z] @devcontainers/cli 0.23.2. Node.js v16.14.2. linux 5.4.0-125-generic x64.
[2022-11-13T17:14:41.758Z] Start: Run: docker buildx version
[2022-11-13T17:14:41.824Z] Stop (66 ms): Run: docker buildx version
[2022-11-13T17:14:41.825Z] 
[2022-11-13T17:14:41.825Z] docker: 'buildx' is not a docker command.
See 'docker --help'

[2022-11-13T17:14:41.826Z] Exit code 1
[2022-11-13T17:14:41.826Z] Start: Resolving Remote
[2022-11-13T17:14:41.831Z] Start: Run: git rev-parse --show-cdup
[2022-11-13T17:14:41.838Z] Stop (7 ms): Run: git rev-parse --show-cdup
[2022-11-13T17:14:41.840Z] Start: Run: docker ps -q -a --filter label=devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as
[2022-11-13T17:14:41.900Z] Stop (60 ms): Run: docker ps -q -a --filter label=devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as
[2022-11-13T17:14:41.901Z] Start: Run: docker inspect --type image mcr.microsoft.com/devcontainers/base:ubuntu
[2022-11-13T17:14:41.938Z] Stop (37 ms): Run: docker inspect --type image mcr.microsoft.com/devcontainers/base:ubuntu
[2022-11-13T17:14:41.939Z] local container features stored at: /home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/node_modules/vscode-dev-containers/container-features
[2022-11-13T17:14:41.940Z] Start: Run: tar --no-same-owner -x -f -
[2022-11-13T17:14:41.956Z] Stop (16 ms): Run: tar --no-same-owner -x -f -
[2022-11-13T17:14:41.963Z] * Processing feature: ghcr.io/devcontainers/features/nix:1
[2022-11-13T17:14:42.413Z] * Processing feature: ghcr.io/devcontainers/features/docker-in-docker:1
[2022-11-13T17:14:42.877Z] * Fetching feature: nix_1_oci
[2022-11-13T17:16:53.931Z] error: Error: connect ETIMEDOUT 185.199.111.154:443
[2022-11-13T17:16:53.931Z] (!) ERR: Failed to fetch feature: Failed to download package for ghcr.io/devcontainers/features/nix 
[2022-11-13T17:16:53.933Z] Error: Failed to download package for ghcr.io/devcontainers/features/nix
[2022-11-13T17:16:53.934Z]     at fO (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1736:10509)
[2022-11-13T17:16:53.934Z]     at process.processTicksAndRejections (node:internal/process/task_queues:96:5)
[2022-11-13T17:16:53.935Z]     at async xse (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1804:8294)
[2022-11-13T17:16:53.935Z]     at async bm (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1804:2465)
[2022-11-13T17:16:53.935Z]     at async Gf (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1806:1327)
[2022-11-13T17:16:53.936Z]     at async _m (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1806:306)
[2022-11-13T17:16:53.936Z]     at async pF (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1887:2022)
[2022-11-13T17:16:53.937Z]     at async eT (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1887:901)
[2022-11-13T17:16:53.937Z]     at async voe (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1893:2049)
[2022-11-13T17:16:53.937Z]     at async Xf (/home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js:1893:3212)
[2022-11-13T17:16:53.942Z] Stop (132448 ms): Run: /nix/store/0clacs5vkmcns9p5fi3b7kbiix6mqwjk-vscode-1.73.1/lib/vscode/code --ms-enable-electron-run-as-node /home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js up --user-data-folder /home/dsyer/.config/Code/User/globalStorage/ms-vscode-remote.remote-containers/data --workspace-folder /home/dsyer/dev/scratch/hello-as --workspace-mount-consistency cached --id-label devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as --log-level debug --log-format json --config /home/dsyer/dev/scratch/hello-as/.devcontainer/devcontainer.json --default-user-env-probe loginInteractiveShell --remove-existing-container --mount type=volume,source=vscode,target=/vscode,external=true --skip-post-create --update-remote-user-uid-default on --mount-workspace-git-root true
[2022-11-13T17:16:53.943Z] Exit code 1
[2022-11-13T17:16:53.957Z] Command failed: /nix/store/0clacs5vkmcns9p5fi3b7kbiix6mqwjk-vscode-1.73.1/lib/vscode/code --ms-enable-electron-run-as-node /home/dsyer/.vscode/extensions/ms-vscode-remote.remote-containers-0.263.0/dist/spec-node/devContainersSpecCLI.js up --user-data-folder /home/dsyer/.config/Code/User/globalStorage/ms-vscode-remote.remote-containers/data --workspace-folder /home/dsyer/dev/scratch/hello-as --workspace-mount-consistency cached --id-label devcontainer.local_folder=/home/dsyer/dev/scratch/hello-as --log-level debug --log-format json --config /home/dsyer/dev/scratch/hello-as/.devcontainer/devcontainer.json --default-user-env-probe loginInteractiveShell --remove-existing-container --mount type=volume,source=vscode,target=/vscode,external=true --skip-post-create --update-remote-user-uid-default on --mount-workspace-git-root true
[2022-11-13T17:16:53.958Z] Exit code 1

[dsyer]

Maybe this is the wrong place to ask, but why not use a base image (which is then properly cached) for nix and docker etc. (things that are extracted into "features" in devcontainers)? "Features" take a long time to install, delaying startup of the devcontainer. And then they fail 90% of the time (right now for me anyway).

[Chuxel]

We maintain quite a few base images already. Features are about enabling arbitrary ecosystems or adding "one more thing." Features end up as Docker layers, so things like cache from work as expected. Some features like Python that require building under certain circumstances will improve with time as well. You can then pick a base, and jump into the ecosystem you want to use. Features then provide needed settings to ensure things like Go work properly in a container-based environment that arbitrary packaging systems can't do. Certainly we could consider more base images, but we're happy for the community to drive and maintain their own as well. Both Dev Container Templates and Features can be community contributed now to highlight the existence of pre-built images.

We need to track down why you are experiencing this problem. All of our base images use Features so it's unclear why you're experiencing this while others are not. It might be some sort of issue with GHCR itself.

[Chuxel]

Quick follow up - where are you located? It could be geo specific.

[dsyer]

Quick follow up - where are you located?

UK. 185.199.111.154 is indeed unreachable. But why is it even trying?

[Chuxel]

That's a GitHub CDN endpoint. It's acquiring the Nix Feature from GHCR. So, there may be a CDN issue in your region and in Codespaces you must end up hitting a slightly different endpoint. I've let folks on the GitHub side know since this sounds like a GH infrastructure hiccup of some sort.

[dsyer]

I don't know if it helps but I seem to have more chance of success if I docker system prune on the host first.

[Chuxel]

Yeah, Features are OCI artifacts, so they're cached (along with any layers that were built from them). Doing a prune forces them to be re-acquired which would trip you randomly hitting this CDN IP is my bet. This is all super helpful info!

[joshspicer]

Hey, Dave Syer (@dsyer) - Can you run the debug steps at http://github-debug.com/ and email me the results (<my-username>@github.com). Additionally, if you could run the traceroute tool against pkg-containers.githubusercontent.com, and ghcr.io to see where it ends up.

I'm working with the GitHub networking team to understand this better.

[dsyer]

Sure. I'm travelling this week, so I'll come back to this on Friday (or maybe Monday) when I'm back.