As the title says, it there a way to display full stack trace when Racket crashed? Or does "repeats 6 more times" literally indicates 6 more lines happens at the same place?
@vector-length: arity mismatch;
the expected number of arguments does not match the given number
expected: 1
given: 2
context...:
/home/scarlet/Hydride/rosette/rosette/base/form/control.rkt:15:25
/usr/share/racket/collects/racket/private/list.rkt:291:2: build-vector
/home/scarlet/Hydride/rosette/rosette/base/core/forall.rkt:43:17: proc
[repeats 6 more times]
/home/scarlet/Hydride/code-synthesizer/hydride/ir/arith/interpreter.rkt:1443:0: evaluate-arith-expr-env
body of "/home/scarlet/Hydride/test/dp4a/test_equiv.rkt"
1 Like
I believe we're discussing the output produced when racket is run at the command-line, is that right? In this case, here's a simple experiment:
test.rkt:
#lang racket
(define (f1 x)
(+ 1 (g (sub1 x))))
(define (f2 x)
(+ 2 (g (sub1 x))))
(define (g x)
(cond [(= x 0) (error 'ouch "asplode!")]
[else
;; randomly call either f1 or f2
(cond [(= 0 (random 2)) (f1 x)]
[else (f2 x)])]))
(g 100)
This program loops over x, nests to a depth of 100, then dies. However, the function at each level is randomly chosen to be either f1 or f2, guaranteeing that the stack frames are randomly interleaved. The result of running this at the command-line is this:
% racket test.rkt
ouch: asplode!
context...:
/tmp/b.rkt:11:0: g
[repeats 99 more times]
body of "/tmp/b.rkt"
This convinces me that either the repeated lines are elided even when they're not equal, or that compilation is aggressively optimizing this in a way that makes every line the same; either way, it's not a safe assumption that you're getting the "stack trace" that you want.
Instead, try running it using errortrace:
> racket -l errortrace -t test.rkt
ouch: asplode!
errortrace...:
/tmp/test.rkt:12:17: (error (quote ouch) "asplode!")
/tmp/test.rkt:12:2: (cond ((= x 0) (error (quote ouch) "asplode!")) (else (cond ((= 0 ....) (f1 ....)) (else (....)))))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:8:2: (+ 2 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
/tmp/test.rkt:5:2: (+ 1 (g (sub1 x)))
context...:
/tmp/test.rkt:4:0: f1
[repeats 3 more times]
/tmp/test.rkt:7:0: f2
[repeats 1 more time]
/tmp/test.rkt:4:0: f1
/tmp/test.rkt:7:0: f2
[repeats 4 more times]
/tmp/test.rkt:4:0: f1
[repeats 2 more times]
/tmp/test.rkt:7:0: f2
[repeats 1 more time]
/tmp/test.rkt:4:0: f1
/tmp/test.rkt:7:0: f2
[repeats 3 more times]
/tmp/test.rkt:4:0: f1
/tmp/test.rkt:7:0: f2
...
This gives you the information you probably want. BUT ALSO, note that the "context" at the end probably aligns with what you were expecting to get first; "4 of these, 2 of these, 1 of these, etc." Also, note that it gives up after a small fixed number of lines. This suggests to me that the result of the earlier experiment was in fact the result of aggressive optimization.
1 Like
Cool! That's what I am looking for. Great thanks!
I'm almost sure that f1 and f2 are inlined so the code only see g calling itself like 100 times.
One solution as you posted is to use errortrace or use the debug mode in DrRacket (that is enabled by default). Anyway using errortrace or use the debug mode in DrRacket prevent a lot of optimizations, so the code is much slower.
1 Like