Show stack trace above error message with innermost first #7334

chaoflow · 2022-11-22T14:24:36Z

When debugging nix expressions the outermost trace tends to be more useful
than the innermost. It is therefore printed last to save developers from
scrolling.

Same rationale for displaying the error message after the stack trace.

domenkozar · 2022-11-22T14:38:03Z

cc @bburdette

chaoflow · 2022-11-22T17:57:56Z

@edolstra @domenkozar @DavHau This is ready. I think it would be great to show the utmost trace / code location even without --show-trace and there is code that looks like it's supposed to do that. Does anybody understand why that does not trigger? Shall we let it use the last einfo.traces instead?

fricklerhandwerk · 2022-11-23T09:43:15Z

@chaoflow please add a brief description in the top post so the Nix team can slate this for review. Linking to an issue is good, but it requires clicking around, and we found it really helpful to see at a glance what the change is about why it is made.

My personal note: I would like to see the rationale for the change in the commit messages, since GitHub issues and pull requests are practically inaccessible through Git history unless linked explicitly - and who knows how long they will exist. Writing those first and then re-using the text in the pull request description makes the above requirement trivial.

chaoflow · 2022-11-23T12:29:58Z

@fricklerhandwerk Thanks you for the feedback, I updated commit messages and PR description accordingly.

kjeremy · 2022-11-23T13:14:53Z

Can you show a before and after here?

chaoflow · 2022-11-23T13:40:10Z

@kjeremy

before

❯ nix build
error: getting status of '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version': No such file or directory
(use '--show-trace' to show detailed location information)
❯ nix build --show-trace
error: getting status of '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version': No such file or directory

       … while realising the context of path '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version'

       at /nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:12:17:

           11|
           12|       version = builtins.readFile ./.version + versionSuffix;
             |                 ^
           13|       versionSuffix =

       … while evaluating the attribute 'name'

       at /nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:288:13:

          287|           nix = with final; with commonDeps { inherit pkgs; }; currentStdenv.mkDerivation {
          288|             name = "nix-${version}";
             |             ^
          289|             inherit version;

       … while evaluating anonymous lambda

       at /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/lib/strings.nix:820:3:

          819|   in
          820|   string:
             |   ^
          821|   # First detect the common case of already valid strings, to speed those up

       … from call site

       at /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:295:9:

          294|         in
          295|         lib.strings.sanitizeDerivationName (
             |         ^
          296|           if attrs ? name

       … while evaluating the derivation attribute 'name'

       at /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7:

          277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
          278|       name =
             |       ^
          279|         let

after

❯ ../outputs/out/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes build
error: getting status of '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version': No such file or directory
(use '--show-trace' to show detailed location information)
❯ ../outputs/out/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes build --show-trace
error:
       … while evaluating the derivation attribute 'name'

       at /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7:

          277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
          278|       name =
             |       ^
          279|         let

       … from call site

       at /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:295:9:

          294|         in
          295|         lib.strings.sanitizeDerivationName (
             |         ^
          296|           if attrs ? name

       … while evaluating anonymous lambda

       at /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/lib/strings.nix:820:3:

          819|   in
          820|   string:
             |   ^
          821|   # First detect the common case of already valid strings, to speed those up

       … while evaluating the attribute 'name'

       at /nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:288:13:

          287|           nix = with final; with commonDeps { inherit pkgs; }; currentStdenv.mkDerivation {
          288|             name = "nix-${version}";
             |             ^
          289|             inherit version;

       … while realising the context of path '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version'

       at /nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:12:17:

           11|
           12|       version = builtins.readFile ./.version + versionSuffix;
             |                 ^
           13|       versionSuffix =

       getting status of '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version': No such file or directory

domenkozar · 2022-11-24T15:36:01Z

@edolstra 🙏

nixos-discourse · 2022-11-25T10:57:45Z

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

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

src/libutil/error.cc

Ericson2314 · 2022-11-28T16:09:35Z

We noticed that … from call site no longer made sense with the flipped order.

To catch such things I did

git grep -l 'makeDebugTraceStacker\|addErrorTrace\|addTrace'

and I came up with this diff: 6a36e18. There is certainly more thing we ought to change, but I think this is sufficient to make this PR at least make nothing worse than today. I would be happy doing the rest in follow-up PRs.

fricklerhandwerk · 2022-12-01T00:06:52Z

Triaged in Nix team meeting on 2022-11-25:

@edolstra: wondering if error messages are still correct when flipping the error
- @Ericson2314: I think the "whiles" can go before or after in English. We're in luck!

-> assigned to @fricklerhandwerk

nixos-discourse · 2022-12-01T00:18:35Z

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

https://discourse.nixos.org/t/2022-11-25-nix-team-meeting-minutes-11/23601/1

fricklerhandwerk

Discussed in Nix team meeting 2022-11-28:

complete discussion

@roberth: at call site is a regression because the grammar doesn't make sense any more in that order
@fricklerhandwerk: remove the attempt of imitating speech and make it a string of information bits
- it has to be readable in both directions, after all
@Ericson2314: should merge this as is and open an issue fixing the presentation minutiae
- don't want to make author do ever more additional things and get frustrated in the process
@fricklerhandwerk: this is again a UX issue which could be handled by experts much better
- we agree that the new order is obviously more suitable for finding the right information

Decision: @chaoflow This is good, only a few cosmetic fixups needed to improve readability. See the suggestions and please use @Ericson2314's diff to change the strings denoting the current action.

It should eventually look something like this, but we do this incrementally once this PR is merged:

❯ ../outputs/out/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes build
error: getting status of '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version': No such file or directory
(use '--show-trace' to show detailed location information)
❯ ../outputs/out/bin/nix --extra-experimental-features nix-command --extra-experimental-features flakes build --show-trace
evaluation trace:
---
evaluating the derivation attribute 'name'

/nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7:

  277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
  278|       name =
     |       ^
  279|         let
---
evaluating call site

/nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:295:9:

  294|         in
  295|         lib.strings.sanitizeDerivationName (
     |         ^
  296|           if attrs ? name
---
evaluating the attribute 'name'

/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:288:13:

  287|           nix = with final; with commonDeps { inherit pkgs; }; currentStdenv.mkDerivation {
  288|             name = "nix-${version}";
     |             ^
  289|             inherit version;
---
realising the context of path '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version'

/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:12:17:

   11|
   12|       version = builtins.readFile ./.version + versionSuffix;
     |                 ^
   13|       versionSuffix =
---
getting status of '/nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/.version': No such file or directory

src/libutil/error.cc

nixos-discourse · 2022-12-05T09:38:15Z

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

https://discourse.nixos.org/t/2022-11-28-nix-team-meeting-minutes-12/23730/1

bew · 2022-12-05T10:39:46Z

Slightly off-topic, on the formatting of the stack trace, can be dealt with in another PR

I have one concern with the suggested formatting in #7334 (review) : the blank lines and the --- seems to group together the source peek and the next frame message.

I'd like to suggest something like this (slightly inspired from Rust's error trace):

evaluating the derivation attribute 'name'

    --> /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7
     |
  277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
  278|       name =
     |       ^
  279|         let

evaluating call site

    --> /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:295:9
     |
  294|         in
  295|         lib.strings.sanitizeDerivationName (
     |         ^
  296|           if attrs ? name

evaluating the attribute 'name'

    --> /nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:288:13
     |
  287|           nix = with final; with commonDeps { inherit pkgs; }; currentStdenv.mkDerivation {
  288|             name = "nix-${version}";
     |             ^
  289|             inherit version;

Remove last : on /nix/store/.../foo.nix:line:col (not really needed with this format)
the only text that is at column 1 is a start of a new frame, everything else is nicely indented under it
link the path to the source peek (no blank line in between that breaks the frame reading flow)

I believe this format is easier to skim through with quick reading.

fricklerhandwerk · 2022-12-05T11:21:53Z

@bew sure, we can still improve cosmetics. Maybe get in touch with @Ericson2314 who wanted to address this more generally.

the blank lines and the --- seems to group together the source peek and the next frame message.

Not sure what you mean. But I may be wrong and grossly misreading to code...

bburdette · 2022-12-05T15:19:13Z

I think he means the lack of spaces between the error location and the next 'evaluating' phrase could lead some folks to think they belong together. Here "evaluating call site" might be interpreted at first glance as belonging to the code above it.


/nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7:

  277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
  278|       name =
     |       ^
  279|         let
---
evaluating call site

With the format proposed by @bew, having a colon at the end of the 'evaluating' line would help reduce ambiguity about what belongs to what:

evaluating the derivation attribute 'name':

    --> /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7
     |
  277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
  278|       name =
     |       ^
  279|         let

Ericson2314 · 2022-12-05T15:33:34Z

If there is some disagreement on what the best formatting is, then I recommend we just add 6a36e18, simplify the for loop per the line comment, and circle back later.

That keeps this PR just the uncontroversial stuff about traceback order along with the bare minimum changing the messages to not regress.

chaoflow · 2022-12-05T15:48:53Z

Building on @bew 's proposal but reducing some whitespace:

Evaluating the derivation attribute 'name' at
  /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:278:7
     |
  277|     // (lib.optionalAttrs (attrs ? name || (attrs ? pname && attrs ? version)) {
  278|       name =
     |       ^
  279|         let

Evaluating call site at
  /nix/store/vp7k2rx0w0yidr691mmq62z6hragpbzx-source/pkgs/stdenv/generic/make-derivation.nix:295:9
     |
  294|         in
  295|         lib.strings.sanitizeDerivationName (
     |         ^
  296|           if attrs ? name

Evaluating the attribute 'name' at
  /nix/store/qz0f0nw8siij1xw7cdk4n20xga6frhrs-source/broken/flake.nix:288:13
     |
  287|           nix = with final; with commonDeps { inherit pkgs; }; currentStdenv.mkDerivation {
  288|             name = "nix-${version}";
     |             ^
  289|             inherit version;

fricklerhandwerk · 2022-12-05T16:28:36Z

@chaoflow I like this a lot. I'd only propose keeping capitalisation out, because it makes reshuffling information harder. We already noticed that assuming too much grammatical structure can be a hindrance to change.

Would be great if you make that change, either here or in a follow-up PR (which I prefer because small changes are easier to review).

chaoflow · 2022-12-09T18:10:33Z

@Ericson2314 thx - got it! Changing the loop entails a bit more work, will look at it later.

Ericson2314

Thanks so much! This looks good to me now. The rest we can do in follow-up PRs.

Ericson2314 · 2022-12-09T19:33:26Z

Asking @roberth for a review since it was he that found those "from ..." messages that were the issue to begin with.

fricklerhandwerk

The build broke, please check again.

src/libutil/error.cc

When debugging nix expressions the outermost trace tends to be more useful than the innermost. It is therefore printed last to save developers from scrolling.

Save developers from scrolling by displaying the error message last, below the stack trace.

Make everything be in the form "while ..." (most things were already), and in particular *don't* use other propositions that must go after or before specific "while ..." clauses to make sense.

Ericson2314 · 2022-12-12T21:14:46Z

Yay! @chaoflow you up for the reformatting follow-up PR now?

chaoflow · 2022-12-16T13:16:40Z

@Ericson2314 Yes, happy to.

domenkozar · 2022-12-21T15:45:32Z

Follow up: #7494

chaoflow marked this pull request as draft November 22, 2022 14:25

chaoflow force-pushed the stack-trace-order branch from 128eee4 to a6915c8 Compare November 22, 2022 16:48

domenkozar requested a review from edolstra November 22, 2022 17:43

chaoflow changed the title ~~WIP: Don't reverse stack trace when showing~~ Don't reverse stack trace when showing Nov 22, 2022

chaoflow marked this pull request as ready for review November 22, 2022 17:58

chaoflow force-pushed the stack-trace-order branch from a6915c8 to 1319b96 Compare November 23, 2022 12:28

chaoflow changed the title ~~Don't reverse stack trace when showing~~ Show stack trace above error message with innermost first Nov 23, 2022

edolstra added UX The way in which users interact with Nix. Higher level than UI. error-messages Confusing messages and better diagnostics labels Nov 24, 2022

thufschmitt assigned fricklerhandwerk Nov 25, 2022

tfc reviewed Nov 25, 2022

View reviewed changes

src/libutil/error.cc Outdated Show resolved Hide resolved

fricklerhandwerk approved these changes Dec 5, 2022

View reviewed changes

src/libutil/error.cc Outdated Show resolved Hide resolved

src/libutil/error.cc Show resolved Hide resolved

chaoflow force-pushed the stack-trace-order branch from 6623c83 to 2e093ae Compare December 9, 2022 18:10

Ericson2314 approved these changes Dec 9, 2022

View reviewed changes

Ericson2314 requested a review from roberth December 9, 2022 19:32

fricklerhandwerk requested changes Dec 10, 2022

View reviewed changes

src/libutil/error.cc Outdated Show resolved Hide resolved

chaoflow force-pushed the stack-trace-order branch from 2e093ae to 21974be Compare December 12, 2022 18:10

Ericson2314 reviewed Dec 12, 2022

View reviewed changes

src/libutil/error.cc Outdated Show resolved Hide resolved

chaoflow force-pushed the stack-trace-order branch from 21974be to 46a211b Compare December 12, 2022 18:40

chaoflow and others added 4 commits December 12, 2022 18:41

Don't reverse stack trace when showing

173dcb0

When debugging nix expressions the outermost trace tends to be more useful than the innermost. It is therefore printed last to save developers from scrolling.

Show stack trace above error message

d269976

Save developers from scrolling by displaying the error message last, below the stack trace.

Fix stack context notes to not rely on order

7b122d4

Make everything be in the form "while ..." (most things were already), and in particular *don't* use other propositions that must go after or before specific "while ..." clauses to make sense.

Simplify loop, feedback from @tfc and @Ericson2314

8618c6c

chaoflow force-pushed the stack-trace-order branch from 46a211b to 8618c6c Compare December 12, 2022 18:41

chaoflow requested review from fricklerhandwerk and removed request for roberth, edolstra and thufschmitt December 12, 2022 19:24

Ericson2314 approved these changes Dec 12, 2022

View reviewed changes

fricklerhandwerk approved these changes Dec 12, 2022

View reviewed changes

fricklerhandwerk merged commit edb54c6 into NixOS:master Dec 12, 2022

chaoflow deleted the stack-trace-order branch December 13, 2022 13:45

roberth mentioned this pull request Dec 29, 2022

lib/types: make either expose submodules NixOS/nixpkgs#208227

Draft

roberth mentioned this pull request Jan 20, 2023

Coerce strings fixups #7641

Merged

3 tasks

roberth added the language The Nix expression language; parser, interpreter, primops, evaluation, etc label Jul 2, 2023

layus mentioned this pull request Feb 7, 2024

Show the first few and last few stack frames by default #9962

Open

9999years mentioned this pull request Feb 23, 2024

Do not skip any stack frames when --show-trace is given #10066

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Show stack trace above error message with innermost first #7334

Show stack trace above error message with innermost first #7334

chaoflow commented Nov 22, 2022 •

edited

domenkozar commented Nov 22, 2022

chaoflow commented Nov 22, 2022

fricklerhandwerk commented Nov 23, 2022

chaoflow commented Nov 23, 2022

kjeremy commented Nov 23, 2022

chaoflow commented Nov 23, 2022

domenkozar commented Nov 24, 2022

nixos-discourse commented Nov 25, 2022

Ericson2314 commented Nov 28, 2022 •

edited

fricklerhandwerk commented Dec 1, 2022

nixos-discourse commented Dec 1, 2022

fricklerhandwerk left a comment •

edited

nixos-discourse commented Dec 5, 2022

bew commented Dec 5, 2022

fricklerhandwerk commented Dec 5, 2022

bburdette commented Dec 5, 2022

Ericson2314 commented Dec 5, 2022 •

edited

chaoflow commented Dec 5, 2022

fricklerhandwerk commented Dec 5, 2022 •

edited

chaoflow commented Dec 9, 2022

Ericson2314 left a comment

Ericson2314 commented Dec 9, 2022

fricklerhandwerk left a comment

Ericson2314 commented Dec 12, 2022

chaoflow commented Dec 16, 2022

domenkozar commented Dec 21, 2022

Show stack trace above error message with innermost first #7334

Show stack trace above error message with innermost first #7334

Conversation

chaoflow commented Nov 22, 2022 • edited

domenkozar commented Nov 22, 2022

chaoflow commented Nov 22, 2022

fricklerhandwerk commented Nov 23, 2022

chaoflow commented Nov 23, 2022

kjeremy commented Nov 23, 2022

chaoflow commented Nov 23, 2022

before

after

domenkozar commented Nov 24, 2022

nixos-discourse commented Nov 25, 2022

Ericson2314 commented Nov 28, 2022 • edited

fricklerhandwerk commented Dec 1, 2022

nixos-discourse commented Dec 1, 2022

fricklerhandwerk left a comment • edited

Choose a reason for hiding this comment

nixos-discourse commented Dec 5, 2022

bew commented Dec 5, 2022

fricklerhandwerk commented Dec 5, 2022

bburdette commented Dec 5, 2022

Ericson2314 commented Dec 5, 2022 • edited

chaoflow commented Dec 5, 2022

fricklerhandwerk commented Dec 5, 2022 • edited

chaoflow commented Dec 9, 2022

Ericson2314 left a comment

Choose a reason for hiding this comment

Ericson2314 commented Dec 9, 2022

fricklerhandwerk left a comment

Choose a reason for hiding this comment

Ericson2314 commented Dec 12, 2022

chaoflow commented Dec 16, 2022

domenkozar commented Dec 21, 2022

chaoflow commented Nov 22, 2022 •

edited

Ericson2314 commented Nov 28, 2022 •

edited

fricklerhandwerk left a comment •

edited

Ericson2314 commented Dec 5, 2022 •

edited

fricklerhandwerk commented Dec 5, 2022 •

edited