TypeError: Cannot read properties of undefined (reading '0') in devContainersSpecCLI.js for some features

[0xE1E10]

For some reasons, this feature causes devcontainers to choke:

	"features": {
		"ghcr.io/devcontainers-community/features/llvm:3.0.0": {},
		// "./features-llvm": {},

build.log

3.0, 3, and latest gives same problem. But cloning the repo and refer to it locally works.

It's not clear what the problem is or how to even begin to debug this problem with the minified script. Do you guys offer a debug build somewhere?

[eljog]

Thank you for cross posting this issue in the feature repo. I hope they will be able to provide clear directions specific to this feature.

[chrmarti]

The error is in the tar module which we recently updated. Does this reproduce with the CLI version 0.53.0?

[0xE1E10]

❯ devcontainer --version
0.54.2
❯ devcontainer build --workspace-folder .
...
TypeError: Cannot read properties of undefined (reading '0')
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:45532
    at Array.every (<anonymous>)
    at n (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:45522)
    at o (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:45603)
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:46030
    at Set.forEach (<anonymous>)
    at s (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:46019)
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:45627
    at i (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:53461)
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:54533

I'm not very good at TypeScript debugging. But next I'll try cloning this repo and see if I can convince it to run with no minify so I can at least see the actual line of code having this issue.

[0xE1E10]

Waiting for the debugger to disconnect...
/workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6107
        return paths.every((q) => q[0] === fn) && dirs.every((q) => q[0] instanceof Set && q[0].has(fn));
                                   ^

TypeError: Cannot read properties of undefined (reading '0')
    at /workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6107:36
    at Array.every (<anonymous>)
    at check (/workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6107:22)
    at run (/workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6110:33)
    at /workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6150:31
    at Set.forEach (<anonymous>)
    at clear (/workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6150:14)
    at /workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6114:18
    at done (/workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6616:11)
    at /workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6708:11

[0xE1E10]

Looks like paths usually have items pointing at CHECKFS2:

        this.reservations.reserve(paths, (done) => this[CHECKFS2](entry, done));

But with a debugger, I can see that during the crash, paths have 2 elements. Both with a value of "undefined". I checked that reserve() never insert invalid elements. So the function must have become undefined after getting inserted. I don't know enough about TypeScript to understand what's going on or why it's only triggered by this one particular repo. But I'll be happy to test things out if you have any ideas.

[chrmarti]

        this.reservations.reserve(paths, (done) => this[CHECKFS2](entry, done));

Not sure this is the correct unminified code, the minified code is using .every().

Could you install version 0.53.0 of the CLI (e.g., npm i -g @devcontainers/[email protected]) and check if it works there?

[chrmarti]

        this.reservations.reserve(paths, (done) => this[CHECKFS2](entry, done));

Not sure this is the correct unminified code, the minified code is using .every().

I missed that you were running the unminified code. The error seems to be specific to the tar package. Would be great if you could try 0.53.0 of the CLI, if it works there that would again hint a something in tar being the root cause. Thanks.

[0xE1E10]

0.53.0 gives exactly same result as 0.54.2 and main branch on git:

❯ devcontainer --version
0.53.0

❯ pwd
/home/clementcheung/src/cli/src/test/configs/example

❯ cat .devcontainer.json
// Example devcontainer.json configuration, 
// wired into the vscode launch task (.vscode/launch.json)
{
        "image": "mcr.microsoft.com/devcontainers/base:latest",
        "features": {
                "ghcr.io/devcontainers/features/go:1": {
                        "version": "latest"
                },
                "ghcr.io/devcontainers-community/features/llvm:3": {}
        }
}%                                                                    

❯ devcontainer build --workspace-folder .
...
TypeError: Cannot read properties of undefined (reading '0')
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:52932
    at Array.every (<anonymous>)
    at n (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:52922)
    at o (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:53003)
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:53430
    at Set.forEach (<anonymous>)
    at s (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:53419)
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:53027
    at i (/home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:60861)
    at /home/clementcheung/.nvm/versions/node/v21.4.0/lib/node_modules/@devcontainers/cli/dist/spec-node/devContainersSpecCLI.js:11:61933

[0xE1E10]

        this.reservations.reserve(paths, (done) => this[CHECKFS2](entry, done));

Not sure this is the correct unminified code, the minified code is using .every().

Could you install version 0.53.0 of the CLI (e.g., npm i -g @devcontainers/[email protected]) and check if it works there?

No, that's not the unminifed code. The unminified code is in the previous comment:

/workspaces/cli/dist/spec-node/devContainersSpecCLI.js:6107
        return paths.every((q) => q[0] === fn) && dirs.every((q) => q[0] instanceof Set && q[0].has(fn));

It does use every().

I was saying that in the unminified code, I can see with a debugger that paths initially have valid elements and q[0] is valid. But after a few loops, paths is an array with 2 undefined elements. [undefined, undefined] When we do every() on it, q === undefined and therefore q[0] is not a valid statement. That's why we hit the error.

TypeError: Cannot read properties of undefined (reading '0')

I then tried to see who put the undefined in there. There's only one place we touch that field in the entire file that I can find:

        this.reservations.reserve(paths, (done) => this[CHECKFS2](entry, done));

CHECKFS2 is a local function. We put a pointer to it. It's not possibly to have undefined. The function also prints that out on console so I can verify it:

[3332 ms] * Fetching feature: llvm_0_oci
paths=devcontainer-feature.json, fn=(done) => this[CHECKFS2](entry, done)
paths=README.md, fn=(done) => this[CHECKFS2](entry, done)
paths=.gitattributes, fn=(done) => this[CHECKFS2](entry, done)
paths=test.sh, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/workflows/, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/workflows/test-feature.yml, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/workflows/publish-feature.yml, fn=(done) => this[CHECKFS2](entry, done)
paths=install.sh, fn=(done) => this[CHECKFS2](entry, done)
paths=LICENSE, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/workflows/, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/workflows/test-feature.yml,.github/workflows/test-feature.yml, fn=(done) => this[CHECKFS2](entry, done)
paths=.github/workflows/publish-feature.yml,.github/workflows/publish-feature.yml, fn=(done) => this[CHECKFS2](entry, done)

fn is always defined. Something weird is going on there.

[0xE1E10]

Did some more debugging.

At the time of the crash, queue has 3 elements:

{".github" => Set(fn)}
{".github/workflows" => Set(fn)}
{".github/workflows/publish-feature.yml" => [fn, fn]}

The first 2 are for the dir case. The last for the path case.

This is how we get the paths and dirs:

      const getQueues = (fn) => {
        const res = reservations.get(fn);
        if (!res) {
          throw new Error("function does not have any path reservations");
        }
        return {
          paths: res.paths.map((path33) => queues.get(path33)),
          dirs: [...res.dirs].map((path33) => queues.get(path33))
        };
      };

Looking thru reservations, I see one suspicious candidate .github/workflows/test-feature.yml. It's not currently in queues. queues.get() would return undefined and get us in trouble.

[0xE1E10]

Wait a sec. We added this entry in the beginning:

paths=.github/workflows/test-feature.yml,.github/workflows/test-feature.yml, fn=(done) => this[CHECKFS2](entry, done)

The same path is duplicated. This is run():

      const run = (fn) => {
        if (running.has(fn) || !check(fn)) {
          return false;
        }
        running.add(fn);
        fn(() => clear(fn));
        return true;
      };

When we're done, we call clear(), which removes the path from queues. If we try to run() that second copy of the same path, it will give us paths == [undefined, undefined].

[0xE1E10]

The tarball contains a hard link to itself for that file because some implementations of tar does not de-duplicate files specified multiple times indirectly thru parent directories.

❯ curl 'https://ghcr.io/token?scope=repository:devcontainers-community/features/llvm:pull'
{"token":"djE6ZGV2Y29udGFpbmVycy1jb21tdW5pdHkvZmVhdHVyZXMvbGx2bToxNzAyNjAxODI2NTQ4MTU0Nzc5"}

❯ curl -H "Authorization: Bearer djE6ZGV2Y29udGFpbmVycy1jb21tdW5pdHkvZmVhdHVyZXMvbGx2bToxNzAyNjAxODI2NTQ4MTU0Nzc5" -H "Accept: application/vnd.oci.image.manifest.v1+json" https://ghcr.io/v2/devcontainers-community/features/llvm/manifests/latest | jq
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100   953  100   953    0     0    551      0  0:00:01  0:00:01 --:--:--   550
{
  "schemaVersion": 2,
  "mediaType": "application/vnd.oci.image.manifest.v1+json",
  "config": {
    "mediaType": "application/vnd.devcontainers",
    "digest": "sha256:e3b0c44298fc1c149afbf4c8996fb92427ae41e4649b934ca495991b7852b855",
    "size": 0
  },
  "layers": [
    {
      "mediaType": "application/vnd.devcontainers.layer.v1+tar",
      "digest": "sha256:784c76ebdff7e8430e5466ed78c041f756f0ec300efecf090bfda7f24a2a615a",
      "size": 20480,
      "annotations": {
        "org.opencontainers.image.title": "devcontainer-feature-llvm.tgz"
      }
    }
  ],
  "annotations": {
    "com.github.package.type": "devcontainer_feature",
    "dev.containers.metadata": "{\"id\":\"llvm\",\"version\":\"3.0.0\",\"name\":\"llvm\",\"documentationURL\":\"https://github.com/devcontainers-community/features-llvm\",\"description\":\"Installs llvm on debian based systems\",\"options\":{},\"mounts\":[],\"installsAfter\":[\"ghcr.io/devcontainers/features/common-utils\"]}",
    "org.opencontainers.image.created": "2023-08-16T06:15:24Z",
    "org.opencontainers.image.source": ""
  }
}

❯ curl -L -H "Authorization: Bearer djE6ZGV2Y29udGFpbmVycy1jb21tdW5pdHkvZmVhdHVyZXMvbGx2bToxNzAyNjAxODI2NTQ4MTU0Nzc5" -H "Accept: */*" 'https://ghcr.io/v2/devcontainers-community/features/llvm/blobs/sha256:784c76ebdff7e8430e5466ed78c041f756f0ec300efecf090bfda7f24a2a615a' -o features-llvm.tar

❯ tar --list -v -f features-llvm.tar
-rw-r--r-- runner/docker   322 2023-08-15 23:15 devcontainer-feature.json
-rw-r--r-- runner/docker   486 2023-08-15 23:15 README.md
-rw-r--r-- runner/docker    51 2023-08-15 23:15 .gitattributes
-rw-r--r-- runner/docker   630 2023-08-15 23:15 test.sh
drwxr-xr-x runner/docker     0 2023-08-15 23:15 .github/
drwxr-xr-x runner/docker     0 2023-08-15 23:15 .github/workflows/
-rw-r--r-- runner/docker   879 2023-08-15 23:15 .github/workflows/test-feature.yml
-rw-r--r-- runner/docker   554 2023-08-15 23:15 .github/workflows/publish-feature.yml
-rw-r--r-- runner/docker   282 2023-08-15 23:15 install.sh
-rw-r--r-- runner/docker  1066 2023-08-15 23:15 LICENSE
drwxr-xr-x runner/docker     0 2023-08-15 23:15 .github/workflows/
hrw-r--r-- runner/docker     0 2023-08-15 23:15 .github/workflows/test-feature.yml link to .github/workflows/test-feature.yml
hrw-r--r-- runner/docker     0 2023-08-15 23:15 .github/workflows/publish-feature.yml link to .github/workflows/publish-feature.yml
hrw-r--r-- runner/docker     0 2023-08-15 23:15 .github/workflows/publish-feature.yml link to .github/workflows/publish-feature.yml
hrw-r--r-- runner/docker     0 2023-08-15 23:15 .github/workflows/test-feature.yml link to .github/workflows/test-feature.yml

This happens if a file is specified multiple times indirectly by the directory when it is created. https://github.com/libarchive/libarchive/issues/1381#issuecomment-635066671 Apparently both GNU tar and libarchive just ignore this kind of silly links instead of fixing the problem. It's stupid but might want to do the same for compatibility.