nix-build is copying files from store to store #711

New issue

Open

opened 2025-03-02 17:58:30 +00:00 by pr2502 · 4 comments

pr2502 commented

2025-03-02 17:58:30 +00:00

Describe the bug

nix-build, (and nix-instantiate --eval too) is logging copying '/nix/store/91vybbg..snip' to the store, implying that it's copying files from the store to the store which seems wrong? unexpected at least. running the same command with nixVersions.stable logs hashing '/nix/store/91vybbg..snip' and takes very comparable time to evaluate, so this might be only a UI issue and i'm being concerned over nothing?

Steps To Reproduce

$ nix-instantiate --log-format internal-json --eval --expr '(import <nixpkgs> {}).hello' >/dev/null

@nix {"action":"msg","level":3,"msg":"fetching path input 'path:/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source'"}
@nix {"action":"start","id":3948737097367552,"level":4,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source'","type":0}
@nix {"action":"stop","id":3948737097367552}
@nix {"action":"start","id":3948737097367553,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh' to the store","type":0}
@nix {"action":"stop","id":3948737097367553}
@nix {"action":"start","id":3948737097367554,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/default-builder.sh' to the store","type":0}
@nix {"action":"stop","id":3948737097367554}
@nix {"action":"start","id":3948737097367555,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/linux/bootstrap-tools/glibc/unpack-bootstrap-tools.sh' to the store","type":0}
@nix {"action":"stop","id":3948737097367555}
@nix {"action":"start","id":3948737097367556,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/builder.sh' to the store","type":0}
...snip...

(the same message is logged for every touched file in nixpkgs)

Comparison to CppNix

I'm not actually sure if there is a difference in behaviour or just the log message but the same steps for nix (Nix) 2.24.12 (nixVersions.stable from nixpkgs) produce

@nix {"action":"start","fields":["https://channels.nixos.org/flake-registry.json"],"id":3949497306578944,"level":4,"parent":0,"text":"downloading 'https://channels.nixos.org/flake-registry.json'","type":101}
@nix {"action":"result","fields":[0,0,0,0],"id":3949497306578944,"type":105}
...snip downloading flake-registry.json for CppNix reasons, i have channels disabled...
@nix {"action":"result","fields":[684,684,0,0],"id":3949497306578944,"type":105}
@nix {"action":"stop","id":3949497306578944}
@nix {"action":"start","id":3949497306578945,"level":4,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source'","type":0}
@nix {"action":"stop","id":3949497306578945}
@nix {"action":"start","id":3949497306578946,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/' to the store","type":0}
@nix {"action":"stop","id":3949497306578946}
@nix {"action":"start","id":3949497306578947,"level":5,"parent":0,"text":"hashing '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh'","type":0}
@nix {"action":"stop","id":3949497306578947}
@nix {"action":"start","id":3949497306578948,"level":5,"parent":0,"text":"hashing '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/default-builder.sh'","type":0}
...snip...

`nix --version` output

nix (Lix, like Nix) 2.93.0-dev-pre20250301-20fea96 but nothing changes with nix (Lix, like Nix) 2.91.1 either

## Describe the bug nix-build, (and nix-instantiate --eval too) is logging `copying '/nix/store/91vybbg..snip' to the store`, implying that it's copying files from the store to the store which seems wrong? unexpected at least. running the same command with `nixVersions.stable` logs `hashing '/nix/store/91vybbg..snip'` and takes very comparable time to evaluate, so this might be only a UI issue and i'm being concerned over nothing? ## Steps To Reproduce ``` $ nix-instantiate --log-format internal-json --eval --expr '(import <nixpkgs> {}).hello' >/dev/null @nix {"action":"msg","level":3,"msg":"fetching path input 'path:/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source'"} @nix {"action":"start","id":3948737097367552,"level":4,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source'","type":0} @nix {"action":"stop","id":3948737097367552} @nix {"action":"start","id":3948737097367553,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh' to the store","type":0} @nix {"action":"stop","id":3948737097367553} @nix {"action":"start","id":3948737097367554,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/default-builder.sh' to the store","type":0} @nix {"action":"stop","id":3948737097367554} @nix {"action":"start","id":3948737097367555,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/linux/bootstrap-tools/glibc/unpack-bootstrap-tools.sh' to the store","type":0} @nix {"action":"stop","id":3948737097367555} @nix {"action":"start","id":3948737097367556,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/builder.sh' to the store","type":0} ...snip... ``` (the same message is logged for every touched file in nixpkgs) ## Comparison to CppNix I'm not actually sure if there is a difference in behaviour or just the log message but the same steps for `nix (Nix) 2.24.12` (`nixVersions.stable` from nixpkgs) produce ``` @nix {"action":"start","fields":["https://channels.nixos.org/flake-registry.json"],"id":3949497306578944,"level":4,"parent":0,"text":"downloading 'https://channels.nixos.org/flake-registry.json'","type":101} @nix {"action":"result","fields":[0,0,0,0],"id":3949497306578944,"type":105} ...snip downloading flake-registry.json for CppNix reasons, i have channels disabled... @nix {"action":"result","fields":[684,684,0,0],"id":3949497306578944,"type":105} @nix {"action":"stop","id":3949497306578944} @nix {"action":"start","id":3949497306578945,"level":4,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source'","type":0} @nix {"action":"stop","id":3949497306578945} @nix {"action":"start","id":3949497306578946,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/' to the store","type":0} @nix {"action":"stop","id":3949497306578946} @nix {"action":"start","id":3949497306578947,"level":5,"parent":0,"text":"hashing '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh'","type":0} @nix {"action":"stop","id":3949497306578947} @nix {"action":"start","id":3949497306578948,"level":5,"parent":0,"text":"hashing '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/default-builder.sh'","type":0} ...snip... ``` ## `nix --version` output `nix (Lix, like Nix) 2.93.0-dev-pre20250301-20fea96` but nothing changes with `nix (Lix, like Nix) 2.91.1` either

pr2502 added the

bug

label

2025-03-02 17:58:30 +00:00

pr2502 commented

2025-03-02 18:04:18 +00:00

Author

It should not be related to https://github.com/NixOS/nix/issues/11228#issuecomment-2261087599 since the path it's copying from is called store 😅

It should not be related to <https://github.com/NixOS/nix/issues/11228#issuecomment-2261087599> since the path it's copying from is called `store` 😅

pennae commented

2025-03-02 18:19:19 +00:00

Owner

that's a side effect of how nixos implements flake-based search paths: <nixpkgs> is not an absolute path but a flake reference, and that reference must pass through the fetcher infrastructure before the evaluator can use it. this fetching is harmless when the path is already present, but it does happen and is logged accordingly. if the flake reference weren't for a path in the store you'd see that flakeref as being fetched:

❯  nix eval --tarball-ttl 0 --override-flake nixpkgs github:nixos/nixpkgs --log-format internal-json --impure --expr '(import <nixpkgs> {}).hello' >/dev/null
...
@nix {"action":"start","fields":["https://api.github.com/repos/nixos/nixpkgs/commits/HEAD"],"id":329187768401920,"level":4,"parent":0,"text":"downloading 'https://api.github.com/repos/nixos/nixpkgs/commits/HEAD'","type":101}

cppnix must do the same thing, only difference may be that it doesn't log anything while fetching a store path as a flake. it seems that it does log the same things though, at least on 2.24 from nixpkgs

that's a side effect of how nixos implements flake-based search paths: `<nixpkgs>` is not an absolute path but a flake reference, and that reference must pass through the fetcher infrastructure before the evaluator can use it. this fetching is harmless when the path is already present, but it does happen and is logged accordingly. if the flake reference weren't for a path in the store you'd see that flakeref as being fetched: ``` ❯ nix eval --tarball-ttl 0 --override-flake nixpkgs github:nixos/nixpkgs --log-format internal-json --impure --expr '(import <nixpkgs> {}).hello' >/dev/null ... @nix {"action":"start","fields":["https://api.github.com/repos/nixos/nixpkgs/commits/HEAD"],"id":329187768401920,"level":4,"parent":0,"text":"downloading 'https://api.github.com/repos/nixos/nixpkgs/commits/HEAD'","type":101} ``` cppnix must do the same thing, only difference may be that it doesn't log anything while fetching a store path as a flake. it seems that it does log the same things though, at least on 2.24 from nixpkgs

pr2502 commented

2025-03-02 19:40:13 +00:00

Author

aha, sorry, i've tried simplifying the reproducer until i've changed it into something else. i've first noticed this with a npins repository where i don't use the <nixpkgs> syntax at all.

i've tried making a smaller reproducer that avoids nixpkgs completely, i still get a (one) log line about copying a file to the store that is already present in the store before the nix-build command is run.

instead of nixpkgs i've made a trivial derivation which depends on a single file (it doesn't work but that doesn't matter, the log line still appears).

$ npins show
test1: (git repository)
    repository: https://git.p2502.net/max/test1.git
    branch: main
    submodules: false
    revision: 5027e6d343003c78499540d0c7433466383734b4
    hash: 0j61kci1y0rcim2y28lg2c26hy1y7czfy22k4v36in02xmsxjkra

$ cat test.nix 
let
  sources = import ./npins;
  test1 = import "${sources.test1}/foo.nix";
in
  test1

$ nix-build --log-format internal-json test.nix
@nix {"action":"msg","level":3,"msg":"fetching git input 'git+https://git.p2502.net/max/test1.git'"}
@nix {"action":"start","id":4023241895051264,"level":5,"parent":0,"text":"copying '/nix/store/4qnlr2dm1cjin934miprpdd27zlgmzgp-test1.git-5027e6d/build.sh' to the store","type":0}
@nix {"action":"stop","id":4023241895051264}
@nix {"action":"start","id":4023250484985856,"level":6,"parent":0,"text":"querying info about missing paths","type":0}
@nix {"action":"stop","id":4023250484985856}
@nix {"action":"msg","level":3,"msg":"this derivation will be built:"}
@nix {"action":"msg","level":3,"msg":"  /nix/store/aflrq3x5jrfgfigh1ligwxk3x3qpp1vv-foo.drv"}
...snip...

and i'm sorry i probably didn't write it clearly which log lines i'm surprised by. here it's the

@nix {"action":"start","id":4023241895051264,"level":5,"parent":0,"text":"copying '/nix/store/4qnlr2dm1cjin934miprpdd27zlgmzgp-test1.git-5027e6d/build.sh' to the store","type":0}

in the description it was this for lix

@nix {"action":"start","id":3948737097367553,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh' to the store","type":0}

replaced by this for cppnix

@nix {"action":"start","id":3949497306578947,"level":5,"parent":0,"text":"hashing '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh'","type":0}

aha, sorry, i've tried simplifying the reproducer until i've changed it into something else. i've first noticed this with a npins repository where i don't use the `<nixpkgs>` syntax at all. i've tried making a smaller reproducer that avoids nixpkgs completely, i still get a (one) log line about copying a file to the store that is already present in the store before the nix-build command is run. instead of nixpkgs i've made a trivial derivation which depends on a single file (it doesn't work but that doesn't matter, the log line still appears). ``` $ npins show test1: (git repository) repository: https://git.p2502.net/max/test1.git branch: main submodules: false revision: 5027e6d343003c78499540d0c7433466383734b4 hash: 0j61kci1y0rcim2y28lg2c26hy1y7czfy22k4v36in02xmsxjkra $ cat test.nix let sources = import ./npins; test1 = import "${sources.test1}/foo.nix"; in test1 $ nix-build --log-format internal-json test.nix @nix {"action":"msg","level":3,"msg":"fetching git input 'git+https://git.p2502.net/max/test1.git'"} @nix {"action":"start","id":4023241895051264,"level":5,"parent":0,"text":"copying '/nix/store/4qnlr2dm1cjin934miprpdd27zlgmzgp-test1.git-5027e6d/build.sh' to the store","type":0} @nix {"action":"stop","id":4023241895051264} @nix {"action":"start","id":4023250484985856,"level":6,"parent":0,"text":"querying info about missing paths","type":0} @nix {"action":"stop","id":4023250484985856} @nix {"action":"msg","level":3,"msg":"this derivation will be built:"} @nix {"action":"msg","level":3,"msg":" /nix/store/aflrq3x5jrfgfigh1ligwxk3x3qpp1vv-foo.drv"} ...snip... ``` and i'm sorry i probably didn't write it clearly which log lines i'm surprised by. here it's the ``` @nix {"action":"start","id":4023241895051264,"level":5,"parent":0,"text":"copying '/nix/store/4qnlr2dm1cjin934miprpdd27zlgmzgp-test1.git-5027e6d/build.sh' to the store","type":0} ``` in the description it was this for lix ``` @nix {"action":"start","id":3948737097367553,"level":5,"parent":0,"text":"copying '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh' to the store","type":0} ``` replaced by this for cppnix ``` @nix {"action":"start","id":3949497306578947,"level":5,"parent":0,"text":"hashing '/nix/store/mipgp0fr3zlcihi4x7xb67v47yfxwcwh-source/pkgs/stdenv/generic/source-stdenv.sh'","type":0} ```

pennae commented

2025-03-02 20:19:24 +00:00

Owner

ah, i see now. yeah, that message is unfortunate and could definitely be improved. we can't really do much about it in the near term though due to how the code that reads things is structured :(