From f91bdc9367981eb1ae529bce60ca723733c9fd6a Mon Sep 17 00:00:00 2001 From: blokyk Date: Thu, 9 Jul 2026 18:06:07 +0200 Subject: [PATCH] libutil: always print `addErrorContext` frames frames manually added with `addErrorContext` are generally a lot more useful/informative to the average user than other frames, esp. in the module system, which can create much better error messages than we can. however, before this change, frames from addErrorContext were truncated by default if they weren't in the first 3 frames, so they were basically useless (with `--show-trace`, you're dredging through 250 frames of module shenanigans just to spot one singular line). this change also removes the frames for _the call to_ `addErrorContext`, which is just pure noise. the way this change is done hopefully leaves a bit of space for future similar changes to error printing, by introducing a new `TraceKind` enum that can be used to categorize traces (i haven't done that in this CL because that would be a pretty herculean task, given all the calls to `BaseError::addTrace` in the codebase, and we probably want to be careful about what categories we choose). the actual printing code could definitely be improved tho... (e.g. by iterating twice through the trace stack instead to first pick out the most important traces and _then_ printing less "important" traces if there's space left) Change-Id: I52acc52f231991a9f2309d9cecae362397c6888c --- doc/manual/rl-next/user-traces.md | 23 +++++++ lix/libexpr/builtins/addErrorContext.md | 60 +------------------ lix/libexpr/eval.cc | 14 ++++- lix/libexpr/primops.cc | 3 +- lix/libutil/error-trace.hh | 12 +++- lix/libutil/error.cc | 31 ++++++---- lix/libutil/error.hh | 2 +- .../functional2/lang/err_context/__init__.py | 0 .../lang/err_context/eval-fail-deep.err.exp | 24 ++++++++ .../lang/err_context/eval-fail.err.exp | 10 ++++ .../functional2/lang/err_context/in-deep.nix | 9 +++ tests/functional2/lang/err_context/in.nix | 1 + tests/functional2/lang/err_context/test.toml | 8 +++ .../lang/err_context/test_err_context.py | 14 ----- 14 files changed, 121 insertions(+), 90 deletions(-) create mode 100644 doc/manual/rl-next/user-traces.md delete mode 100644 tests/functional2/lang/err_context/__init__.py create mode 100644 tests/functional2/lang/err_context/eval-fail-deep.err.exp create mode 100644 tests/functional2/lang/err_context/eval-fail.err.exp create mode 100644 tests/functional2/lang/err_context/in-deep.nix create mode 100644 tests/functional2/lang/err_context/in.nix create mode 100644 tests/functional2/lang/err_context/test.toml delete mode 100644 tests/functional2/lang/err_context/test_err_context.py diff --git a/doc/manual/rl-next/user-traces.md b/doc/manual/rl-next/user-traces.md new file mode 100644 index 000000000..97c8d50c4 --- /dev/null +++ b/doc/manual/rl-next/user-traces.md @@ -0,0 +1,23 @@ +--- +synopsis: "Always print frames from `addErrorContext` in error traces" +cls: [5847] +category: "Improvements" +credits: [blokyk] +issues: [] +--- + +The [`builtins.addErrorContext`](@docroot@/language/builtins.md#builtins-addErrorContext) +function allows an author to add artificial stack frames with custom messages to +help end-users understand the context of an error and the path the code took to +get there, without having to read and understand the original source code. A +particularly notable user of this is the Nixpkgs module system, which adds +custom frames detailing what option it's evaluating or which definition it's +looking at. + +However, previously, these frames would end up treated just as any other, +meaning they would most often not be visible without `--show-trace`; yet, using +`--show-trace`, they would be drowned out in the noise of the hundreds of other +frames, rendering them just as unusable. + +With this change, these frames are now unconditionally shown, even without +`--show-trace`, which makes basic error traces much more informative. diff --git a/lix/libexpr/builtins/addErrorContext.md b/lix/libexpr/builtins/addErrorContext.md index 6d99659bb..8a169aa67 100644 --- a/lix/libexpr/builtins/addErrorContext.md +++ b/lix/libexpr/builtins/addErrorContext.md @@ -23,70 +23,14 @@ countDown 2 Then, evaluating the file will give the following stack trace: ```console -$ nix-instantiate --show-trace err.nix +$ nix-instantiate err.nix error: - … from call site - at /home/plop/git.lix.systems/lix-project/lix/err.nix:9:1: - 8| in - 9| countDown 2 - | ^ - 10| - - … while calling 'countDown' - at /home/plop/git.lix.systems/lix-project/lix/err.nix:3:5: - 2| countDown = - 3| n: - | ^ - 4| if n == 0 then - - … while calling the 'addErrorContext' builtin - at /home/plop/git.lix.systems/lix-project/lix/err.nix:7:7: - 6| else - 7| builtins.addErrorContext "while counting down; n = ${toString n}" ("x" + countDown (n - 1)); - | ^ - 8| in - … while counting down; n = 2 - … from call site - at /home/plop/git.lix.systems/lix-project/lix/err.nix:7:80: - 6| else - 7| builtins.addErrorContext "while counting down; n = ${toString n}" ("x" + countDown (n - 1)); - | ^ - 8| in - - … while calling 'countDown' - at /home/plop/git.lix.systems/lix-project/lix/err.nix:3:5: - 2| countDown = - 3| n: - | ^ - 4| if n == 0 then - - … while calling the 'addErrorContext' builtin - at /home/plop/git.lix.systems/lix-project/lix/err.nix:7:7: - 6| else - 7| builtins.addErrorContext "while counting down; n = ${toString n}" ("x" + countDown (n - 1)); - | ^ - 8| in - … while counting down; n = 1 - … from call site - at /home/plop/git.lix.systems/lix-project/lix/err.nix:7:80: - 6| else - 7| builtins.addErrorContext "while counting down; n = ${toString n}" ("x" + countDown (n - 1)); - | ^ - 8| in - - … while calling 'countDown' - at /home/plop/git.lix.systems/lix-project/lix/err.nix:3:5: - 2| countDown = - 3| n: - | ^ - 4| if n == 0 then - … caused by explicit throw - at /home/plop/git.lix.systems/lix-project/lix/err.nix:5:7: + at err.nix:5:7: 4| if n == 0 then 5| throw "kaboom" | ^ diff --git a/lix/libexpr/eval.cc b/lix/libexpr/eval.cc index e9d24f941..7d24ed92d 100644 --- a/lix/libexpr/eval.cc +++ b/lix/libexpr/eval.cc @@ -1195,12 +1195,18 @@ Value EvalState::callFunction(Value & fun, std::span args, const PosIdx p // was being evaluated and an explicit thrown error. if (fn->name == "throw" && !e.hasTrace()) { e.addTrace(ctx.positions[pos], "caused by explicit %s", "throw"); - } else { + } + // otherwise, print a trace of this builtin, as long as it isn't + // a 'addErrorContext' call (which would just create noise) + else if (fn->name != "addErrorContext") + { e.addTrace(ctx.positions[pos], "while calling the '%s' builtin", fn->name); } throw; } catch (Error & e) { - e.addTrace(ctx.positions[pos], "while calling the '%1%' builtin", fn->name); + if (fn->name != "addErrorContext") { + e.addTrace(ctx.positions[pos], "while calling the '%1%' builtin", fn->name); + } throw; } @@ -1246,7 +1252,9 @@ Value EvalState::callFunction(Value & fun, std::span args, const PosIdx p // so the debugger allows to inspect the wrong parameters passed to the builtin. vCur = fn->fun(*this, vArgs.data()); } catch (Error & e) { - e.addTrace(ctx.positions[pos], "while calling the '%1%' builtin", fn->name); + if (fn->name != "addErrorContext") { + e.addTrace(ctx.positions[pos], "while calling the '%1%' builtin", fn->name); + } throw; } } diff --git a/lix/libexpr/primops.cc b/lix/libexpr/primops.cc index b12061c1c..000f6774d 100644 --- a/lix/libexpr/primops.cc +++ b/lix/libexpr/primops.cc @@ -1,3 +1,4 @@ +#include "libutil/error-trace.hh" #include "lix/libutil/archive.hh" #include "lix/libstore/derivations.hh" #include "lix/libexpr/eval.hh" @@ -699,7 +700,7 @@ static Value prim_addErrorContext(EvalState & state, Value ** args) auto message = state.coerceToString(noPos, *args[0], context, "while evaluating the error message passed to builtins.addErrorContext", StringCoercionMode::Strict, false).toOwned(); - e.addTrace(nullptr, HintFmt(message)); + e.addTrace(nullptr, HintFmt(message), TraceKind::UserTrace); throw; } } diff --git a/lix/libutil/error-trace.hh b/lix/libutil/error-trace.hh index de660b681..5168187dc 100644 --- a/lix/libutil/error-trace.hh +++ b/lix/libutil/error-trace.hh @@ -12,6 +12,15 @@ namespace nix { +/** @brief The kind/origin of a trace frame + * + * Right now, this is mainly used to prioritize certain traces above others. + */ +enum TraceKind { + UnknownTrace, + UserTrace, +}; + struct Pos; /** @brief Information for a @ref Trace that encountered a derivation. @@ -32,13 +41,12 @@ struct DrvTrace operator<=>(DrvTrace const & lhs, DrvTrace const & rhs) noexcept = default; }; -struct Trace; - struct Trace { std::shared_ptr pos; HintFmt hint; std::optional drvTrace; + TraceKind kind = UnknownTrace; /** Construct a Trace and canned format message assuming a derivation's * position and name. diff --git a/lix/libutil/error.cc b/lix/libutil/error.cc index b90573d74..3855a951f 100644 --- a/lix/libutil/error.cc +++ b/lix/libutil/error.cc @@ -18,9 +18,9 @@ namespace nix { -void BaseError::addTrace(std::shared_ptr && e, HintFmt hint) +void BaseError::addTrace(std::shared_ptr && e, HintFmt hint, TraceKind kind) { - err.traces.push_front(Trace { .pos = std::move(e), .hint = hint }); + err.traces.push_front(Trace{.pos = std::move(e), .hint = hint, .kind = kind}); } // c++ std::exception descendants must have a 'const char* what()' function. @@ -150,12 +150,13 @@ void printTrace( count++; } -void printSkippedTracesMaybe( +void printDuplicateTracesMaybe( std::ostream & output, const std::string_view & indent, size_t & count, std::vector & skippedTraces, - std::set tracesSeen) + std::set tracesSeen +) { if (skippedTraces.size() > 0) { // If we only skipped a few frames, print them out normally; @@ -371,31 +372,39 @@ std::ostream & showErrorInfo(std::ostream & out, const ErrorInfo & einfo, bool s // omitted`. std::set tracesSeen; // A consecutive sequence of stack traces that are all in `tracesSeen`. - std::vector skippedTraces; + std::vector duplicatedTraces; size_t count = 0; + bool didSkipTrace = false; + for (const auto & trace : einfo.traces) { if (trace.hint.str().empty()) continue; - if (!showTrace && count > 3) { - oss << "\n" << ANSI_WARNING "(stack trace truncated; use '--show-trace' to show the full trace)" ANSI_NORMAL << "\n"; - break; + if (!showTrace && count > 3 && trace.kind != TraceKind::UserTrace) { + didSkipTrace = true; + continue; // continue so that we still print later user traces } if (tracesSeen.count(trace)) { - skippedTraces.push_back(trace); + duplicatedTraces.push_back(trace); continue; } tracesSeen.insert(trace); - printSkippedTracesMaybe(oss, ellipsisIndent, count, skippedTraces, tracesSeen); + printDuplicateTracesMaybe(oss, ellipsisIndent, count, duplicatedTraces, tracesSeen); count++; printTrace(oss, ellipsisIndent, count, trace); } - printSkippedTracesMaybe(oss, ellipsisIndent, count, skippedTraces, tracesSeen); + printDuplicateTracesMaybe(oss, ellipsisIndent, count, duplicatedTraces, tracesSeen); + if (didSkipTrace) { + oss << "\n" + << ANSI_WARNING + "(stack trace truncated; use '--show-trace' to show the full trace)" ANSI_NORMAL + << "\n"; + } oss << "\n" << prefix; } diff --git a/lix/libutil/error.hh b/lix/libutil/error.hh index 2e1d8dfee..090bcf41d 100644 --- a/lix/libutil/error.hh +++ b/lix/libutil/error.hh @@ -199,7 +199,7 @@ public: addTrace(std::move(e), HintFmt(std::string(fs), args...)); } - void addTrace(std::shared_ptr && e, HintFmt hint); + void addTrace(std::shared_ptr && e, HintFmt hint, TraceKind kind = UnknownTrace); bool hasTrace() const { return !err.traces.empty(); } diff --git a/tests/functional2/lang/err_context/__init__.py b/tests/functional2/lang/err_context/__init__.py deleted file mode 100644 index e69de29bb..000000000 diff --git a/tests/functional2/lang/err_context/eval-fail-deep.err.exp b/tests/functional2/lang/err_context/eval-fail-deep.err.exp new file mode 100644 index 000000000..2a6d4b545 --- /dev/null +++ b/tests/functional2/lang/err_context/eval-fail-deep.err.exp @@ -0,0 +1,24 @@ +error: + … computing fib(4) + + … while calling the 'add' builtin + at /pwd/in.nix:7:8: + 6| # note: we use builtins.add explicitly because it creates more frames than (+) + 7| (builtins.add (fib (n - 1)) (fib (n - 2))); + | ^ + 8| in + + … computing fib(3) + + … computing fib(2) + + … computing fib(1) + + (stack trace truncated; use '--show-trace' to show the full trace) + + error: assertion failed + at /pwd/in.nix:3:5: + 2| fib = n: + 3| assert n > 0; + | ^ + 4| builtins.addErrorContext diff --git a/tests/functional2/lang/err_context/eval-fail.err.exp b/tests/functional2/lang/err_context/eval-fail.err.exp new file mode 100644 index 000000000..2680c9aed --- /dev/null +++ b/tests/functional2/lang/err_context/eval-fail.err.exp @@ -0,0 +1,10 @@ +error: + … Hello + + … caused by explicit throw + at /pwd/in.nix:1:35: + 1| builtins.addErrorContext "Hello" (throw "Foo") + | ^ + 2| + + error: Foo diff --git a/tests/functional2/lang/err_context/in-deep.nix b/tests/functional2/lang/err_context/in-deep.nix new file mode 100644 index 000000000..006cc4b90 --- /dev/null +++ b/tests/functional2/lang/err_context/in-deep.nix @@ -0,0 +1,9 @@ +let + fib = n: + assert n > 0; + builtins.addErrorContext + "computing fib(${toString n})" + # note: we use builtins.add explicitly because it creates more frames than (+) + (builtins.add (fib (n - 1)) (fib (n - 2))); +in + fib 4 diff --git a/tests/functional2/lang/err_context/in.nix b/tests/functional2/lang/err_context/in.nix new file mode 100644 index 000000000..b79f2daa4 --- /dev/null +++ b/tests/functional2/lang/err_context/in.nix @@ -0,0 +1 @@ +builtins.addErrorContext "Hello" (throw "Foo") diff --git a/tests/functional2/lang/err_context/test.toml b/tests/functional2/lang/err_context/test.toml new file mode 100644 index 000000000..5da654753 --- /dev/null +++ b/tests/functional2/lang/err_context/test.toml @@ -0,0 +1,8 @@ +[[test]] +runner = "eval-fail" +flags = ["--no-show-trace"] + +[[test]] +runner = "eval-fail" +in = "in-deep.nix" +flags = ["--no-show-trace"] diff --git a/tests/functional2/lang/err_context/test_err_context.py b/tests/functional2/lang/err_context/test_err_context.py deleted file mode 100644 index e3764deff..000000000 --- a/tests/functional2/lang/err_context/test_err_context.py +++ /dev/null @@ -1,14 +0,0 @@ -from testlib.fixtures.nix import Nix - -import pytest - -pytestmark = pytest.mark.no_daemon - - -def test_err_context(nix: Nix): - # the lang test framework doesn't check this folder, as there is a custom test in here - # it won't scream about missing an `in.nix` or .exp files - result = nix.nix_instantiate( - ["--show-trace", "--eval", "-E", 'builtins.addErrorContext "Hello" (throw "Foo")'] - ).run() - assert "Hello" in result.expect(1).stderr_s