bug#16358: combinatorial explosion in elided stack trace

[Andy Wingo]

Hi Zefram,

Thanks for the great report!

I believe this is fixed in v2.1.3.  Reproducing the bug is a little
different there but I think I did get it so that Guile should try to
print out the value.  I don't know if we would be able to fix this in
2.0 though :/  I am closing because I believe it to be fixed, albeit in
the next release series.

Regards,

Andy

On Mon 06 Jan 2014 00:02, Zefram <address@hidden> writes:

> In guile 2.0.9, if an error is signalled in the interpreter, and the
> stack contains in a certain position an object whose unabbreviated print
> representation is very large, then the process of displaying the stack
> trace will take a huge amount of time and memory, pausing in the middle
> of output, even though the displayed stack trace doesn't actually show
> the object at all.  Test case:
>
> $ cat t6
> (define bs (let aaa ((n 100) (v '())) (if (= n 0) v (aaa (- n 1) (cons v 
> v)))))
> (write (list bs (error "wibble")))
> $ guile-2.0 --no-auto-compile t6
> Backtrace:
> In ice-9/boot-9.scm:
>  157: 11 [catch #t #<catch-closure e6a400> ...]
> In unknown file:
>    ?: 10 [apply-smob/1 #<catch-closure e6a400>]
> In ice-9/boot-9.scm:
>   63: 9 [call-with-prompt prompt0 ...]
> In ice-9/eval.scm:
>  432: 8 [eval # #]
> In ice-9/boot-9.scm:
> 2320: 7 [save-module-excursion #<procedure e9bcc0 at ice-9/boot-9.scm:3961:3 
> ()>]
> 3968: 6 [#<procedure e9bcc0 at ice-9/boot-9.scm:3961:3 ()>]
> 1645: 5 [%start-stack load-stack #<procedure e9c980 at 
> ice-9/boot-9.scm:3957:10 ()>]
> 1650: 4 [#<procedure e9a060 ()>]
> In unknown file:
>    ?: 3 [primitive-load "/home/zefram/usr/guile/t6"]
> In ice-9/eval.scm:
>  387: 2 ^Z
> zsh: suspended  guile-2.0 --no-auto-compile t6
> $ jobs -l
> [1]  + 32574 suspended  guile-2.0 --no-auto-compile t6
> $ ps vw 32574
>   PID TTY      STAT   TIME  MAJFL   TRS   DRS   RSS %MEM COMMAND
> 32574 pts/5    T      0:36      0     3 2266300 1634556  9.9 guile-2.0 
> --no-auto-compile t6
>
> With the test's size parameter at 100 as above, there is no realistic
> prospect of actually completing generation of the stack trace.  For some
> range of values (about 25 on my machine) there will be a noticeable pause,
> after which the stack trace completes:
>
> ...
>  387: 2 [eval # ()]
>  387: 1 [eval # ()]
> In unknown file:
>    ?: 0 [scm-error misc-error #f "~A" ("wibble") #f]
>
> It appears that it's generating the entire print representation of
> the object behind the scenes, though it then obviously throws it away.
> Experimentation with customising print methods for SRFI-9 record types
> shows that the delay and memory usage depend on the print representation
> per se, rather than on the amount of structure beneath the object.
> (A record-based cons-like type produces similar behaviour to the
> cons test when using the default print method that shows the content.
> Replacing it with a print method that emits a fixed string and doesn't
> recurse eliminates the delay entirely.)
>
> If my test program is run in compiled form (via auto-compilation) then
> it doesn't exhibit the pause.  Actually it gets optimised such that the
> problem object isn't anywhere near what the stack trace displays, so for
> a fair test the program needs to be tweaked.  It can be arranged for the
> problem object to be directly mentioned in the stack trace, and there is
> still no pause: the object appears in a highly abbreviated form, such as
>
>    2: 1 [vv ((# # # # ...) (# # # # ...) (# # # # ...) (# # # # ...) ...)]
>
> For comparison, guile-1.8 never exhibits this problem.  By default
> it doesn't emit a stack trace for a script, but it can be asked to do
> so via --debug.  It then behaves like the compiled form of guile-2.0:
> there is no delay, and the object is shown in very abbreviated form.
>
> Debian incarnation of this bug report:
> http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=734132
>
> -zefram