python3 on macOS explodes

[dwt]

What happened?

When trying out python, I get this error:

❯ devbox shell
Info: Ensuring packages are installed.
✓ Computed the Devbox environment.
Error: nix: command error: nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' print-dev-env --json path:/Users/dwt/Code/Projekte/nix/devbox/.devbox/gen/flake: 1 dependencies of derivation '/nix/store/4iz1ykjv5jai03bd1iy29mwz3165n5k7-nix-shell-env.drv' failed to build: exit code 1

Error: There was an internal error. Run with DEVBOX_DEBUG=1 for a detailed error message, and consider reporting it at https://github.com/jetify-com/devbox/issues

Steps to reproduce

1. devbox init
2. devbox add python
3. devbox shell

Command

shell

devbox.json

{
  "$schema":  "https://raw.githubusercontent.com/jetify-com/devbox/0.13.0/.schema/devbox.schema.json",
  "packages": ["python@latest"],
  "shell": {
    "init_hook": ["echo 'Welcome to devbox!' > /dev/null"],
    "scripts": {
      "test": ["echo \"Error: no test specified\" && exit 1"]
    }
  }
}

Devbox version

0.13.0

Nix version

nix (Lix, like Nix) 2.91.0

What system does this bug occur on?

macOS (Apple Silicon)

Debug logs

❯ DEVBOX_DEBUG=1 devbox shell
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:125 msg="searching for config file (including parent directories)" path=.
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=devbox.json
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:133 msg="config file found" path=/Users/dwt/Code/Projekte/nix/devbox/devbox.json dur=325.458µs
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:125 msg="searching for config file (including parent directories)" path=.
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=devbox.json
time=2024-10-02T22:26:37.144+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:133 msg="config file found" path=/Users/dwt/Code/Projekte/nix/devbox/devbox.json dur=59.209µs
time=2024-10-02T22:26:37.145+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.191+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/nix.go:337 msg="nix --version --debug output" out="nix (Lix, like Nix) 2.91.0\nSystem type: aarch64-darwin\nAdditional system types: x86_64-darwin\nFeatures: gc, signed-caches\nSystem configuration file: /etc/nix/nix.conf\nUser configuration files: /Users/dwt/.config/nix/nix.conf:/etc/xdg/nix/nix.conf\nStore directory: /nix/store\nState directory: /nix/var/nix\nData directory: /nix/store/93ni93d5g2v62kz9a0v3cwn5p0qrq8nl-lix-2.91.0/share\n"
time=2024-10-02T22:26:37.191+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/command.go:60 msg="nix command starting" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' eval --impure --raw --expr builtins.currentSystem" cmd.path=/nix/var/nix/profiles/default/bin/nix
time=2024-10-02T22:26:37.225+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/command.go:67 msg="nix command exited" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' eval --impure --raw --expr builtins.currentSystem" cmd.path=/nix/var/nix/profiles/default/bin/nix cmd.pid=33484 cmd.code=0 cmd.dur=33.563666ms
time=2024-10-02T22:26:37.225+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:125 msg="searching for config file (including parent directories)" path=.
time=2024-10-02T22:26:37.225+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=devbox.json
time=2024-10-02T22:26:37.225+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:133 msg="config file found" path=/Users/dwt/Code/Projekte/nix/devbox/devbox.json dur=98.042µs
time=2024-10-02T22:26:37.225+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.225+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.226+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
Info: Ensuring packages are installed.
time=2024-10-02T22:26:37.227+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/plugin/plugin.go:85 msg="creating files for package" pkg=python@latest
time=2024-10-02T22:26:37.227+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/plugin/plugin.go:128 msg="Creating file %q from contentPath: %q" /Users/dwt/Code/Projekte/nix/devbox/.devbox/virtenv/python/bin/venvShellHook.sh=python/venvShellHook.sh
time=2024-10-02T22:26:37.228+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.228+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/command.go:60 msg="nix command starting" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' path-info --offline --json /nix/store/9pj4rzx5pbynkkxq1srzwjhywmcfxws3-python3-3.12.5" cmd.path=/nix/var/nix/profiles/default/bin/nix
time=2024-10-02T22:26:37.266+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/command.go:67 msg="nix command exited" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' path-info --offline --json /nix/store/9pj4rzx5pbynkkxq1srzwjhywmcfxws3-python3-3.12.5" cmd.path=/nix/var/nix/profiles/default/bin/nix cmd.pid=33486 cmd.code=0 cmd.dur=37.930792ms
time=2024-10-02T22:26:37.266+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.266+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/plugin/plugin.go:85 msg="creating files for package" pkg=python3
time=2024-10-02T22:26:37.266+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/plugin/plugin.go:128 msg="Creating file %q from contentPath: %q" /Users/dwt/Code/Projekte/nix/devbox/.devbox/virtenv/python/bin/venvShellHook.sh=python/venvShellHook.sh
time=2024-10-02T22:26:37.266+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto
time=2024-10-02T22:26:37.267+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/nix.go:80 msg="running print-dev-env cmd" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' print-dev-env --json path:/Users/dwt/Code/Projekte/nix/devbox/.devbox/gen/flake"
⣾ Computing the Devbox environment...
time=2024-10-02T22:26:37.267+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/command.go:60 msg="nix command starting" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' print-dev-env --json path:/Users/dwt/Code/Projekte/nix/devbox/.devb⢿ Computing the Devbox environment...
time=2024-10-02T22:26:37.629+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/nix/command.go:67 msg="nix command exited" cmd.args="nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' print-dev-env --json path:/Users/dwt/Code/Projekte/nix/devbox/.devbox/gen/flake" cmd.path=/nix/var/nix/profiles/default/bin/nix cmd.stderr="1 dependencies of derivation '/nix/store/4iz1ykjv5jai03bd1iy29mwz3165n5k7-nix-shell-env.drv' failed to build" cmd.pid=33489 cmd.code=1 cmd.dur=✓ Computed the Devbox environment.
Error: nix: command error: nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' print-dev-env --json path:/Users/dwt/Code/Projekte/nix/devbox/.devbox/gen/flake: 1 dependencies of derivation '/nix/store/4iz1ykjv5jai03bd1iy29mwz3165n5k7-nix-shell-env.drv' failed to build: exit code 1

time=2024-10-02T22:26:37.629+02:00 level=ERROR source=go.jetpack.io/devbox/internal/boxcli/midcobra/debug.go:68 msg="command error" stderr="fetching path input 'path:/Users/dwt/Code/Projekte/nix/devbox/.devbox/gen/flake'\nbuilding '/nix/store/dkcrgq9bpxdh81lgln217b6z4knwpsaa-python3-3.12.5.drv'...\nerror: builder for '/nix/store/dkcrgq9bpxdh81lgln217b6z4knwpsaa-python3-3.12.5.drv' failed with exit code 1;\n last 25 log lines:\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:108 msg="trying config file" path=.\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/private/tmp/devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/private/devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=ERROR source=go.jetpack.io/devbox/internal/devconfig/config.go:135 msg="config file search error" err="no devbox config file found" dur=93.75µs\n > time=2024-10-02T22:26:37.620+02:00 level=ERROR source=go.jetpack.io/devbox/internal/boxcli/run.go:79 msg="failed to open devbox" err="no devbox.json found in the current directory (or any parent directories). Did you run devbox init yet?\ngo.jetpack.io/devbox/internal/boxcli/usererr.New\n\tgo.jetpack.io/devbox/internal/boxcli/usererr/usererr.go:30\ngo.jetpack.io/devbox/internal/devbox.Open\n\tgo.jetpack.io/devbox/internal/devbox/devbox.go:84\ngo.jetpack.io/devbox/internal/boxcli.listScripts\n\tgo.jetpack.io/devbox/internal/boxcli/run.go:72\ngo.jetpack.io/devbox/internal/boxcli.runCmd\n\tgo.jetpack.io/devbox/internal/boxcli/run.go:66\ngo.jetpack.io/devbox/internal/boxcli.globalCmd\n\tgo.jetpack.io/devbox/internal/boxcli/global.go:37\ngo.jetpack.io/devbox/internal/boxcli.RootCmd\n\tgo.jetpack.io/devbox/internal/boxcli/root.go:66\ngo.jetpack.io/devbox/internal/boxcli.Execute\n\tgo.jetpack.io/devbox/internal/boxcli/root.go:111\ngo.jetpack.io/devbox/internal/boxcli.Main\n\tgo.jetpack.io/devbox/internal/boxcli/root.go:139\nmain.main\n\tgo.jetpack.io/devbox/cmd/devbox/main.go:11\nruntime.main\n\truntime/proc.go:272\nruntime.goexit\n\truntime/asm_arm64.s:1223"\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:125 msg="searching for config file (including parent directories)" path=.\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:108 msg="trying config file" path=.\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/private/tmp/devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/private/devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/devbox.json\n > time=2024-10-02T22:26:37.620+02:00 level=ERROR source=go.jetpack.io/devbox/internal/devconfig/config.go:135 msg="config file search error" err="no devbox config file found" dur=37.25µs\n > time=2024-10-02T22:26:37.620+02:00 level=ERROR source=go.jetpack.io/devbox/internal/boxcli/run.go:79 msg="failed to open devbox" err="no devbox.json found in the current directory (or any parent directories). Did you run devbox init yet?\ngo.jetpack.io/devbox/internal/boxcli/usererr.New\n\tgo.jetpack.io/devbox/internal/boxcli/usererr/usererr.go:30\ngo.jetpack.io/devbox/internal/devbox.Open\n\tgo.jetpack.io/devbox/internal/devbox/devbox.go:84\ngo.jetpack.io/devbox/internal/boxcli.listScripts\n\tgo.jetpack.io/devbox/internal/boxcli/run.go:72\ngo.jetpack.io/devbox/internal/boxcli.runCmd\n\tgo.jetpack.io/devbox/internal/boxcli/run.go:66\ngo.jetpack.io/devbox/internal/boxcli.RootCmd\n\tgo.jetpack.io/devbox/internal/boxcli/root.go:75\ngo.jetpack.io/devbox/internal/boxcli.Execute\n\tgo.jetpack.io/devbox/internal/boxcli/root.go:111\ngo.jetpack.io/devbox/internal/boxcli.Main\n\tgo.jetpack.io/devbox/internal/boxcli/root.go:139\nmain.main\n\tgo.jetpack.io/devbox/cmd/devbox/main.go:11\nruntime.main\n\truntime/proc.go:272\nruntime.goexit\n\truntime/asm_arm64.s:1223"\n > time=2024-10-02T22:26:37.620+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/patchpkg/builder.go:92 msg="starting build to patch package" pkg=/nix/store/9pj4rzx5pbynkkxq1srzwjhywmcfxws3-python3-3.12.5 glibc="" out=/nix/store/zsdnh5swlzwmx5642qy0lqqhwiqsvn00-python3-3.12.5\n > Error: can't find hash to restore store path reference "eeeeeeeeeeeeeeeeeeeeeeeeeeeeeeee-llvm-16.0.6" in "lib/python3.12/_sysconfigdata__darwin_darwin.py": regexp "[0123456789abcdfghijklmnpqrsvwxyz]{32}-llvm-16\\.0\\.6([$\"'{}/[\\] \\t\\r\\n]|$)" returned 0 matches\n >\n > time=2024-10-02T22:26:37.622+02:00 level=ERROR source=go.jetpack.io/devbox/internal/boxcli/midcobra/debug.go:70 msg="command error" execid=0f3d36c8ea8348caa2e9ff1271d259f9 stack=\n > time=2024-10-02T22:26:37.623+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:125 msg="searching for config file (including parent directories)" path=.\n > time=2024-10-02T22:26:37.623+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=devbox.json\n > time=2024-10-02T22:26:37.623+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:108 msg="trying config file" path=.\n > time=2024-10-02T22:26:37.623+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/private/tmp/devbox.json\n > time=2024-10-02T22:26:37.623+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/private/devbox.json\n > time=2024-10-02T22:26:37.623+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=/devbox.json\n > time=2024-10-02T22:26:37.623+02:00 level=ERROR source=go.jetpack.io/devbox/internal/devconfig/config.go:135 msg="config file search error" err="no devbox config file found" dur=35.875µs\n For full logs, run 'nix log /nix/store/dkcrgq9bpxdh81lgln217b6z4knwpsaa-python3-3.12.5.drv'.\nerror: 1 dependencies of derivation '/nix/store/4iz1ykjv5jai03bd1iy29mwz3165n5k7-nix-shell-env.drv' failed to build\n" execid=c711bbeb710e42a6820ca7e04e0f64ee stack=
time=2024-10-02T22:26:37.630+02:00 level=ERROR source=go.jetpack.io/devbox/internal/boxcli/midcobra/debug.go:70 msg="command error" execid=c711bbeb710e42a6820ca7e04e0f64ee stack=
time=2024-10-02T22:26:37.630+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:125 msg="searching for config file (including parent directories)" path=.
time=2024-10-02T22:26:37.630+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:146 msg="trying config file" path=devbox.json
time=2024-10-02T22:26:37.630+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devconfig/config.go:133 msg="config file found" path=/Users/dwt/Code/Projekte/nix/devbox/devbox.json dur=425.792µs
time=2024-10-02T22:26:37.630+02:00 level=DEBUG source=go.jetpack.io/devbox/internal/devpkg/package.go:200 msg="package needs patching" pkg=python mode=auto

~/C/Projekte/nix/devbox

[savil]

I wonder if there's some subtle difference from using Lix, instead of nix. @Lagoja have you ever tried devbox with Lix?

[Lagoja]

I tested with Lix on macOS, and was unable to reproduce this issue.

Looking into the errors some more, I think this might be related to issue #2293, which was resolved in Devbox 0.13.1. @dwt, can you confirm if this issue still happens in Devbox 0.13.3?

[SapphicCode]

Heya, I just stumbled across this one too, initially on Devbox 0.13.0. (also running nix (Lix, like Nix) 2.91.0)

I can confirm it was not fixed with Devbox 0.13.1. I've compiled and tested both 0.13.1 and 0.13.3 and it still occurs.

I've also manually run the command it complains about: nix --extra-experimental-features ca-derivations --option experimental-features 'nix-command flakes fetch-closure' print-dev-env --json path:<snip>/.devbox/gen/flake and here's the log for that: https://gist.github.com/SapphicCode/70a2b1ede2cf46ef307b3e8b7ae8c16a#file-error-log

[gcurtis]

@SapphicCode thanks for the detailed logs.

Could you try deleting the .devbox directory and re-running devbox shell? I'm wondering if this is caused by an old version of Devbox (in this case 0.13.0) being called in the flake build.

[SapphicCode]

@gcurtis You're right. 0.13.1 on a clean .devbox does indeed fix it. I should've thought of that 😅