Stack overflow #42

jamii · 2019-11-07T15:47:13Z

Using master (stable version had a missing ref in fetchGit):

jamie@machine:~/materialize$ crate2nix generate 
Generated ./Cargo.nix successfully.
jamie@machine:~/materialize$ nix build -f Cargo.nix workspaceMembers.materialized.build
error: stack overflow (possible infinite recursion)

--show-trace doesn't show a trace.

gdb shows:

#0  0x00007ffff7e68ee7 in nix::ExprSelect::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#1  0x000000000049e3b9 in nix::EvalState::forceValue(nix::Value&, nix::Pos const&) ()
#2  0x00007ffff7e677b4 in nix::ExprVar::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#3  0x00007ffff7e67ae1 in nix::ExprOpConcatLists::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#4  0x00007ffff7e67216 in nix::EvalState::callFunction(nix::Value&, nix::Value&, nix::Value&, nix::Pos const&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#5  0x00007ffff7e693cd in nix::ExprApp::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#6  0x000000000049e3b9 in nix::EvalState::forceValue(nix::Value&, nix::Pos const&) ()
#7  0x00007ffff7e690f1 in nix::ExprSelect::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#8  0x000000000049e3b9 in nix::EvalState::forceValue(nix::Value&, nix::Pos const&) ()
#9  0x00007ffff7e677b4 in nix::ExprVar::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#10 0x00007ffff7e67ae1 in nix::ExprOpConcatLists::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#11 0x00007ffff7e67216 in nix::EvalState::callFunction(nix::Value&, nix::Value&, nix::Value&, nix::Pos const&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#12 0x00007ffff7e693cd in nix::ExprApp::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#13 0x000000000049e3b9 in nix::EvalState::forceValue(nix::Value&, nix::Pos const&) ()
#14 0x00007ffff7e690f1 in nix::ExprSelect::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#15 0x000000000049e3b9 in nix::EvalState::forceValue(nix::Value&, nix::Pos const&) ()
#16 0x00007ffff7e677b4 in nix::ExprVar::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#17 0x00007ffff7e67ae1 in nix::ExprOpConcatLists::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#18 0x00007ffff7e67216 in nix::EvalState::callFunction(nix::Value&, nix::Value&, nix::Value&, nix::Pos const&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#19 0x00007ffff7e693cd in nix::ExprApp::eval(nix::EvalState&, nix::Env&, nix::Value&) () from /nix/store/zkpr9y1kj88wmizbyz84kcymi6h6ic5m-nix-2.3.1/lib/libnixexpr.so
#20 0x000000000049e3b9 in nix::EvalState::forceValue(nix::Value&, nix::Pos const&) ()
...

nix doesn't have debug symbols so I can't find the actual expr being run.

I threw builtins.trace around in the tera file but nothing jumps out so far.

Unfortunately I can't share the code, but here is the generated Cargo.nix - https://gist.github.com/jamii/5c347263b59292e2d9ae62baffc7685c

Without a proper stack trace I'm not sure how to go about debugging this.

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

kolloch · 2019-11-24T18:57:18Z

Thanks for the report! Sorry that I have no time debugging this currently.

jamii · 2019-11-25T11:42:39Z

Not at all, thanks for all the free code :)

Do you know of any resources on how to debug infinite recursion in nix?

kristoff3r · 2019-11-25T14:04:29Z

@jamii I tried looking at it for a few minutes, but I didn't get to the bottom. I think the best approach is to comment out dependencies until you have a minimal example that still doesn't evaluate, and then seeing if you can spot something that doesn't make sense.

I still got the error after commenting out everything except pgwire from materialized, and everything but coord and dataflow-types from pgwire, but removing any of those makes the error go away. I suspect it is a cyclic dependency graph, or simply one that is deep enough that you hit the recursion limit.

jamii · 2019-11-25T14:58:11Z

~~Increasing the ulimit doesn't help, so it's probably not just depth. I'll work my way through commenting more stuff out.~~

jamii · 2019-11-25T16:23:24Z

I was wrong - ulimit -s unlimited allows it to build. The problem appears to be one of breadth, not depth. I think the problem is that there is no memoization in build*, so we can build a number of derivations exponential in the depth of the graph.

jamie@machine:~/materialize$ ulimit -s unlimited

jamie@machine:~/materialize$ time nix-instantiate Cargo.nix -A workspaceMembers.materialized.build > build-log 2>&1

real	9m21.681s
user	7m3.289s
sys	0m31.606s

jamie@machine:~/materialize$ grep -c 'build deps' ./build-log 
238881

jamie@machine:~/materialize$ grep -c 'deps with renames' ./build-log 
111720

jamie@machine:~/materialize$ grep -c 'futures' ./build-log 
26682

kolloch · 2019-11-26T09:05:34Z

So you are saying the the dependent crates are even built multiple times? Then they are even multiple different derivations for them? (Otherwise the hashes should match and nix should build them only once)

crate2nix walks the whole dependency tree including the buildInputs trees, see listOfPackageFeatures. That can be a lot but I can't quite see how to derive at the exponential explosion that you are hinting at.

Could you explain it in more detail for me? Thanks.

kristoff3r · 2019-11-26T09:18:21Z

@kolloch Each crate isn't built multiple times but it is evaluated multiple times, and the build only starts after the entire nix expression has been evaluated. I found discussion of a similar issue here: https://discourse.nixos.org/t/memoize-result-of-builtins-exec/2028

jamii · 2019-11-26T10:35:29Z

So you are saying the the dependent crates are even built multiple times?

@kristoff3r is right, my language was imprecise. Functions like buildByPackageId are called many times with the same arguments, even though the same derivation is produced each time and only built once.

That can be a lot but I can't quite see how to derive at the exponential explosion that you are hinting at.

Suppose we have a dependency tree like:

A -> B1, B2
B1 -> C1, C2
B2 -> C1, C2
C1 -> D1, D2
C2 -> D1, D2
D1 -> E
D2 -> E

Without memoization, we'll construct the derivation for E 8 times - once for each path like A -> B1 -> C1 -> D1 -> E.

Here are the number of times dependencies is evaluated per package:

  # ... lots of lower counts ... #
   9947 proc-macro2
  10154 lazy_static
  12911 unicode-xid
  13267 futures
  15002 rand_core
  20131 cfg-if
  24425 libc

jamii · 2019-11-26T11:28:28Z

Here is hacky way to memoize.

        builtByPackageId =
          builtins.listToAttrs (map (packageId: {name = packageId; value = buildByPackageId packageId;}) (builtins.attrNames crateConfigs));
        buildByPackageId = packageId:
          let features = mergedFeatures.${packageId} or [];
              crateConfig = lib.filterAttrs (n: v: n != "resolvedDefaultFeatures") crateConfigs.${packageId};
              dependencies =
                  dependencyDerivations builtByPackageId features (crateConfig.dependencies or {});
              buildDependencies =
                  dependencyDerivations builtByPackageId features (crateConfig.buildDependencies or {});
              dependenciesWithRenames =
                lib.filterAttrs (n: v: v ? "rename")
                  (crateConfig.buildDependencies or {} // crateConfig.dependencies or {});
              crateRenames =
                  lib.mapAttrs (name: value: value.rename or name) dependenciesWithRenames;
          in buildRustCrate (crateConfig // { inherit features dependencies buildDependencies crateRenames; });

It cuts the instantiate time down to 3m43, which still seems pretty high.

jamii · 2019-11-26T11:47:55Z

Even with this memoization, if I run with -vvvvv I get:

amie@machine:~$ grep 'instantiated' materialize/build-log3 | cut -d' ' -f 2 | sort | uniq -c | sort -h
   # ... lots of lower counts ... #
   4908 'rust_rand_core-0.3.1'
   6117 'bytes-0.4.12.tar.gz'
   6117 'rust_bytes-0.4.12'
   6288 'either-1.5.2.tar.gz'
   6288 'rust_either-1.5.2'
   6341 'byteorder-1.3.2.tar.gz'
   6341 'rust_byteorder-1.3.2'
   6838 'crossbeam-utils-0.6.6.tar.gz'
   6838 'rust_crossbeam-utils-0.6.6'
   9429 'log-0.4.8.tar.gz'
   9429 'rust_log-0.4.8'
   9710 'iovec-0.1.2.tar.gz'
   9710 'rust_iovec-0.1.2'
   9800 'proc-macro2-1.0.1.tar.gz'
   9800 'rust_proc-macro2-1.0.1'
   9816 'rand_core-0.4.0.tar.gz'
   9816 'rust_rand_core-0.4.0'
  10154 'lazy_static-1.4.0.tar.gz'
  10154 'rust_lazy_static-1.4.0'
  12727 'rust_unicode-xid-0.2.0'
  12727 'unicode-xid-0.2.0.tar.gz'
  13267 'rust_futures-0.1.29'
  20131 'cfg-if-0.1.9.tar.gz'
  20131 'rust_cfg-if-0.1.9'
  24425 'libc-0.2.65.tar.gz'
  24425 'rust_libc-0.2.65'

kolloch · 2019-11-27T07:39:39Z

@jamii I don't think memoization at that point in the code makes a difference. In fact, the last numbers are the same. We need to apply it at a lower level.

kolloch · 2019-11-27T07:40:41Z

Your explanation comment is just awesome, @jamii! Thank you for being so elaborate.

kolloch · 2019-11-27T09:28:35Z

I tried to memoize the feature resolution in

https://github.com/kolloch/crate2nix/tree/cachedFeatureResolve

Unfortunately, I get the following an error while compiling crate2nix. The weird thing is that I thought that I'd only change the feature resolution and the result of the feature resolution seems to be the same. I checked with

nix eval --json '(let cargo = import crate2nix/Cargo.nix {}; in cargo.mergePackageFeatures { packageId = cargo.rootCrate.packageId; features = ["default"]; })' | nix run nixpkgs.jq -c jq

It is also the same as the default resolution of cargo metadata:

nix eval --raw '(let cargo = import crate2nix/Cargo.nix {}; in cargo.diffDefaultPackageFeatures { packageId = cargo.rootCrate.packageId; })' | nix run nixpkgs.jq -c jq

(it outputs some onlyInCargo crates because they are filtered by target)

If you'd find the bug, I'd be very happy :)

jamii · 2019-11-27T11:38:08Z

I don't think memoization at that point in the code makes a difference. In fact, the last numbers are the same.

Memoization at that point reduced the runtime from 10m to 3m40 and the number of evaluations per package from several 100k to 1.

I agree that the same problem seems to exist somewhere lower in the stack, but we probably need both.

jamii · 2019-11-27T12:23:48Z

Unfortunately, I get the following an error while compiling crate2nix.

What was the error?

kolloch · 2019-11-27T14:30:45Z

Sure, we will memoize on both levels if that improves things :) I just looked at the last numbers of what you posted and they were the same? Probably missed something.

The error is related to the log crate in env_logger.

jamii · 2019-11-27T15:05:57Z

I just looked at the last numbers of what you posted and they were the same? Probably missed something.

The first set of numbers was number of calls to buildByPackageId. That went down to 1 after memoization. The second set of numbers was package instantiations after memoization. I assume that they are the same number because at both levels the same graph is being unwound, so the number of paths is the same. But it seems to be two different parts of the code that are doing that same unwinding.

kolloch · 2019-11-27T21:56:58Z

BTW, why do you think that you memoization was hacky? I thought it was quite cool. Accidentially, I didn't know that this kind of forward reference is allowed in nix (buildRustCrate from builtRustCrate).

Anyways, I also found the bug in the other memoization attempt. I am very curious if that improves things for you...

jamii · 2019-11-28T10:29:41Z

why do you think that you memoization was hacky?

Oh, just because I did the easiest thing that would test the hypothesis, rather than thinking about how best to write it.

I am very curious if that improves things for you...

It seems to be on par with memoizing buildByPackageId. The number of evaluations per package is sensible, but the number of instantiations is still huge.

kolloch added the help wanted Extra attention is needed label Nov 24, 2019

kolloch added a commit that referenced this issue Nov 27, 2019

Memoize buildRustCrate (see #42)

8717c5d

kolloch closed this as completed in ec8aab5 Nov 27, 2019

sphw mentioned this issue Aug 16, 2021

Stack overflow killing build with SGX crates #209

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Stack overflow #42

Stack overflow #42

jamii commented Nov 7, 2019

kolloch commented Nov 24, 2019

jamii commented Nov 25, 2019

kristoff3r commented Nov 25, 2019

jamii commented Nov 25, 2019 •

edited

Loading

jamii commented Nov 25, 2019

kolloch commented Nov 26, 2019

kristoff3r commented Nov 26, 2019

jamii commented Nov 26, 2019 •

edited by kolloch

Loading

jamii commented Nov 26, 2019

jamii commented Nov 26, 2019 •

edited by kolloch

Loading

kolloch commented Nov 27, 2019 •

edited

Loading

kolloch commented Nov 27, 2019

kolloch commented Nov 27, 2019

jamii commented Nov 27, 2019

jamii commented Nov 27, 2019

kolloch commented Nov 27, 2019

jamii commented Nov 27, 2019

kolloch commented Nov 27, 2019

jamii commented Nov 28, 2019

Stack overflow #42

Stack overflow #42

Comments

jamii commented Nov 7, 2019

kolloch commented Nov 24, 2019

jamii commented Nov 25, 2019

kristoff3r commented Nov 25, 2019

jamii commented Nov 25, 2019 • edited Loading

jamii commented Nov 25, 2019

kolloch commented Nov 26, 2019

kristoff3r commented Nov 26, 2019

jamii commented Nov 26, 2019 • edited by kolloch Loading

jamii commented Nov 26, 2019

jamii commented Nov 26, 2019 • edited by kolloch Loading

kolloch commented Nov 27, 2019 • edited Loading

kolloch commented Nov 27, 2019

kolloch commented Nov 27, 2019

jamii commented Nov 27, 2019

jamii commented Nov 27, 2019

kolloch commented Nov 27, 2019

jamii commented Nov 27, 2019

kolloch commented Nov 27, 2019

jamii commented Nov 28, 2019

jamii commented Nov 25, 2019 •

edited

Loading

jamii commented Nov 26, 2019 •

edited by kolloch

Loading

jamii commented Nov 26, 2019 •

edited by kolloch

Loading

kolloch commented Nov 27, 2019 •

edited

Loading