`resolvedResult.builtOutputs` doesn't contain expected output after successful multi-output build #6383

fogti · 2022-04-08T09:39:30Z

Describe the bug

Got the following error, but absolutely no information where exactly it occured (as-in no stacktrace or location info).
idk how to debug this.

openblas> patching script interpreter paths in /nix/store/fjkhb5vm7wdvs3piirjgvxd7gbpbq20b-openblas-0.3.20
openblas> checking for references to /build/ in /nix/store/fjkhb5vm7wdvs3piirjgvxd7gbpbq20b-openblas-0.3.20...
openblas> shrinking RPATHs of ELF executables and libraries in /nix/store/fqhw0blv04is1mc9r1ziqcgp9v4xc2s8-openblas-0.3.20-dev
openblas> strip is /nix/store/1kmkmwvs6d50z4jghnildm4cj3pzhvrq-gcc-wrapper-9.3.0/bin/strip
openblas> stripping (with command strip and flags -S) in /nix/store/fqhw0blv04is1mc9r1ziqcgp9v4xc2s8-openblas-0.3.20-dev/lib
openblas> patching script interpreter paths in /nix/store/fqhw0blv04is1mc9r1ziqcgp9v4xc2s8-openblas-0.3.20-dev
openblas> checking for references to /build/ in /nix/store/fqhw0blv04is1mc9r1ziqcgp9v4xc2s8-openblas-0.3.20-dev...
error: map::at

Steps To Reproduce

Unknown.

Expected behavior

The error should either not happen, or at least contain enough information to know where to start debugging, or a stacktrace...

nix-env --version output

nix-env (Nix) 2.8.0pre20220401_a24d077
but this might not be the version actually used, because this was hit when using nixos-rebuild, which first rebuilds itself.
the other rev involved is 8b1e328.
Also happens with nix-env (Nix) 2.8.0pre20220307_92b8d4d.
nix-env (Nix) 2.7.0pre20220225_df552ff: unable to test against, because it hits a known SIGBUS before gettings near this bug.

Additional context
experimental-features = nix-command ca-derivations flakes

The text was updated successfully, but these errors were encountered:

fogti · 2022-04-08T09:40:33Z

ok, when I rerun Nix, I hit this error every time...

# nixos-rebuild -v -L --show-trace --keep-going -j1 --cores 4 switch
$ nix build --out-link /tmp/nixos-rebuild.8KVZyL/nixos-rebuild /persist/home/zseri/devel/nixos-configs#nixosConfigurations."orca".config.system.build.nixos-rebuild -v -L --show-trace --keep-going -j1 --cores 4
$ exec /nix/store/3ky9qwk6ika2lqqp9b2gbkvmd3vc8fiw-nixos-rebuild/bin/nixos-rebuild -v -L --show-trace --keep-going -j1 --cores 4 switch
building the system configuration...
Building in flake mode.
$ nix build /persist/home/zseri/devel/nixos-configs#nixosConfigurations."orca".config.system.build.toplevel -v -L --show-trace --keep-going -j1 --cores 4 --out-link /tmp/nixos-rebuild.vsZ0hZ/result
building '/nix/store/ky50pz3nw9x4wn4lfdd7hfwj0hbkbg7x-xscreensaver.pam.drv'...
error: map::at

it also happens when I run nix directly on the flake:

[zseri@orca:~/devel/nixos-configs]$ nix build --keep-going --show-trace -v -L -j1 --cores 4 .#nixosConfigurations.orca.config.system.build.toplevel
building '/nix/store/ky50pz3nw9x4wn4lfdd7hfwj0hbkbg7x-xscreensaver.pam.drv'...
error: map::at

rm -rf ~/.cache/nix doesn't affect this.

edolstra · 2022-04-08T12:56:11Z

We should probably stop using at() since it gives hard-to-diagnose errors. Assertion failures would be better...

edolstra · 2022-04-08T13:04:51Z

This almost certainly comes from one of the uses of at() in output hash handling in libstore (like rewriteDerivation(), which had some recent changes).

fogti · 2022-04-08T20:24:54Z

nix-2.5pre20211029_888771b and nix-2.6.0pre20220116_e1720b8 also show the same error (even when deleting the cache between each run), so it is either nix-daemon-, nix database, CA, or nixpkgs related, perhaps a combination of these is necessary.

This pretty much means that although the error message appears on the client side, no recent client-side change could've caused this. But I also can't use a much older nix-daemon version, because the CA db schema changed in the last few months.

$ for i in /nix/store/*-nix-2.*/bin/nix; do echo; echo "$i"; rm -rf ~/.cache/nix; echo; "$i" build --keep-going --show-trace -v -L -j1 --cores 1 .#nixosConfigurations.orca.config.system.build.toplevel; ech
o '$? =' $?; donekeep-going --show-trace -v -L -j1 --cores 1 .#nixosConfigurations.orca.config.system.build.toplevel; echo '$? =' $?; done

/nix/store/04yzz6xpsn8faalw1cx3fzz9s51r5ha5-nix-2.8.0pre20220318_8ad485e/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/099d2qzzpas73aswnnvqy96gvh6xmmvx-nix-2.5pre20211029_888771b/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/3q76li15y1d3c72hwkyjh69lk5fknz1s-nix-2.6.0pre20220116_e1720b8/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/8irzp38v9yln9z9y3bhg30y38njndiij-nix-2.7.0pre20220125_5fa624f/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/8lnp4vrc6y9w4i94p6bw4vm4d5a5r0di-nix-2.7.0pre20220201_73d5f38/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/ab211gdqzlc8gq8v2hfiibb7mxrlhamc-nix-2.8.0pre20220317_6afc361/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/bqa6i70frjcw868pk4gmnzw1gj1sx20v-nix-2.8.0pre20220401_a24d077/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/c50ifpbp4w5wgkapd46y2m7bkkjvqkcl-nix-2.7.0pre20220210_5b809f9/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

/nix/store/cg9xkwpyi1gv3f8b9ichi9fsyrmi7l13-nix-2.6.0pre20220113_5e9653c/bin/nix

building '/nix/store/hbj25pjsa637ksgb15r3i9yh0ci5asls-etc-nixos-config-rev.drv'...
error: map::at
$? = 1

[...etc...]

Interestingly, nix build --keep-going --show-trace -v -L -j4 --cores 4 .#nixosConfigurations.orca.pkgs.nix works, but ~~derivations, which produce a file instead of a directory, fail~~ nvm, just openblas occuring in the resolve derivations graph, making the failure recurrent.

fogti · 2022-04-08T20:51:25Z

but that alone can't be the only reason, because with

{ pkgs ? import <nixpkgs> {
  config.contentAddressedByDefault = true;
} }: {
  file = pkgs.writeTextFile {
    name = "nix-case-file";
    text = ''
      This is a test file.
    '';
  };
  dir = derivation {
    name = "nix-case-dir";
    builder = "${pkgs.coreutils}/bin/mkdir";
    args = [ "-p" "${placeholder "out"}" ];
    system = builtins.currentSystem;
    __contentAddressed = true;
  };
}

it works as expected:

[zseri@orca:~/tmp/nixdbg2]$ nix-build -A dir ./default.nix
this derivation will be built:
  /nix/store/zjyjr4xscbwilb1xnxg59wwrr319x00a-nix-case-dir.drv
resolved derivation: '/nix/store/zjyjr4xscbwilb1xnxg59wwrr319x00a-nix-case-dir.drv' -> '/nix/store/qzx327lgjk7kfw94hk1psz8hq9fqpqlb-nix-case-dir.drv'...
building '/nix/store/qzx327lgjk7kfw94hk1psz8hq9fqpqlb-nix-case-dir.drv'...
/nix/store/qrmj2g3mariwr2s9s09ar41dsvkqbqvf-nix-case-dir

[zseri@orca:~/tmp/nixdbg2]$ nix-build -A file ./default.nix
this derivation will be built:
  /nix/store/9nziajzcm97pxz91j7i2z0qll0di6fps-nix-case-file.drv
resolved derivation: '/nix/store/9nziajzcm97pxz91j7i2z0qll0di6fps-nix-case-file.drv' -> '/nix/store/z0d40ll2k583gx3d9p1ii3agavg8h45b-nix-case-file.drv'...
building '/nix/store/z0d40ll2k583gx3d9p1ii3agavg8h45b-nix-case-file.drv'...
/nix/store/d5zb08hb13mqp74dkgm1x51nawfjadwv-nix-case-file

adding a file or directory to the nix store also works:

[zseri@orca:~/tmp/nixdbg2]$ nix-store --add ./default.nix 
/nix/store/w376f9kk374b2xfrzb7d9yghv2zyq1jz-default.nix

[zseri@orca:~/tmp/nixdbg2]$ nix-store --add-fixed sha256 ./default.nix 
/nix/store/9qn2bqy6hrfy02pfs9k03kzcd6py43a5-default.nix

[zseri@orca:~/tmp/nixdbg2]$ nix-store --add .
/nix/store/ywcaf425dd2h1xskg8f5w059syrs7kb7-.

[zseri@orca:~/tmp/nixdbg2]$ nix-store --add-fixed --recursive sha256 .
/nix/store/ywcaf425dd2h1xskg8f5w059syrs7kb7-.

fogti · 2022-04-08T20:59:39Z

interestingly, I previously had the error that some derivation in nixpkgs just produced no output, causing the derivation to fail...idk if that's related.

fogti · 2022-04-10T01:18:46Z

To debug this further, I try to get rid of all interesting at calls at https://github.com/zseri/nix/tree/fix-at-exp

fogti · 2022-04-10T12:47:19Z

With #6393 applied I get the following error:

building '/nix/store/khb2zp8kvl9lxq21s2qw8pawx6h50r1h-etc-nixos-config-rev.drv'...
error: derivation '/nix/store/yhzspk7x7d9w8axhqnnnspikjwp541ah-openblas-0.3.20.drv' doesn't have expected output 'dev' (derivation-goal.cc/resolvedFinished,realisation)

Mentioned derivation contents:

([('dev', '', 'r:sha256', ''), ('out', '', 'r:sha256', '')],
 [],
 ['/nix/store/1kmkmwvs6d50z4jghnildm4cj3pzhvrq-gcc-wrapper-9.3.0',
  '/nix/store/1yqclccnpawmjav9gp975n8pxcjh6n1s-perl-5.34.0',
  '/nix/store/6bq5zqgfsn4m1p8fa6y6dfbvm9x2ip1r-gcc-wrapper-10.3.0',
  '/nix/store/8n3dw45drrljrz52zanvlcfamwaj6n72-source',
  '/nix/store/9krlzvny65gdc8s7kpb6lkx8cd02c25b-default-builder.sh',
  '/nix/store/ffdzg3pbsl645k4a11ykasbvp858n6a5-which-2.21',
  '/nix/store/hkid242kbc3mhyx7s4jpcsl0abdp5fnw-bash-5.1-p16',
  '/nix/store/jiq6mmy3535a0859j0wmvvgl1r4s588r-stdenv-linux'],
 'x86_64-linux',
 '/nix/store/hkid242kbc3mhyx7s4jpcsl0abdp5fnw-bash-5.1-p16/bin/bash',
 ['-e', '/nix/store/9krlzvny65gdc8s7kpb6lkx8cd02c25b-default-builder.sh'],
 [('NIX_HARDENING_ENABLE', 'fortify format'),
  ('blas64', ''),
  ('buildInputs', ''),
  ('builder',
   '/nix/store/hkid242kbc3mhyx7s4jpcsl0abdp5fnw-bash-5.1-p16/bin/bash'),
  ('checkTarget', 'tests'),
  ('configureFlags', ''),
  ('depsBuildBuild',
   '/nix/store/1kmkmwvs6d50z4jghnildm4cj3pzhvrq-gcc-wrapper-9.3.0 '
   '/nix/store/6bq5zqgfsn4m1p8fa6y6dfbvm9x2ip1r-gcc-wrapper-10.3.0'),
  ('depsBuildBuildPropagated', ''),
  ('depsBuildTarget', ''),
  ('depsBuildTargetPropagated', ''),
  ('depsHostHost', ''),
  ('depsHostHostPropagated', ''),
  ('depsTargetTarget', ''),
  ('depsTargetTargetPropagated', ''),
  ('dev', '/02qcpld1y6xhs5gz9bchpxaw0xdhmsp5dv88lh25r2ss44kh8dxz'),
  ('doCheck', '1'),
  ('doInstallCheck', ''),
  ('hardeningDisable', 'stackprotector pic strictoverflow relro bindnow'),
  ('makeFlags',
   'BINARY=64 CC=cc CROSS=0 DYNAMIC_ARCH=1 FC=gfortran HOSTCC=cc INTERFACE64=0 '
   'NO_AVX512=1 NO_BINARY_MODE= NO_SHARED=0 NO_STATIC=1 NUM_THREADS=64 '
   'PREFIX=/1rz4g4znpzjwh1xymhjpm42vipw92pr73vdgl6xs1hycac8kf2n9 TARGET=ATHLON '
   'USE_OPENMP=1'),
  ('name', 'openblas-0.3.20'),
  ('nativeBuildInputs',
   '/nix/store/1yqclccnpawmjav9gp975n8pxcjh6n1s-perl-5.34.0 '
   '/nix/store/ffdzg3pbsl645k4a11ykasbvp858n6a5-which-2.21'),
  ('out', '/1rz4g4znpzjwh1xymhjpm42vipw92pr73vdgl6xs1hycac8kf2n9'),
  ('outputHashAlgo', 'sha256'),
  ('outputHashMode', 'recursive'),
  ('outputs', 'out dev'),
  ('patches', ''),
  ('pname', 'openblas'),
  ('postInstall',
   '    # Write pkgconfig aliases. Upstream report:\n'
   '    # https://github.com/xianyi/OpenBLAS/issues/1740\n'
   '    for alias in blas cblas lapack; do\n'
   '      cat <<EOF > $out/lib/pkgconfig/$alias.pc\n'
   'Name: $alias\n'
   'Version: 0.3.20\n'
   'Description: $alias provided by the OpenBLAS package.\n'
   'Cflags: -I$out/include\n'
   'Libs: -L$out/lib -lopenblas\n'
   'EOF\n'
   '    done\n'
   '\n'
   '    # Setup symlinks for blas / lapack\n'
   'ln -s $out/lib/libopenblas.so $out/lib/libblas.so\n'
   'ln -s $out/lib/libopenblas.so $out/lib/libcblas.so\n'
   'ln -s $out/lib/libopenblas.so $out/lib/liblapack.so\n'
   'ln -s $out/lib/libopenblas.so $out/lib/liblapacke.so\n'
   'ln -s $out/lib/libopenblas.so $out/lib/libblas.so.3\n'
   'ln -s $out/lib/libopenblas.so $out/lib/libcblas.so.3\n'
   'ln -s $out/lib/libopenblas.so $out/lib/liblapack.so.3\n'
   'ln -s $out/lib/libopenblas.so $out/lib/liblapacke.so.3\n'),
  ('propagatedBuildInputs', ''),
  ('propagatedNativeBuildInputs', ''),
  ('src', '/nix/store/8n3dw45drrljrz52zanvlcfamwaj6n72-source'),
  ('stdenv', '/nix/store/jiq6mmy3535a0859j0wmvvgl1r4s588r-stdenv-linux'),
  ('strictDeps', ''),
  ('system', 'x86_64-linux'),
  ('version', '0.3.20')])

Present store paths:

$ for i in /nix/store/*-openblas-0.3.20{,-dev}; do echo "$i"; done
/nix/store/3gah0acqfsh5a43cbq0w4y664w4xhpa3-openblas-0.3.20
/nix/store/9s9kr1qda57gbsxf881dx68zg230zyd3-openblas-0.3.20
/nix/store/a46kdvc7sd2da693cd7fn0v54d7ldp5i-openblas-0.3.20
/nix/store/b1kalaran9xarv5ng8nqqw5d22a5y6pm-openblas-0.3.20
/nix/store/g7fxzz27ljmrq9kcc5gyi2i50g3f6jw4-openblas-0.3.20
/nix/store/xzb471x2f9xrb13c84pzbbc8nmaz8gh5-openblas-0.3.20
/nix/store/3l4jql3dmashnfk0kwvch6jlwpn40yxi-openblas-0.3.20-dev
/nix/store/49c8nmr7fidsy6r4xnflq2639y87hyh0-openblas-0.3.20-dev
/nix/store/igjpzq7hf89cc5ivr9yrbs5zq3px1x12-openblas-0.3.20-dev
/nix/store/rdmkibibyxl0l0z23781j56r5cf2pni7-openblas-0.3.20-dev
/nix/store/v2958ri9qpfbnyka3h4lskpqi7h4p4hy-openblas-0.3.20-dev
/nix/store/vv9wy8kv45nxni6iz6w4lzf3sdbdj8iy-openblas-0.3.20-dev

fogti · 2022-04-10T13:00:52Z

[root@orca:~]# for i in /nix/store/*-openblas-0.3.20*; do nix-store --delete "$i"; echo $?; done
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/29jqw2h0q9d8xjl2qbwpln82qp1bxwjc-openblas-0.3.20.drv' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/3gah0acqfsh5a43cbq0w4y664w4xhpa3-openblas-0.3.20' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/3l4jql3dmashnfk0kwvch6jlwpn40yxi-openblas-0.3.20-dev' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/4206c1fh1fk726146x2fzsz6sy35p5jd-openblas-0.3.20.drv' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
deleting '/nix/store/49c8nmr7fidsy6r4xnflq2639y87hyh0-openblas-0.3.20-dev'
deleting unused links...
note: currently hard linking saves 155126.19 MiB
1 store paths deleted, 0.00 MiB freed
0
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/vv9wy8kv45nxni6iz6w4lzf3sdbdj8iy-openblas-0.3.20-dev' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/xzb471x2f9xrb13c84pzbbc8nmaz8gh5-openblas-0.3.20' since it is still alive. To find out why, use: nix-store --query --roots
1
finding garbage collector roots...
0 store paths deleted, 0.00 MiB freed
error: Cannot delete path '/nix/store/yhzspk7x7d9w8axhqnnnspikjwp541ah-openblas-0.3.20.drv' since it is still alive. To find out why, use: nix-store --query --roots
1

doesn't help:

error: derivation '/nix/store/yhzspk7x7d9w8axhqnnnspikjwp541ah-openblas-0.3.20.drv' doesn't have expected output 'dev' (derivation-goal.cc/resolvedFinished,realisation)

I'll try to run a garbage collection and check if that helps...

fogti · 2022-04-10T13:01:47Z

next step would be debugging where the corruption happened...

fogti · 2022-04-10T13:17:42Z

btw. nix-store --query --referrers /nix/store/yhzspk7x7d9w8axhqnnnspikjwp541ah-openblas-0.3.20.drv does not return anything (that is, no dependees, why can't it be deleted then??)

fogti · 2022-04-10T13:58:48Z

I suspect 0948b8e and 390269e might be relevant to this.

fogti · 2022-04-10T14:39:36Z

Broader context:

nix/src/libstore/build/derivation-goal.cc

Lines 987 to 991 in 646af73

    
           for (auto & wantedOutput : realWantedOutputs) { 
        
               assert(initialOutputs.count(wantedOutput) != 0); 
        
               assert(resolvedHashes.count(wantedOutput) != 0); 
        
               auto realisation = resolvedResult.builtOutputs.at( 
        
                   DrvOutput { resolvedHashes.at(wantedOutput), wantedOutput });

The following line produces the exception:

nix/src/libstore/build/derivation-goal.cc

Line 990 in 646af73

auto realisation = resolvedResult.builtOutputs.at(

So, what happens here?

resolvedResult.builtOutputs does not contain the requested DrvOutput { resolvedHashes.at(wantedOutput), wantedOutput }
(inclusive) either the hash or the wantedOutput do not match what is expected
but a resolved hash is present, so why isn't it reflected in the builtOutputs?
So maybe the part which fills in/constructs DrvOutput originally mismatches this retrieving site.

pre {last related change} blame: https://github.com/NixOS/nix/blame/28309352d991f50c9d8b54a5a0ee99995a1a5297/src/libstore/build/derivation-goal.cc

fogti · 2022-04-10T14:57:39Z

This bug appears to affect many CA derivations with multiple outputs...

lock released on '/nix/store/lg3782a6f71d4i4bmqi9ja9ya531sh5i-gcc-9.3.0.lock'
lock released on '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv.info.lock'
lock released on '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv.lib.lock'
lock released on '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv.man.lock'
lock released on '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv.out.lock'
building of '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv!info,lib,man,out' from .drv file: done
building of '/nix/store/q418bvmn55kp2k4s7y54xkbhwwnm97bd-gcc-9.3.0.drv!info,lib,man,out' from .drv file: waitee 'building of '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv!info,lib,man,out' from .drv file' done; 0 left
building of '/nix/store/q418bvmn55kp2k4s7y54xkbhwwnm97bd-gcc-9.3.0.drv!info,lib,man,out' from .drv file: woken up
building of '/nix/store/q418bvmn55kp2k4s7y54xkbhwwnm97bd-gcc-9.3.0.drv!info,lib,man,out' from .drv file: resolved derivation finished
building of '/nix/store/mkjzc50cmlw8v1ykdfydk0shkrdpzjy8-openblas-0.3.20.drv!out' from .drv file: goal destroyed
building of '/nix/store/r9614bl81cjcrd1g4rpqz4cb8cws7sa0-gcc-wrapper-9.3.0.drv!out' from .drv file: goal destroyed
building of '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv!info,lib,man,out' from .drv file: goal destroyed
building of '/nix/store/q418bvmn55kp2k4s7y54xkbhwwnm97bd-gcc-9.3.0.drv!info,lib,man,out' from .drv file: goal destroyed
error: derivation '/nix/store/z20mw8ma41chlnd8cjc33pc9mpzdqisn-gcc-9.3.0.drv' doesn't have expected output 'info' (derivation-goal.cc/resolvedFinished,realisation)

Sadly, I didn't start this compilation before adding further debugging to print the exact contents of the buildResult, and the build converged on retry...

instantiated 'unzip60.tar.gz' -> '/nix/store/hgri3kx3hqrnhm5pfw2mh2sjxf4mnw23-unzip60.tar.gz.drv'
instantiated 'unzip-6.0' -> '/nix/store/l5n07bd4hri2qvd18k0vdarzphsgv2hj-unzip-6.0.drv'
instantiated 'source' -> '/nix/store/n0qk70gzqd62b7qamgbf3g6nfs58yf4h-source.drv'
instantiated 'openblas-0.3.20' -> '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv'
evaluating uncached attribute nixosConfigurations.orca.pkgs.openblas.outputName
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: created
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: woken up
querying info about missing paths...
starting pool of 24 threads
entered goal loop
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: init
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: loading derivation
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: have derivation
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: done
building of '/nix/store/xhc03hrjzmhmasvi99w94sj6f9i4ri9n-openblas-0.3.20.drv!out' from .drv file: goal destroyed

trofi · 2022-04-30T16:50:04Z

Do you know if there is a workaround apart from restarting the build? I did a partial nix store gc --max ... recently and now getting quite a few failures when trying to build the system. All map::at failures look transient and don't repeat on restart.

fogti · 2022-04-30T18:04:12Z

I don't know... I downgraded to 540d7e3 to be able to finish the nixos-rebuild.

fogti · 2022-05-04T13:04:56Z

@trofi with #6393 merged the error messages should be much better and easier debuggable.

trofi · 2022-05-04T20:15:23Z

Oh, that's great! I confirm now I get slightly more precise errors:

error: derivation '/nix/store/8g3n3023npvsjhqibnp54c6g7gnmh54m-cairo-1.16.0.drv' doesn't have expected output 'out' (derivation-goal.cc/resolvedFinished,realisation)

fogti · 2022-05-04T21:24:19Z

you could try building nix against https://github.com/zseri/nix/tree/debug-6383, which should make this specific error more precise. (and might hint at the problem origin). (I currently don't want to test it myself because I'm in-between an update phase, and want to finish it first, which takes a few days)

trofi · 2022-05-04T22:53:13Z

Aha, that reports failures like:

error: derivation '/nix/store/g7q24qrdzdcvsirxw8aw0alc9s0qsl77-shared-mime-info-unstable-2021-12-03.drv' doesn't have expected output 'dev @ sha256:094p4p14vbmqhhd2g4nr08phln6hr789rzqnjwll9q79kisc7n7g'
        builtOutputs:
                out @ sha256:094p4p14vbmqhhd2g4nr08phln6hr789rzqnjwll9q79kisc7n7g (key) = /nix/store/98f30ch5mldzkw0zznx2s2ll6r940jv3-shared-mime-info-unstable-2021-12-03

fogti · 2022-05-05T02:46:59Z

thanks.
ok, now it gets interesting, because something which constructs the DrvOutputs omits stuff which shouldn't be omitted... maybe something like:

nix/src/libstore/build/local-derivation-goal.cc

Lines 2651 to 2652 in 470e27c

    
           if (wantOutput(outputName, wantedOutputs)) 
        
               builtOutputs.emplace(thisRealisation.id, thisRealisation);

fogti · 2022-05-05T02:50:08Z

related: #6312

cc @Ericson2314 you appear to have much more insight than me about how wantedOutputs are dealt with, do you know where resolvedResult.builtOutputs gets constructed? (which is interesting in this case because it is incomplete).

I suppose only commits after 540d7e3 are relevant (as in: might have caused this regression), but I'm not 100% sure about that.

Ericson2314 · 2022-05-12T15:49:01Z

@zseri Yes we should land that. While I am not sure whether the race condition in fact happens, the larger point that we can clean up the code to be more robust certainly does. Also, removing the derived path from goals which, in any event, have mutable wanted outputs, is certainly a good a idea.

trofi · 2022-06-14T06:04:04Z

When system-wide rebuilds happen for me I frequently see such failures. It looks like the pattern is multiple goal destructions for a single package:

$ nix build -f nixos system --keep-going --verbose --debug
...
building of '/nix/store/jb2pxhcp45ksd03y135czwk1cnpmbgyh-bash-5.1-p16.drv!dev,doc,info,man,out' from .drv file: goal destroyed
building of '/nix/store/w8iqdk3rd3d1cs893ijrvharxj4275c7-gzip-1.12.drv!info,man,out' from .drv file: goal destroyed
building of '/nix/store/cd4mm6myiksh4r0gl46kbkqyl95wzyph-gzip-1.12.drv!out' from .drv file: goal destroyed
error: derivation '/nix/store/w8iqdk3rd3d1cs893ijrvharxj4275c7-gzip-1.12.drv' doesn't have expected output 'out' (derivation-goal.cc/resolvedFinished,realisation)

Could it be that something underlying a package (gzip in this case) was destroyed too early?

gador · 2022-10-01T09:58:27Z

I am affected by that as well. Doing a system rebuild with config.contentAddressedByDefault = true; will results in many errors like error: derivation '/nix/store/c4yvsb45yqp1zvlnp4n1kcga93zmplyv-cups-2.4.2.drv' doesn't have expected output 'dev' (derivation-goal.cc/resolvedFinished,realisation)
When doing a rebuild of that package with nix build --rebuild /nix/store/c4yvsb45yqp1zvlnp4n1kcga93zmplyv-cups-2.4.2.drv I don't get that error (with cups) anymore but it will fail at the next packages with multiple outputs.
Any help would be appreciated. Also if someone wants to try a fix, I'll be happy to test it

thufschmitt · 2022-11-17T15:59:40Z

Is this still happening after #7283 ? It's not sure, but there's a small chance that it's a different symptom of the same cause.

trofi · 2022-11-17T22:11:48Z

I'd say it at least has got a lot better. I used to get quite a few failures while building system with CA enabled. Today I tried building system a few times from staging and saw no failures so far.

trofi · 2022-11-17T22:41:12Z

And almost right after I posted it I got another transient failure:

$ nix build --no-link -f. -f nixos system --keep-going --max-jobs 1
error: derivation '/nix/store/jil66a59d6wnz47q7sqznkv25xijlzvc-gtest-1.12.1.drv' doesn't have expected output 'out' (derivation-goal.cc/resolvedFinished,realisation)

nixos-discourse · 2022-11-25T09:50:52Z

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

https://discourse.nixos.org/t/tweag-nix-dev-update-40/23480/1

check the store for input before failing (hopefully fix #6383)

fogti added the bug label Apr 8, 2022

thufschmitt added the ca-derivations Derivations with content addressed outputs label Apr 8, 2022

fogti mentioned this issue Apr 10, 2022

Get rid of most .at calls #6393

Merged

fogti added a commit to fogti/nix that referenced this issue Apr 10, 2022

debug NixOS#6383, print resolvedResult in error

fcbbcd0

fogti changed the title ~~map::at error~~ resolvedResult.builtOutputs doesn't contain expected output after successful multi-output build Apr 10, 2022

fogti added a commit to fogti/nix that referenced this issue May 4, 2022

debug NixOS#6383

971ba33

fogti mentioned this issue May 4, 2022

debug #6383 #6484

Closed

Radvendii added a commit to Radvendii/nix that referenced this issue Dec 2, 2022

check the store for input before failing (hopefully fix NixOS#6383)

0bcfb1b

Radvendii mentioned this issue Dec 2, 2022

check the store for input before failing (hopefully fix #6700) #7390

Merged

Radvendii mentioned this issue Dec 6, 2022

check the store for input before failing (hopefully fix #6383) #7409

Merged

thufschmitt closed this as completed in 8c7661d Dec 9, 2022

thufschmitt added a commit that referenced this issue Dec 9, 2022

Merge pull request #7409 from tweag/fix-6383

2affb19

check the store for input before failing (hopefully fix #6383)

jm8 pushed a commit to jm8/nix that referenced this issue Aug 5, 2023

check the store for input before failing (hopefully fix NixOS#6383)

04c0ca7

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

`resolvedResult.builtOutputs` doesn't contain expected output after successful multi-output build #6383

`resolvedResult.builtOutputs` doesn't contain expected output after successful multi-output build #6383

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 8, 2022 •

edited

Loading

edolstra commented Apr 8, 2022

edolstra commented Apr 8, 2022

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 8, 2022

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented Apr 10, 2022 •

edited

Loading

trofi commented Apr 30, 2022

fogti commented Apr 30, 2022

fogti commented May 4, 2022

trofi commented May 4, 2022

fogti commented May 4, 2022

trofi commented May 4, 2022

fogti commented May 5, 2022

fogti commented May 5, 2022 •

edited

Loading

Ericson2314 commented May 12, 2022

trofi commented Jun 14, 2022

gador commented Oct 1, 2022

thufschmitt commented Nov 17, 2022

trofi commented Nov 17, 2022

trofi commented Nov 17, 2022

nixos-discourse commented Nov 25, 2022

resolvedResult.builtOutputs doesn't contain expected output after successful multi-output build #6383

resolvedResult.builtOutputs doesn't contain expected output after successful multi-output build #6383

Comments

fogti commented Apr 8, 2022 • edited Loading

fogti commented Apr 8, 2022 • edited Loading

edolstra commented Apr 8, 2022

edolstra commented Apr 8, 2022

fogti commented Apr 8, 2022 • edited Loading

fogti commented Apr 8, 2022 • edited Loading

fogti commented Apr 8, 2022

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022 • edited Loading

fogti commented Apr 10, 2022 • edited Loading

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022

fogti commented Apr 10, 2022 • edited Loading

fogti commented Apr 10, 2022 • edited Loading

trofi commented Apr 30, 2022

fogti commented Apr 30, 2022

fogti commented May 4, 2022

trofi commented May 4, 2022

fogti commented May 4, 2022

trofi commented May 4, 2022

fogti commented May 5, 2022

fogti commented May 5, 2022 • edited Loading

Ericson2314 commented May 12, 2022

trofi commented Jun 14, 2022

gador commented Oct 1, 2022

thufschmitt commented Nov 17, 2022

trofi commented Nov 17, 2022

trofi commented Nov 17, 2022

nixos-discourse commented Nov 25, 2022

`resolvedResult.builtOutputs` doesn't contain expected output after successful multi-output build #6383

`resolvedResult.builtOutputs` doesn't contain expected output after successful multi-output build #6383

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 8, 2022 •

edited

Loading

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented Apr 10, 2022 •

edited

Loading

fogti commented May 5, 2022 •

edited

Loading