Is nix 2.4 significantly slower?

pennae · November 23, 2021, 8:14am

as part of our (ultimately failed) attempts at making system rebuilds faster we’ve also run performance comparisons of nix 2.3.16 and nix 2.4 on the same task, and noticed that nix 2.4 takes significantly longer (~7.8s vs ~9.3s). we’ve run basic system builds using our current configuration (nix-build ./nixos -A system) in an recent(ish) checkout of nixpkgs (15e5f8ba8ea99e41414c3e47e495769265b63d60). the same happens with a more minimal config, though to a lesser degree (~2.7s vs ~3.2s). increasing the GC heap size to 4G does not seem to have a measurable effect.

can anyone confirm, or tell us where we’re holding it wrong?

test script and results

% git show --oneline 
15e5f8ba8ea (HEAD -> master, origin/master, origin/HEAD) Merge pull request #146305 from Ptival/coq-bits-1.1.0
% nix --version
nix (Nix) 2.3.16
% for i in {1..5}; do time nix-build ./nixos -A system >/dev/null; done                         
nix-build ./nixos -A system > /dev/null  6.45s user 0.58s system 92% cpu 7.631 total
nix-build ./nixos -A system > /dev/null  6.74s user 0.56s system 92% cpu 7.918 total
nix-build ./nixos -A system > /dev/null  6.57s user 0.54s system 91% cpu 7.731 total
nix-build ./nixos -A system > /dev/null  6.94s user 0.56s system 91% cpu 8.179 total
nix-build ./nixos -A system > /dev/null  6.56s user 0.52s system 92% cpu 7.677 total
% nix run nixpkgs.nix_2_4 -c zsh -c 'nix --version; for i in {1..5}; do time nix-build ./nixos -A system >/dev/null; done'
nix (Nix) 2.4
nix-build ./nixos -A system > /dev/null  8.06s user 0.69s system 91% cpu 9.550 total
nix-build ./nixos -A system > /dev/null  7.55s user 0.72s system 89% cpu 9.228 total
nix-build ./nixos -A system > /dev/null  7.72s user 0.66s system 91% cpu 9.161 total
nix-build ./nixos -A system > /dev/null  8.08s user 0.70s system 90% cpu 9.736 total
nix-build ./nixos -A system > /dev/null  7.63s user 0.70s system 89% cpu 9.331 total
% for i in {1..5}; do time GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system >/dev/null; done
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  5.17s user 0.69s system 89% cpu 6.527 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  5.47s user 0.68s system 90% cpu 6.831 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  5.35s user 0.72s system 90% cpu 6.711 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  5.42s user 0.72s system 89% cpu 6.822 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  5.35s user 0.71s system 89% cpu 6.743 total
% nix run nixpkgs.nix_2_4 -c zsh -c 'nix --version; for i in {1..5}; do time GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system >/dev/null; done'
nix (Nix) 2.4
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  6.26s user 0.86s system 87% cpu 8.152 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  6.31s user 0.85s system 87% cpu 8.187 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  6.40s user 0.92s system 87% cpu 8.363 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  6.46s user 0.90s system 87% cpu 8.383 total
GC_INITIAL_HEAP_SIZE=4G nix-build ./nixos -A system > /dev/null  6.24s user 0.85s system 87% cpu 8.139 total
% cat /tmp/configuration.nix
{
  boot.isContainer = true;
  time.timeZone = "Europe/Berlin";
  networking.useDHCP = false;
  networking.hostName = "test";
  services = {
    xserver = {
      enable = true;
      displayManager.sx.enable = true;
      windowManager.i3.enable = true;
    };
  };
  sound.enable = true;
}
% for i in {1..5}; do time nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system >/dev/null; done
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.26s user 0.26s system 91% cpu 2.762 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.06s user 0.25s system 90% cpu 2.546 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.05s user 0.25s system 90% cpu 2.542 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.28s user 0.27s system 91% cpu 2.775 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  1.99s user 0.25s system 90% cpu 2.467 total
% nix run nixpkgs.nix_2_4 -c zsh -c 'nix --version; for i in {1..5}; do time nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system >/dev/null; done' 
nix (Nix) 2.4
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.49s user 0.31s system 87% cpu 3.204 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.57s user 0.32s system 87% cpu 3.285 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.50s user 0.34s system 87% cpu 3.229 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.52s user 0.32s system 87% cpu 3.243 total
nix-build ./nixos -I nixos-config=/tmp/configuration.nix -A system > /dev/nul  2.54s user 0.31s system 88% cpu 3.234 total

pennae · November 23, 2021, 10:16am

digging through the nix issue list a bit we found Decreased evaluation performance in newer versions · Issue #4847 · NixOS/nix · GitHub, but that hasn’t seen any activity since may

asymmetric · November 23, 2021, 3:53pm

This issue could also be relevant.

bew · November 23, 2021, 5:44pm

There is no flakes involved here as far as I see, so that issue shouldn’t be related to the slowdowns you see.

asymmetric · November 23, 2021, 6:06pm

Hm, I thought the issue might be caused by the new nix commands, rather than something specific in the handling of flakes, but it was just a wild guess.

nixinator · November 23, 2021, 6:48pm

i like that script, should be in the nixos test suite! … however, there’s probably something like it lurking there!

colemickens · November 23, 2021, 6:51pm

On top of this, I don’t think caching even works right. I can eval .#thing.drvPath and wait 12 seconds and then turn around and eval .#thing.outPath and wait the entire 12 seconds all over again. I remember a time (or even sporadic times) when it felt like caching worked, but … I’m back to doing things like evaluating, capturing JSON, and then running jq over the json blob to avoid double eval costs. Which… I’m not thrilled about.

knedlsepp · November 23, 2021, 7:18pm

I’m assuming this is also the cause of a few bumps in the metrics job Hydra - nixos:trunk-combined:nixpkgs.metrics around November 15th.

vcunat · November 24, 2021, 11:33am

I think that would rather be due to running on a different machine: Revert "metrics: drop requiredSystemFeatures; /cc #76776" · NixOS/nixpkgs@30e1b0b · GitHub

nrdxp · November 24, 2021, 5:42pm

I’ve been thinking lately, that we probably shouldn’t have a turing complete package fetching mechanism. Thinking on that for a while now, I think it would be possible to build some sort of traditional index after a full evaluation of nixpkgs, or any flake really, and nix could have a step, before evaluation, where it searches this index, which would be much like a local package index used by other popular Linux package managers, and if it hits, we just pull the package directly, avoiding the evaluation phase all together. It should be simple enough to map from: commit of flake repo → hashes of packages it exports.

This opens up new possibilities which could help to mitigate its potentially biggest downside, i.e. index corruption. If we have a way to grab packages without evaluation, then we could actually include the eval cache as part of a packages derivation, or perhaps as a partner derivation, to avoid infinite recursion. That way, we could easily verify the evaluation using Nix’s already existing codepaths.

If the evaluation doesn’t match, we miss the cache, leading to a much earlier indicator of some sort of corruption without having to complete eval. Just an idea though, whatever we decide to do, I feel it would be wise to reduce the runtime complexity of fetching from substituters as much as possible.