From d00edfb28d0a52d9acd392c582a43f98e773cf4c Mon Sep 17 00:00:00 2001 From: Qyriad Date: Sat, 22 Jun 2024 21:22:29 -0600 Subject: [PATCH 1/4] trace when the `foo` part of `foo.bar.baz` errors MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Turns errors like: let errpkg = throw "invalid foobar"; in errpkg.meta error: … while calling the 'throw' builtin at «string»:2:12: 1| let 2| errpkg = throw "invalid foobar"; | ^ 3| in errpkg.meta error: invalid foobar into errors like: let errpkg = throw "invalid foobar"; in errpkg.meta error: … while evaluating 'errpkg' to select 'meta' on it at «string»:3:4: 2| errpkg = throw "invalid foobar"; 3| in errpkg.meta | ^ … while calling the 'throw' builtin at «string»:2:12: 1| let 2| errpkg = throw "invalid foobar"; | ^ 3| in errpkg.meta error: invalid foobar For the low price of one try/catch, you too can have the incorrect line of code actually show up in the trace! Change-Id: If8d6200ec1567706669d405c34adcd7e2d2cd29d --- doc/manual/rl-next/better-attrpath-errors.md | 64 +++++++++++++++++++ src/libexpr/eval.cc | 15 ++++- .../lang/eval-fail-recursion.err.exp | 6 ++ 3 files changed, 84 insertions(+), 1 deletion(-) create mode 100644 doc/manual/rl-next/better-attrpath-errors.md diff --git a/doc/manual/rl-next/better-attrpath-errors.md b/doc/manual/rl-next/better-attrpath-errors.md new file mode 100644 index 000000000..d06bfc43b --- /dev/null +++ b/doc/manual/rl-next/better-attrpath-errors.md @@ -0,0 +1,64 @@ +--- +synopsis: "Trace when the `foo` part of a `foo.bar.baz` expression errors" +cls: 1505 +credits: Qyriad +category: Improvements +--- + +Previously, if an expression like `linux_4_9.meta.description` errored in the `linux_4_9` part, it wouldn't show you that that's the part of the expression that failed to evaluate, or even that that line of code is what caused evaluation of the failing expression. +The previous error looks like this: + +``` +let + inherit (pkgs.linuxKernel.kernels) linux_4_9; +in linux_4_9.meta.description + +error: + … while evaluating the attribute 'linux_4_9' + at /nix/store/dk2rpyb6ndvfbf19bkb2plcz5y3k8i5v-source/pkgs/top-level/linux-kernels.nix:278:5: + 277| } // lib.optionalAttrs config.allowAliases { + 278| linux_4_9 = throw "linux 4.9 was removed because it will reach its end of life within 22.11"; + | ^ + 279| linux_4_14 = throw "linux 4.14 was removed because it will reach its end of life within 23.11"; + + … while calling the 'throw' builtin + at /nix/store/dk2rpyb6ndvfbf19bkb2plcz5y3k8i5v-source/pkgs/top-level/linux-kernels.nix:278:17: + 277| } // lib.optionalAttrs config.allowAliases { + 278| linux_4_9 = throw "linux 4.9 was removed because it will reach its end of life within 22.11"; + | ^ + 279| linux_4_14 = throw "linux 4.14 was removed because it will reach its end of life within 23.11"; + + error: linux 4.9 was removed because it will reach its end of life within 22.11 +``` + +Now, the error will look like this: + +``` +let + inherit (pkgs.linuxKernel.kernels) linux_4_9; +in linux_4_9.meta.description +error: + … while evaluating 'linux_4_9' to select 'meta.description' on it + at «string»:3:4: + 2| inherit (pkgs.linuxKernel.kernels) linux_4_9; + 3| in linux_4_9.meta.description + | ^ + + … while evaluating the attribute 'linux_4_9' + at /nix/store/dk2rpyb6ndvfbf19bkb2plcz5y3k8i5v-source/pkgs/top-level/linux-kernels.nix:278:5: + 277| } // lib.optionalAttrs config.allowAliases { + 278| linux_4_9 = throw "linux 4.9 was removed because it will reach its end of life within 22.11"; + | ^ + 279| linux_4_14 = throw "linux 4.14 was removed because it will reach its end of life within 23.11"; + + … caused by explicit throw + at /nix/store/dk2rpyb6ndvfbf19bkb2plcz5y3k8i5v-source/pkgs/top-level/linux-kernels.nix:278:17: + 277| } // lib.optionalAttrs config.allowAliases { + 278| linux_4_9 = throw "linux 4.9 was removed because it will reach its end of life within 22.11"; + | ^ + 279| linux_4_14 = throw "linux 4.14 was removed because it will reach its end of life within 23.11"; + + error: linux 4.9 was removed because it will reach its end of life within 22.11 +``` + +Not only does the line of code that referenced the failing binding show up in the trace, it also tells you that it was specifically the `linux_4_9` part that failed. diff --git a/src/libexpr/eval.cc b/src/libexpr/eval.cc index a6a64a43c..b01867a09 100644 --- a/src/libexpr/eval.cc +++ b/src/libexpr/eval.cc @@ -1432,7 +1432,20 @@ void ExprSelect::eval(EvalState & state, Env & env, Value & v) Value * vCurrent = &vFirst; // Position for the current attrset Value in this select chain. PosIdx posCurrent; - e->eval(state, env, vFirst); + + try { + e->eval(state, env, vFirst); + } catch (Error & e) { + assert(this->e != nullptr); + state.addErrorTrace( + e, + getPos(), + "while evaluating '%s' to select '%s' on it", + ExprPrinter(state, *this->e), + showAttrPath(state.symbols, this->attrPath) + ); + throw; + } try { auto dts = state.debugRepl diff --git a/tests/functional/lang/eval-fail-recursion.err.exp b/tests/functional/lang/eval-fail-recursion.err.exp index 19380dc65..f0057b2d5 100644 --- a/tests/functional/lang/eval-fail-recursion.err.exp +++ b/tests/functional/lang/eval-fail-recursion.err.exp @@ -1,4 +1,10 @@ error: + … while evaluating 'a' to select 'foo' on it + at /pwd/lang/eval-fail-recursion.nix:1:21: + 1| let a = {} // a; in a.foo + | ^ + 2| + … in the right operand of the update (//) operator at /pwd/lang/eval-fail-recursion.nix:1:12: 1| let a = {} // a; in a.foo From 5f29e1b357d45b7daa9eaf3dee34a25cf05c14fe Mon Sep 17 00:00:00 2001 From: Qyriad Date: Sat, 22 Jun 2024 21:59:47 -0600 Subject: [PATCH 2/4] trace which part of `foo.bar.baz` errors MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Turns errors like: let somepkg.src = throw "invalid foobar"; in somepkg.src.meta error: … while evaluating the attribute 'src.meta' at «string»:2:3: 1| let 2| somepkg.src = throw "invalid foobar"; | ^ 3| in somepkg.src.meta … while calling the 'throw' builtin at «string»:2:17: 1| let 2| somepkg.src = throw "invalid foobar"; | ^ 3| in somepkg.src.meta error: invalid foobar into errors like: let somepkg.src = throw "invalid foobar"; in somepkg.src.meta error: … while evaluating the attribute 'src.meta' at «string»:2:3: 1| let 2| somepkg.src = throw "invalid foobar"; | ^ 3| in somepkg.src.meta … while evaluating 'somepkg.src' to select 'meta' on it at «string»:3:4: 2| somepkg.src = throw "invalid foobar"; 3| in somepkg.src.meta | ^ … while calling the 'throw' builtin at «string»:2:17: 1| let 2| somepkg.src = throw "invalid foobar"; | ^ 3| in somepkg.src.meta error: invalid foobar And for type errors, from: let somepkg.src = "I'm not an attrset"; in somepkg.src.meta error: … while evaluating the attribute 'src.meta' at «string»:2:3: 1| let 2| somepkg.src = "I'm not an attrset"; | ^ 3| in somepkg.src.meta … while selecting an attribute at «string»:3:4: 2| somepkg.src = "I'm not an attrset"; 3| in somepkg.src.meta | ^ error: expected a set but found a string: "I'm not an attrset" into: let somepkg.src = "I'm not an attrset"; in somepkg.src.meta error: … while evaluating the attribute 'src.meta' at «string»:2:3: 1| let 2| somepkg.src = "I'm not an attrset"; | ^ 3| in somepkg.src.meta … while selecting 'meta' on 'somepkg.src' at «string»:3:4: 2| somepkg.src = "I'm not an attrset"; 3| in somepkg.src.meta | ^ error: expected a set but found a string: "I'm not an attrset" For the low price of an enumerate() and a lambda you too can have the incorrect line of code actually show up in the trace! Change-Id: Ic1491c86e33c167891bdac9adad6224784760bd6 --- src/libexpr/eval.cc | 43 ++++++++++++++++++++++++++++++++++++++++--- 1 file changed, 40 insertions(+), 3 deletions(-) diff --git a/src/libexpr/eval.cc b/src/libexpr/eval.cc index b01867a09..56581cc19 100644 --- a/src/libexpr/eval.cc +++ b/src/libexpr/eval.cc @@ -1458,12 +1458,46 @@ void ExprSelect::eval(EvalState & state, Env & env, Value & v) showAttrPath(state, env, attrPath)) : nullptr; - for (auto const & currentAttrName : attrPath) { + for (auto const & [partIdx, currentAttrName] : enumerate(attrPath)) { state.nrLookups++; Symbol const name = getName(currentAttrName, state, env); - state.forceValue(*vCurrent, pos); + // For formatting errors, which should be done only when needed. + auto partsSoFar = [&]() -> std::string { + std::stringstream ss; + // We start with the base thing this ExprSelect is selecting on. + assert(this->e != nullptr); + this->e->show(state.symbols, ss); + + // Then grab each part of the attr path up to this one. + assert(partIdx < attrPath.size()); + std::span const parts( + attrPath.begin(), + attrPath.begin() + partIdx + ); + + // And convert them to strings and join them. + for (auto const & part : parts) { + auto const partName = getName(part, state, env); + ss << "." << state.symbols[partName]; + } + + return ss.str(); + }; + + try { + state.forceValue(*vCurrent, pos); + } catch (Error & e) { + state.addErrorTrace( + e, + getPos(), + "while evaluating '%s' to select '%s' on it", + partsSoFar(), + state.symbols[name] + ); + throw; + } if (vCurrent->type() != nAttrs) { @@ -1479,7 +1513,10 @@ void ExprSelect::eval(EvalState & state, Env & env, Value & v) "expected a set but found %s: %s", showType(*vCurrent), ValuePrinter(state, *vCurrent, errorPrintOptions) - ).withTrace(pos, "while selecting an attribute").debugThrow(); + ).addTrace( + pos, + HintFmt("while selecting '%s' on '%s'", state.symbols[name], partsSoFar()) + ).debugThrow(); } // Now that we know this is actually an attrset, try to find an attr From f52436a5b28ad1e421a9fd2e89534e4cf68dcb9e Mon Sep 17 00:00:00 2001 From: Qyriad Date: Mon, 24 Jun 2024 17:26:21 -0600 Subject: [PATCH 3/4] distinguish between throws & errors during throw MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Turns errors like this: let throwMsg = a: throw (a + " invalid bar"); in throwMsg "bullshit" error: … from call site at «string»:3:4: 2| throwMsg = a: throw (a + " invalid bar"); 3| in throwMsg "bullshit" | ^ … while calling 'throwMsg' at «string»:2:14: 1| let 2| throwMsg = a: throw (a + " invalid bar"); | ^ 3| in throwMsg "bullshit" … while calling the 'throw' builtin at «string»:2:17: 1| let 2| throwMsg = a: throw (a + " invalid bar"); | ^ 3| in throwMsg "bullshit" error: bullshit invalid bar into errors like this: let throwMsg = a: throw (a + " invalid bar"); in throwMsg "bullshit" error: … from call site at «string»:3:4: 2| throwMsg = a: throw (a + " invalid bar"); 3| in throwMsg "bullshit" | ^ … while calling 'throwMsg' at «string»:2:14: 1| let 2| throwMsg = a: throw (a + " invalid bar"); | ^ 3| in throwMsg "bullshit" … caused by explicit throw at «string»:2:17: 1| let 2| throwMsg = a: throw (a + " invalid bar"); | ^ 3| in throwMsg "bullshit" error: bullshit invalid bar Change-Id: I593688928ece20f97999d1bf03b2b46d9ac338cb --- src/libexpr/eval.cc | 9 +++++++++ tests/functional/eval.sh | 2 +- tests/functional/lang/eval-fail-duplicate-traces.err.exp | 2 +- .../eval-fail-foldlStrict-strict-op-application.err.exp | 2 +- tests/functional/lang/eval-fail-mutual-recursion.err.exp | 2 +- tests/functional/lang/eval-fail-not-throws.err.exp | 2 +- tests/functional/lang/eval-fail-toJSON.err.exp | 2 +- 7 files changed, 15 insertions(+), 6 deletions(-) diff --git a/src/libexpr/eval.cc b/src/libexpr/eval.cc index 56581cc19..d9bdb0d2c 100644 --- a/src/libexpr/eval.cc +++ b/src/libexpr/eval.cc @@ -1807,6 +1807,15 @@ void EvalState::callFunction(Value & fun, size_t nrArgs, Value * * args, Value & try { fn->fun(*this, vCur.determinePos(noPos), args, vCur); + } catch (ThrownError & e) { + // Distinguish between an error that simply happened while "throw" + // was being evaluated and an explicit thrown error. + if (fn->name == "throw") { + addErrorTrace(e, pos, "caused by explicit %s", "throw"); + } else { + addErrorTrace(e, pos, "while calling the '%s' builtin", fn->name); + } + throw; } catch (Error & e) { addErrorTrace(e, pos, "while calling the '%1%' builtin", fn->name); throw; diff --git a/tests/functional/eval.sh b/tests/functional/eval.sh index 9c125b569..ae6fcec63 100644 --- a/tests/functional/eval.sh +++ b/tests/functional/eval.sh @@ -25,7 +25,7 @@ nix eval -E 'assert 1 + 2 == 3; true' # Top-level eval errors should be printed to stderr with a traceback. topLevelThrow="$(expectStderr 1 nix eval --expr 'throw "a sample throw message"')" [[ "$topLevelThrow" =~ "a sample throw message" ]] -[[ "$topLevelThrow" =~ "while calling the 'throw' builtin" ]] +[[ "$topLevelThrow" =~ "caused by explicit throw" ]] # But errors inside something should print an elided version, and exit with 0. outputOfNestedThrow="$(nix eval --expr '{ throws = throw "a sample throw message"; }')" diff --git a/tests/functional/lang/eval-fail-duplicate-traces.err.exp b/tests/functional/lang/eval-fail-duplicate-traces.err.exp index cedaebd3b..d9e2ec945 100644 --- a/tests/functional/lang/eval-fail-duplicate-traces.err.exp +++ b/tests/functional/lang/eval-fail-duplicate-traces.err.exp @@ -41,7 +41,7 @@ error: | ^ 5| if n > 0 - … while calling the 'throw' builtin + … caused by explicit throw at /pwd/lang/eval-fail-duplicate-traces.nix:7:10: 6| then throwAfter (n - 1) 7| else throw "Uh oh!"; diff --git a/tests/functional/lang/eval-fail-foldlStrict-strict-op-application.err.exp b/tests/functional/lang/eval-fail-foldlStrict-strict-op-application.err.exp index 4903bc82d..6955fad13 100644 --- a/tests/functional/lang/eval-fail-foldlStrict-strict-op-application.err.exp +++ b/tests/functional/lang/eval-fail-foldlStrict-strict-op-application.err.exp @@ -27,7 +27,7 @@ error: | ^ 6| - … while calling the 'throw' builtin + … caused by explicit throw at /pwd/lang/eval-fail-foldlStrict-strict-op-application.nix:5:9: 4| null 5| [ (_: throw "Not the final value, but is still forced!") (_: 23) ] diff --git a/tests/functional/lang/eval-fail-mutual-recursion.err.exp b/tests/functional/lang/eval-fail-mutual-recursion.err.exp index c034afcd5..c03d2e840 100644 --- a/tests/functional/lang/eval-fail-mutual-recursion.err.exp +++ b/tests/functional/lang/eval-fail-mutual-recursion.err.exp @@ -54,7 +54,7 @@ error: (21 duplicate frames omitted) - … while calling the 'throw' builtin + … caused by explicit throw at /pwd/lang/eval-fail-mutual-recursion.nix:34:10: 33| then throwAfterB true 10 34| else throw "Uh oh!"; diff --git a/tests/functional/lang/eval-fail-not-throws.err.exp b/tests/functional/lang/eval-fail-not-throws.err.exp index fc81f7277..5882a260a 100644 --- a/tests/functional/lang/eval-fail-not-throws.err.exp +++ b/tests/functional/lang/eval-fail-not-throws.err.exp @@ -5,7 +5,7 @@ error: | ^ 2| - … while calling the 'throw' builtin + … caused by explicit throw at /pwd/lang/eval-fail-not-throws.nix:1:4: 1| ! (throw "uh oh!") | ^ diff --git a/tests/functional/lang/eval-fail-toJSON.err.exp b/tests/functional/lang/eval-fail-toJSON.err.exp index ad267711b..18c334923 100644 --- a/tests/functional/lang/eval-fail-toJSON.err.exp +++ b/tests/functional/lang/eval-fail-toJSON.err.exp @@ -40,7 +40,7 @@ error: | ^ 8| } - … while calling the 'throw' builtin + … caused by explicit throw at /pwd/lang/eval-fail-toJSON.nix:7:13: 6| { 7| c.d = throw "hah no"; From 8fc4fb4fd119c74be8453c73593ee7f564e0f15f Mon Sep 17 00:00:00 2001 From: Qyriad Date: Mon, 24 Jun 2024 19:08:53 -0600 Subject: [PATCH 4/4] mildly cleanup libexpr/eval.hh Change-Id: I40d01a8f8b7fb101279c6f88ebdf1f0969d9d7f0 --- src/libexpr/eval.hh | 51 ++++++++++++++++++++++++--------------------- 1 file changed, 27 insertions(+), 24 deletions(-) diff --git a/src/libexpr/eval.hh b/src/libexpr/eval.hh index 8e390e46d..2d12a6532 100644 --- a/src/libexpr/eval.hh +++ b/src/libexpr/eval.hh @@ -9,14 +9,13 @@ #include "symbol-table.hh" #include "config.hh" #include "experimental-features.hh" -#include "input-accessor.hh" #include "search-path.hh" #include "repl-exit-status.hh" +#include #include #include #include -#include #include namespace nix { @@ -38,11 +37,26 @@ namespace eval_cache { class EvalCache; } +/** Alias for std::map which uses boehmgc's allocator conditional on us actually + * using boehmgc in this build. + */ +#if HAVE_BOEHMGC + template + using GcMap = std::map< + KeyT, + ValueT, + std::less, + traceable_allocator> + >; +#else + using GcMap = std::map +#endif + /** * Function that implements a primop. */ -typedef void (* PrimOpFun) (EvalState & state, const PosIdx pos, Value * * args, Value & v); +using PrimOpImpl = void(EvalState & state, PosIdx pos, Value ** args, Value & v); /** * Info about a primitive operation, and its implementation @@ -76,7 +90,7 @@ struct PrimOp /** * Implementation of the primop. */ - std::function::type> fun; + std::function fun; /** * Optional experimental for this to be gated on. @@ -115,11 +129,7 @@ struct Constant bool impureOnly = false; }; -#if HAVE_BOEHMGC - typedef std::map, traceable_allocator > > ValMap; -#else - typedef std::map ValMap; -#endif +using ValMap = GcMap; struct Env { @@ -214,7 +224,8 @@ public: /** * Debugger */ - ReplExitStatus (* debugRepl)(ref es, const ValMap & extraEnv); + using ReplCallbackImpl = ReplExitStatus(ref es, ValMap const & extraEnv); + ReplCallbackImpl * debugRepl; bool debugStop; bool inDebugger = false; int trylevel; @@ -252,21 +263,13 @@ private: /** * A cache from path names to parse trees. */ -#if HAVE_BOEHMGC - typedef std::map, traceable_allocator>> FileParseCache; -#else - typedef std::map FileParseCache; -#endif + using FileParseCache = GcMap; FileParseCache fileParseCache; /** * A cache from path names to values. */ -#if HAVE_BOEHMGC - typedef std::map, traceable_allocator>> FileEvalCache; -#else - typedef std::map FileEvalCache; -#endif + using FileEvalCache = GcMap; FileEvalCache fileEvalCache; SearchPath searchPath; @@ -737,15 +740,15 @@ private: bool countCalls; - typedef std::map PrimOpCalls; + using PrimOpCalls = std::map; PrimOpCalls primOpCalls; - typedef std::map FunctionCalls; + using FunctionCalls = std::map; FunctionCalls functionCalls; void incrFunctionCall(ExprLambda * fun); - typedef std::map AttrSelects; + using AttrSelects = std::map; AttrSelects attrSelects; friend struct ExprOpUpdate; @@ -787,7 +790,7 @@ std::string showType(const Value & v); */ SourcePath resolveExprPath(SourcePath path); -static const std::string corepkgsPrefix{"/__corepkgs__/"}; +static constexpr std::string_view corepkgsPrefix{"/__corepkgs__/"}; }