Poor performance of `nix build --debugger`

[kjeremy]

Describe the bug

Adding --debugger to an invocation of nix build adds many minutes to a build. From the order of 30 seconds without the option to over 20 minutes on one of my flakes.

Steps To Reproduce

nix build .#blah --debugger

Expected behavior

I would expect that performance would be similar to a build without --debugger.

nix-env (Nix) 2.22.1

Additional context

Add any other context about the problem here.

Priorities

Add :+1: to issues you find important.

[fricklerhandwerk]

Triaged in Nix maintainers meeting:

• @roberth this concerns only the evaluator and maintains some extra data, the slowdown should not be more than 2x

@kjeremy could you please provide more detailed reproduction steps, it may pertain to your code.

[nixos-discourse]

This issue has been mentioned on NixOS Discourse. There might be relevant details there:

https://discourse.nixos.org/t/2024-05-29-nix-team-meeting-minutes-148/46195/1

[kjeremy]

@fricklerhandwerk That wouldn't surprise me. We have a flake that builds 60ish proprietary native packages and about 20+ cross-compiled nixos systems. I can't distribute any of it but I'll try to come up with some kind of representative example.

[kjeremy]

time nix run .#rosPackages.noetic.mrak_test_results_coverage --debug

gives

real 0m13.060s user 0m5.782s sys 0m1.896s

With --debugger

I'm running with --debugger --debug and noticing that the same things are being instantiated multiple times including the following two that I happened to Ctrl+C out of.

performing daemon worker op: 7
instantiated 'glibc-2.39.tar.xz' -> '/nix/store/gxv8zyycd4g400h51gfzpg0isk3b7qqd-glibc-2.39.tar.xz.drv'
performing daemon worker op: 7
instantiated 'glibc-2.39-52' -> '/nix/store/1whh7vxmcz14dym0h9453hpiqcw7lkcf-glibc-2.39-52.drv'

error: interrupted by the user

real	4m29.427s
user	3m42.872s
sys	0m21.521s

[mightyiam]

Yup super poor performance.

[ccdunder]

I'm getting hit by this as a result of the 24.11 nixpkgs release.

Nix 2.18 builds my systems in ~30 seconds. I gave up waiting after 20 minutes with Nix 2.24. Removing "--debugger" arg avoids the performance regression.

[szlend]

This regression makes the latest Nix pretty much unusable for me. I just tested a bunch of different nix versions and found that this was regressed in nix 2.21.

---

Edit: Actually it could also be in 2.22. I can't meaningfully test 2.21 because it's seemingly trying to copy my entire root to the /nix/store.

$ nix run nixpkgs#nixVersions.nix_2_21 -- eval nixpkgs#hello.outPath --no-eval-cache -vv
evaluating file '<nix/derivation-internal.nix>'
copying '/nix/store/4r8s42c9mwfvgdlxv0izb1cmlzrsb5nz-source'...
copying '/' to the store

Basically to reproduce (make sure to warm up):

# Normal
$ nix run nixpkgs#nixVersions.nix_2_20 -- eval nixpkgs#hello.outPath --no-eval-cache -vv --debugger --ignore-try

# Extremely slow
$ nix run nixpkgs#nixVersions.nix_2_22 -- eval nixpkgs#hello.outPath --no-eval-cache -vv --debugger --ignore-try

[ccdunder]

Thanks for providing a simple repro @szlend! I ran a bisect locally and narrowed it down to 5d9fdab3d.

Runtime of eval nixpkgs#hello.outPath --no-eval-cache -vv --ignore-try with --debugger vs. without: 5d9fdab3d: 73.38 sec / 0.82 sec 855fd5a1b (parent): 1.62 sec / 0.83 sec

[ccdunder]

As to the root cause, perhaps @pennae has insight?

My completely un-expert guess is that the cost added in that commit to calculate exact position info is being incurred when running with --debugger.

[simonzkl]

this concerns only the evaluator and maintains some extra data, the slowdown should not be more than 2x

The slowdown is more like 45x. Imo this should be labeled as a regression since it worked fine in 2.18 (regressed in 2.21). Right now --debugger is unusable in practice.