GNU bug report logs - #36471
Unreadable Stacktrace Example

Previous Next

To reply to this bug, email your comments to 36471 AT debbugs.gnu.org.

Toggle the display of automated, internal messages from the tracker.

Message #5 received at submit <at> debbugs.gnu.org (full text, mbox):

From: Björn Höfling <bjoern.hoefling <at> bjoernhoefling.de>
To: <bug-guix <at> gnu.org>
Subject: Unreadable Stacktrace Example
Date: Tue, 2 Jul 2019 13:12:45 +0200

[Message part 1 (text/plain, inline)]

X-Debbugs-CC: Robert Vollmert <rob <at> vllmrt.net>

Hello,

in the 1.0-beyond-discussions, Robert asked that Stacktraces should be
more clear. I refer to this message (lists.gnu.org is down, so I
cannot link):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Robert Vollmert <rob <at> vllmrt.net>
Subject: Re: Guix beyond 1.0: let’s have a roadmap!
Message-ID: <878stirsdc.fsf <at> gnu.org>

Here is my example. I'm on top of

48eb71aea807262210c38b5fb675d747adfccff3

First the full stacktrace, below are some comments:

./pre-inst-env  guix lint -c cve freecad                         
Backtrace:reecad <at> 0.18.2-1.dbb4cc6 [cve]...
          11 (apply-smob/1 #<catch-closure 1a071a0>)
In ice-9/boot-9.scm:
    705:2 10 (call-with-prompt _ _ #<procedure default-prompt-handle?>)
In ice-9/eval.scm:
    619:8  9 (_ #(#(#<directory (guile-user) 1ac5140>)))
In guix/ui.scm:
  1668:12  8 (run-guix-command _ . _)
In srfi/srfi-1.scm:
    640:9  7 (for-each #<procedure 1df01a0 at guix/scripts/lint.scm?> ?)
In guix/scripts/lint.scm:
   1152:4  6 (run-checkers #<package freecad <at> 0.18.2-1.dbb4cc6 gnu/p?> ?)
In srfi/srfi-1.scm:
    640:9  5 (for-each #<procedure 3e473c0 at guix/scripts/lint.scm?> ?)
In guix/scripts/lint.scm:
    933:4  4 (check-vulnerabilities _)
    928:9  3 (_ _)
In unknown file:
           2 (force #<promise #<procedure 7f1ce3ab6228 at guix/scrip?>)
In guix/scripts/lint.scm:
   917:24  1 (_)
In ice-9/boot-9.scm:
    829:9  0 (catch srfi-34 #<procedure 37e64e0 at guix/scripts/lin?> ?)

ice-9/boot-9.scm:829:9: In procedure catch:
In procedure connect: Connection timed out


OK, this is semi-readable but I will explain a bit what I find
strange/unreadable:

In guix/scripts/lint.scm:
   1152:4  6 (run-checkers #<package freecad <at> 0.18.2-1.dbb4cc6 gnu/p?> ?)

--> OK: This is perfectly readable. I know in which procedure I am,
in which line, the line matches my source code. Fine.

In srfi/srfi-1.scm:
    640:9  5 (for-each #<procedure 3e473c0 at guix/scripts/lint.scm?> ?)

--> This is OK, though it could print the line of the procedure?

In guix/scripts/lint.scm:
    933:4  4 (check-vulnerabilities _)
    928:9  3 (_ _)

--> 933: Nice, I'm in check-vulnerabilities. But why is there no argument?
--> What is this strange second line: (_ _)? Why is there nothing written?
Is that due to tail-recursion?


In unknown file:
           2 (force #<promise #<procedure 7f1ce3ab6228 at guix/scrip?>)

--> Why is this in a "unknown file"?
--> Is this force/promise making my stacktrace more unreadable?

In guix/scripts/lint.scm:
   917:24  1 (_)

--> Uh. Any more details?. Is "(_)" the call to "(current-vulnerabilities*)"?!

In ice-9/boot-9.scm:
    829:9  0 (catch srfi-34 #<procedure 37e64e0 at guix/scripts/lin?> ?)

ice-9/boot-9.scm:829:9: In procedure catch:
In procedure connect: Connection timed out

--> Now, wait: The real problem happens somewhere down here and I don't
have any detailed stacktrace about that?

I have to manually go down into current-vulnerabilities*,
call/nw/failsaife, etc? Why don't I get the details from here?

Is this because in "call-with-networking-fail-safe", line 900 we
through newly:

        (args
         (apply throw args))))))

but then the stacktrace gets lost?

Would there be a throw-with-caused-by?

Björn

[Message part 2 (application/pgp-signature, inline)]

Message #10 received at 36471 <at> debbugs.gnu.org (full text, mbox):

From: Ludovic Courtès <ludo <at> gnu.org>
To: Björn Höfling <bjoern.hoefling <at> bjoernhoefling.de>
Cc: 36471 <at> debbugs.gnu.org, robert vollmert <rob <at> vllmrt.net>
Subject: Re: bug#36471: Unreadable Stacktrace Example
Date: Sun, 07 Jul 2019 16:38:08 +0200

Hi Björn,

I’m reassigning this bug report to ‘guile’.  :-)

Björn Höfling <bjoern.hoefling <at> bjoernhoefling.de> skribis:

> First the full stacktrace, below are some comments:
>
> ./pre-inst-env  guix lint -c cve freecad                         
> Backtrace:reecad <at> 0.18.2-1.dbb4cc6 [cve]...
>           11 (apply-smob/1 #<catch-closure 1a071a0>)
> In ice-9/boot-9.scm:
>     705:2 10 (call-with-prompt _ _ #<procedure default-prompt-handle?>)
> In ice-9/eval.scm:
>     619:8  9 (_ #(#(#<directory (guile-user) 1ac5140>)))
> In guix/ui.scm:
>   1668:12  8 (run-guix-command _ . _)
> In srfi/srfi-1.scm:
>     640:9  7 (for-each #<procedure 1df01a0 at guix/scripts/lint.scm?> ?)
> In guix/scripts/lint.scm:
>    1152:4  6 (run-checkers #<package freecad <at> 0.18.2-1.dbb4cc6 gnu/p?> ?)
> In srfi/srfi-1.scm:
>     640:9  5 (for-each #<procedure 3e473c0 at guix/scripts/lint.scm?> ?)
> In guix/scripts/lint.scm:
>     933:4  4 (check-vulnerabilities _)
>     928:9  3 (_ _)
> In unknown file:
>            2 (force #<promise #<procedure 7f1ce3ab6228 at guix/scrip?>)
> In guix/scripts/lint.scm:
>    917:24  1 (_)
> In ice-9/boot-9.scm:
>     829:9  0 (catch srfi-34 #<procedure 37e64e0 at guix/scripts/lin?> ?)
>
> ice-9/boot-9.scm:829:9: In procedure catch:
> In procedure connect: Connection timed out

[...]

> In guix/scripts/lint.scm:
>     933:4  4 (check-vulnerabilities _)
>     928:9  3 (_ _)
>
> --> 933: Nice, I'm in check-vulnerabilities. But why is there no argument?
> --> What is this strange second line: (_ _)? Why is there nothing written?

Good question, I’m not sure why that happens, but hopefully it’s easily
fixed.

> In unknown file:
>            2 (force #<promise #<procedure 7f1ce3ab6228 at guix/scrip?>)
>
> --> Why is this in a "unknown file"?

Because ‘force’ is implemented in C, so there’s no source location info
available.

> --> Is this force/promise making my stacktrace more unreadable?

No.

> In guix/scripts/lint.scm:
>    917:24  1 (_)
>
> --> Uh. Any more details?. Is "(_)" the call to "(current-vulnerabilities*)"?!

Dunno.  :-/

> In ice-9/boot-9.scm:
>     829:9  0 (catch srfi-34 #<procedure 37e64e0 at guix/scripts/lin?> ?)
>
> ice-9/boot-9.scm:829:9: In procedure catch:
> In procedure connect: Connection timed out
>
> --> Now, wait: The real problem happens somewhere down here and I don't
> have any detailed stacktrace about that?
>
> I have to manually go down into current-vulnerabilities*,
> call/nw/failsaife, etc? Why don't I get the details from here?

Part of what makes information “disappear” from stack traces is the
tail-call optimization (TCO).  If F calls G, and G then calls H in tail
position, then the backtrace will suggest that F called H (G doesn’t
appear at all.)

IIRC Chez Scheme has a fancy trick that allows it to keep track of part
of the “conceptual” stack trace, without losing the space guarantees
that TCO provides.  It cannot come for free though, but I wonder if
Guile should provide it in ‘--debug’ mode or something.

> Is this because in "call-with-networking-fail-safe", line 900 we
> through newly:
>
>         (args
>          (apply throw args))))))
>
> but then the stacktrace gets lost?
>
> Would there be a throw-with-caused-by?

Not sure what you mean, but note that in many cases ‘throw’ itself is
called in tail position, which can also contribute to obfuscating the
stack trace…

Thanks,
Ludo’.

Previous Next

GNU bug tracking system
Copyright (C) 1999 Darren O. Benham, 1997,2003 nCipher Corporation Ltd, 1994-97 Ian Jackson.