[PATCH] Don't truncate backtraces

  • Open
  • quality assurance status badge
Details
3 participants
  • David Pirotte
  • Mark H Weaver
  • Robert Vollmert
Owner
unassigned
Submitted by
Robert Vollmert
Severity
normal
R
R
Robert Vollmert wrote on 15 Jul 2019 22:29
(address . bug-guile@gnu.org)(name . Robert Vollmert)(address . rob@vllmrt.net)
20190715202918.92925-1-rob@vllmrt.net
* module/system/repl/debug.scm (print-frame): Print full object if
width keyword is #f.
* libguile/backtrace.c (display_backtrace_body): Call print-frames
with #:width #f.
---

This change was prompted by recent discussion on the Guix lists:
In Guix, the truncation of stack traces frequently obscures
important information due to the long filenames.

Apologies if this misses some obvious things, I'm not particularly
at home in the Guile sources. Let me know, happy to adapt!

Cheers
Robert

libguile/backtrace.c | 6 ++++--
module/system/repl/debug.scm | 13 +++++++++----
2 files changed, 13 insertions(+), 6 deletions(-)

Toggle diff (57 lines)
diff --git a/libguile/backtrace.c b/libguile/backtrace.c
index 4a19d4b8a..4d0b4ab94 100644
--- a/libguile/backtrace.c
+++ b/libguile/backtrace.c
@@ -77,6 +77,7 @@ boot_print_exception (SCM port, SCM frame, SCM key, SCM args)
static SCM print_exception_var;
static SCM print_frame_var;
static SCM kw_count;
+static SCM kw_width;
static SCM print_frames_var;
static SCM frame_to_stack_vector_var;
@@ -99,6 +100,7 @@ static void
init_print_frames_var_and_frame_to_stack_vector_var (void)
{
kw_count = scm_from_latin1_keyword ("count");
+ kw_width = scm_from_latin1_keyword ("width");
print_frames_var =
scm_c_public_variable ("system repl debug", "print-frames");
frame_to_stack_vector_var =
@@ -236,8 +238,8 @@ display_backtrace_body (struct display_backtrace_args *a)
scm_stack_ref (a->stack, a->first));
/* FIXME: highlight_objects */
- scm_call_4 (scm_variable_ref (print_frames_var), frames, a->port,
- kw_count, a->depth);
+ scm_call_6 (scm_variable_ref (print_frames_var), frames, a->port,
+ kw_count, a->depth, kw_width, SCM_BOOL_F);
return SCM_UNSPECIFIED;
}
diff --git a/module/system/repl/debug.scm b/module/system/repl/debug.scm
index 383d37921..7422bf980 100644
--- a/module/system/repl/debug.scm
+++ b/module/system/repl/debug.scm
@@ -135,10 +135,15 @@
(col (and=> source source:column)))
(if (and file (not (equal? file (source:pretty-file last-source))))
(format port "~&In ~a:~&" file))
- (format port "~9@a~:[~*~3_~;~3d~] ~v:@y~%"
- (if line (format #f "~a:~a" line col) "")
- index index width
- (frame-call-representation frame #:top-frame? (zero? index)))
+ (if width
+ (format port "~9@a~:[~*~3_~;~3d~] ~v:@y~%"
+ (if line (format #f "~a:~a" line col) "")
+ index index width
+ (frame-call-representation frame #:top-frame? (zero? index)))
+ (format port "~9@a~:[~*~3_~;~3d~] ~a~%"
+ (if line (format #f "~a:~a" line col) "")
+ index index
+ (frame-call-representation frame #:top-frame? (zero? index))))
(if full?
(print-locals frame #:width width
#:per-line-prefix " "))))
--
2.20.1 (Apple Git-117)
M
M
Mark H Weaver wrote on 17 Jul 2019 19:57
(name . Robert Vollmert)(address . rob@vllmrt.net)(address . 36677@debbugs.gnu.org)
87ef2ownkf.fsf@netris.org
Hi Robert,

Robert Vollmert <rob@vllmrt.net> writes:

Toggle quote (11 lines)
> * module/system/repl/debug.scm (print-frame): Print full object if
> width keyword is #f.
> * libguile/backtrace.c (display_backtrace_body): Call print-frames
> with #:width #f.
> ---
>
> This change was prompted by recent discussion on the Guix lists:
> https://lists.gnu.org/archive/html/guix-devel/2019-07/msg00207.html
> In Guix, the truncation of stack traces frequently obscures
> important information due to the long filenames.

I'm sympathetic to this problem, but simply disabling the truncated
printing during backtraces is not workable. It is quite often the case
that some of the structures printed in backtraces are *huge*, or even
cyclic.

Have you tried setting the COLUMNS environment variable to a larger
value? I'd prefer a solution along those lines, where the user can set
an environment variable to ask for less truncation in backtraces.

Thanks,
Mark
R
R
Robert Vollmert wrote on 17 Jul 2019 20:11
(name . Mark H Weaver)(address . mhw@netris.org)(address . 36677@debbugs.gnu.org)
827D6B68-7E10-47BD-9419-A8471C9A0090@vllmrt.net
Toggle quote (26 lines)
> On 17. Jul 2019, at 19:57, Mark H Weaver <mhw@netris.org> wrote:
>
> Hi Robert,
>
> Robert Vollmert <rob@vllmrt.net> writes:
>
>> * module/system/repl/debug.scm (print-frame): Print full object if
>> width keyword is #f.
>> * libguile/backtrace.c (display_backtrace_body): Call print-frames
>> with #:width #f.
>> ---
>>
>> This change was prompted by recent discussion on the Guix lists:
>> https://lists.gnu.org/archive/html/guix-devel/2019-07/msg00207.html
>> In Guix, the truncation of stack traces frequently obscures
>> important information due to the long filenames.
>
> I'm sympathetic to this problem, but simply disabling the truncated
> printing during backtraces is not workable. It is quite often the case
> that some of the structures printed in backtraces are *huge*, or even
> cyclic.
>
> Have you tried setting the COLUMNS environment variable to a larger
> value? I'd prefer a solution along those lines, where the user can set
> an environment variable to ask for less truncation in backtraces.

Defaulting to something longer than 80 might be workable, say 250?

I don’t think that it should be necessary to set an environment variable
to get usable stack traces…
R
R
Robert Vollmert wrote on 21 Jul 2019 17:35
(name . Mark H Weaver)(address . mhw@netris.org)(address . 36677@debbugs.gnu.org)
D5475C37-C3E9-468C-B59E-496CB5CA7DCB@vllmrt.net
Toggle quote (35 lines)
> On 17. Jul 2019, at 20:11, Robert Vollmert <rob@vllmrt.net> wrote:
>
>
>
>> On 17. Jul 2019, at 19:57, Mark H Weaver <mhw@netris.org> wrote:
>>
>> Hi Robert,
>>
>> Robert Vollmert <rob@vllmrt.net> writes:
>>
>>> * module/system/repl/debug.scm (print-frame): Print full object if
>>> width keyword is #f.
>>> * libguile/backtrace.c (display_backtrace_body): Call print-frames
>>> with #:width #f.
>>> ---
>>>
>>> This change was prompted by recent discussion on the Guix lists:
>>> https://lists.gnu.org/archive/html/guix-devel/2019-07/msg00207.html
>>> In Guix, the truncation of stack traces frequently obscures
>>> important information due to the long filenames.
>>
>> I'm sympathetic to this problem, but simply disabling the truncated
>> printing during backtraces is not workable. It is quite often the case
>> that some of the structures printed in backtraces are *huge*, or even
>> cyclic.
>>
>> Have you tried setting the COLUMNS environment variable to a larger
>> value? I'd prefer a solution along those lines, where the user can set
>> an environment variable to ask for less truncation in backtraces.
>
> Defaulting to something longer than 80 might be workable, say 250?
>
> I don’t think that it should be necessary to set an environment variable
> to get usable stack traces…

I’d like to add that the current code to determine terminal width
seems to be broken. COLUMNS is a bash-local variable, it’s not typically
set anywhere as an environment variable.

Some ways to get actual terminal size:

$ tput cols # from ncurses
80
$ stty size # from coreutils
25 80

Though it’s unclear how these work in non-interactive situations.
D
D
David Pirotte wrote on 22 Jul 2019 00:59
(name . Mark H Weaver)(address . mhw@netris.org)
20190721195943.096ebac6@capac
Hello Mark,

Toggle quote (10 lines)
> > This change was prompted by recent discussion on the Guix lists:
> > https://lists.gnu.org/archive/html/guix-devel/2019-07/msg00207.html
> > In Guix, the truncation of stack traces frequently obscures
> > important information due to the long filenames.

> I'm sympathetic to this problem, but simply disabling the truncated
> printing during backtraces is not workable. It is quite often the case
> that some of the structures printed in backtraces are *huge*, or even
> cyclic.

I am very pleased to read that you think it is important to enable truncated
printing as a default for backtrace, I think so to. But maybe Guile could provide an
easy mechanism to overwrite these defaults, using procedures, or parameters? (not
depending on an 'external' variable I mean (*)

I wrote "these defaults", "procedures or parameters", using plural, because I think
that the default should also enable truncated printing for the repl and the
raised exception system, what do you think?

I wrote about this a couple of times, and as a gentle ping, here is my last email
about this request, which is a good summary which also points to other discussion on
this topic:


David.

(*) if an easy mechanism would depends on variables, let's make these Guile
variable then. like GUILE_BACKTRACE_PRINTER_TO_USE_N_COLUMN_AT_MOST
(or what ever, I am not the best to name things ...),
GUILE_REPL_PRINTER_TO_USE_N_COLUMN_AT_MOST and
GUILE_RAISED_EXCEPTION_SYSTEM_TO_USE_N_COLUMN_AT_MOST, with -1 meaning no
truncated printing ...

But I would prefer procedures to set these, 'keeping' the default to be what
truncated-print uses as defined 'now', in (ice-9 pretty-print), so we could use
them in our repl, our .guile, or the global init.scm setting, and change that on the
fly as we wish ... as for the procedure names, or one procedure and two args, one
for the parmeter to set, one for the value ... let's think about it ...
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCgAdFiEEhCJlRZtBM3furJHe83T9k6MFetcFAl007l8ACgkQ83T9k6MF
etfXzAf/cm1L65b2npLdjB/CpH+r2Vsjxfp7g4J29TBSAEmopVpoaDXA16wlpJ5z
53V2KkhX7pIrAXoeci46h7af/NRPSWkgfOZ/popEyxcfHpmZpluFVJ72wCIx4+b5
gBbe2pdp1ROoAjNF+lUUaWElZwLCLSWxZ6dnj95aRsLyZxllQfstQczXYNovMlwd
4CuoIlXssn85wMUdlUgh1wgHzUMNUqwRLvSL7Zt7Gf47cZrPQlkvkp7X6OX7fogl
EEh6zgefYWR5R7RLvrThIdHfJ5S3BMhAYVV2KElUcX+uFbr7ZOrciKslGtkm4Yka
FKDhbW/GHCX0nteHmZLKjAd28fPS3w==
=+MGU
-----END PGP SIGNATURE-----


M
M
Mark H Weaver wrote on 22 Jul 2019 02:33
(name . David Pirotte)(address . david@altosw.be)
87lfwq52lv.fsf@netris.org
Hi David,

Toggle quote (6 lines)
> I am very pleased to read that you think it is important to enable
> truncated printing as a default for backtrace, I think so to. But
> maybe Guile could provide an easy mechanism to overwrite these
> defaults, using procedures, or parameters? (not depending on an
> 'external' variable I mean (*)

You can see now that there are pressures coming from both directions on
this issue. There are complaints that we truncate too much information,
and other complaints that we don't truncate often enough. There are
proposals to never truncate anything by default, and proposals to
truncate everything by default.

Toggle quote (4 lines)
> I wrote "these defaults", "procedures or parameters", using plural,
> because I think that the default should also enable truncated printing
> for the repl and the raised exception system, what do you think?

I'm reluctant to truncate REPL output by default for a few reasons:

(1) Historically, the Guile has never truncated REPL output, and I'm
concerned that changing the default behavior may violate longstanding user expectations. I, for one,
often ask for a moderately large data structure to be computed and
printed at the REPL, and I normally want to see the whole thing.

(2) Some software may act as a front-end for the Guile REPL, sending
commands to it and interpreting the output. For example, I believe that
Geiser does this. I'm concerned that changing the default truncation
behavior may cause problems here.

(3) I'm not confident that 'truncated-print' is fully robust for
arbitrary data types. I would need to make a careful audit of the code.

(4) The Guile REPL already provides a way to specify a custom printer,
so there's nothing stopping you from installing 'truncated-print' as the
REPL printer.

Regarding truncating exception printing by default, I'm inclined to
think that it's better to err on the side of printing too much than too
little. If an uncaught exception occurs, that clearly indicates an
error, and if we truncate the error report, that might make the
difference between being able to figure out what went wrong and being
unable to do so, especially if the error is not easily reproducible.

Your position on this is pretty much the opposite of what Robert
Vollmert is advocating here, although to be precise he's talking about
backtraces whereas you're now talking about exception conditions.
Still, they both seem to be in the same area.

To be honest, the main reason I find lack of truncation painful
sometimes is because Emacs does not cope well with extremely long lines,
to put it mildly. Honestly, that's a flaw in Emacs, and it seems like
it would be better to fix Emacs than to work around it in Guile by
omitting potentially useful information from error reports by default.

I need to think more on this. In the meantime, I welcome opinions.

Regards.
Mark
D
D
David Pirotte wrote on 25 Jul 2019 18:27
(name . Mark H Weaver)(address . mhw@netris.org)
20190725132757.60e2e1cb@capac
Hi Mark,

Toggle quote (3 lines)
> You can see now that there are pressures coming from both directions
> on this issue.

I always 'did see' that, my point is that enabling truncated printing
should be the default, and that we should be able to 'toggle' that to
full printing anytime ... for the repl, errors, and backtraces, The
'toggle' should be made so easy that we could bind it to, say, F8 or
another key, then hit it when needed ... not matter how easy is the
'toggle' mechanism though, the default should be, imo, to enable
truncated printing for he repl, errors, and backtraces.

Fwiw, I recently helped two quite advanced guilers, on #guile, one did
ask if he could 'truncate' and how, I pointed to the guile-cv
documentation, the other said: "I wish I new this was possible ...".

Currently, wrt to errors, it is very difficult, next to impossible, to
configure guile to enable truncated printing, and the above user, an
advanced guiler, answered, when I also pointed to a complete 'recipe',
in the guile-cv doc, '... thanks but I 'm gona get there ...' (or
something along the lines, I don't remember the exact words - it was
very clear though, that he was afraid to 'just' apply the recipe).

It seems, from Robert's email, that it is currently quite difficult, if
not impossible, to toggle bactraces to full printing.

Toggle quote (4 lines)
> (1) Historically, the Guile has never truncated REPL output, and I'm
> concerned that changing the default behavior may violate longstanding
> user expectations.

'Historically' stands, imo, as an explanation, not as a justification
for a 'no change' ... we did change, and it did break user code, from
1.8 to 2.0 ... I don't think this change will break anything, but even
though, 2.2 -> 3.0 is 'an opportunity', should we agree of course ...

Toggle quote (4 lines)
> I, for one, often ask for a moderately large data structure to be
> computed and printed at the REPL, and I normally want to see the
> whole thing.

You are an expert, you know it is possible, you know how ...

The persons I am 'targeting' to become guile-cv users are newbies,
although highly educated in their domain, they don't know what scheme
is, they don't even know the word 'Lisp', they don't understand I
have to configure Guile so they can use it ... and tell me, for the
very few I could 'sit next to' and configure for them, that they would
never ever do that themselves ... not even the 'simple' (simple for us),
repl config ...

Then as exposed above, even advanced guilers don't know, and when
informed 'how to', don't want to 'risk' lots of 'small changes' in
(ice-9 boot), which is understandable, I'm not 'jugging' ...

Toggle quote (5 lines)
> (2) Some software may act as a front-end for the Guile REPL, sending
> commands to it and interpreting the output. For example, I believe
> that Geiser does this. I'm concerned that changing the default
> truncation behavior may cause problems here.

I use geiser, and never ever had a problem - but if I would I would
have talked to Jao, who's extremely responsive ... and he would have
solved the problem, but I never had a single problem: geiser only
interprets certain pattern, like guile-cv's output, to display images
in emacs ... so truncated print is not a problem at all for geier,
afaict at least.

Toggle quote (4 lines)
> (3) I'm not confident that 'truncated-print' is fully robust for
> arbitrary data types. I would need to make a careful audit of the
> code.

Again, imo, it explains, but does not stand as a justification for a
'no change': we could reuse the backtrace 'trunker', or make
truncaped-print robust, I never had a single truncated-print related
problem in years though, not a proof, but quite a good 'start' ...

Toggle quote (4 lines)
> (4) The Guile REPL already provides a way to specify a custom printer,
> so there's nothing stopping you from installing 'truncated-print' as
> the REPL printer.

Imo, no matter how easy it is to change, the default should be to
enable truncated printing for the repl, erros and backtraces, then
indeed we should have 'dead easy' 'toggle' mechanism for those
'extremely rare' guilers who want (occasionally in my experience, I
sometimes do to of course) full print ...

Toggle quote (7 lines)
> To be honest, the main reason I find lack of truncation painful
> sometimes is because Emacs does not cope well with extremely long
> lines, to put it mildly. Honestly, that's a flaw in Emacs, and it
> seems like it would be better to fix Emacs than to work around it in
> Guile by omitting potentially useful information from error reports
> by default.

I strongly disagree with you: it is a guile and not an emacs problem.
But it also is impossible to work in a terminal, just try guile-cv,
it won't last minutes that you get totally crasy :) so to speak of
course, and wish truncated printing would be enable for the repl, erros
and backtraces, by default.

I should also add that typical image sizes that 'we' need to process
using gule-cv (or open-cv, imagej ...) are not small, made in average
of 20 millions+ pixels ... but you may try guile-cv even using small
images, in a terminal, it's not workable 'as is ...'

David
-----BEGIN PGP SIGNATURE-----

iQEzBAEBCgAdFiEEhCJlRZtBM3furJHe83T9k6MFetcFAl052I0ACgkQ83T9k6MF
etem1gf/e0A1ErSOg0IFKWzGnaT+r6FkhgiFKYRKO6K/nSxvKCKlC9UZvQm0M4K/
SPvdz7izBvrukRU2vYksWQXght5blbuPopowQetG/tm7W83clxVC+RiwjB6I93Nh
1BAyXB8nAc/7vFY6YQC0WV6H9S20Wzk/dabr3OEPA+/8STmWbhVIJm6uEaemKjkL
fS0auLCToxoaCZpjmSDdu9pwZrNe9gTI88ddYG3exNQcPPUBdDhYS+7f5NPLO0Zh
zn6bmN51PGC4hjFXsdqSGJycHeW+Qque8rByyfFsOglZC4VCQ4WAzQL9rCH3gwt1
XDI4cqBDoeREvvUxy9HSX7H7cYnRKg==
=Iytg
-----END PGP SIGNATURE-----


?