debugging help: how to read/use a backtrace?

debugging help: how to read/use a backtrace?

[Jan Nieuwenhuizen]

Hi,

I often find myself struggling to pinpoint an error location from
Guile's backtrace (see below) and I am starting to wonder if there is
something that I'm missing.

Usually I can guess.  If not, I scatter the code with debug printing
before and after statements

   (let* ((x ...)
          (foo (format (current-error-port) "00=~a\n" x))
          (y ..)
          (foo (format (current-error-port) "01=~a\n" y))

to find the problematic call.

Looking at the trace below, I see only one possible indirect indicator
of where this error occurs: the `In unknown file' bit.  All the others
are srfi/srfi-1.scm and ice-9/eval.scm.  So my starting point is

    In unknown file:
               0 (_ () () 0 1)

Hmm.  Originally it read

    0 (_ () () 0 0)

because I already started by modifying my source code and change all the
places that match such a call, modifying the last zero with a unique
integer (which will produce incorrect results, of course), like so

    (append-map (lambda/label->list '() '() 0 1) o))
    ...
    (offset (if prefix (length (functions->text (cdr prefix) '() 0 2))
    ...
    (t ((lambda/label->list '() '() 0 3) l/l))

ETC.

That helps me to identify the source location and then I can add debug
printing

    (define (lambda/label->list f g t d)
      (lambda (l/l)
        (format (current-error-port) "l/l=~a\n" l/l)
        (format (current-error-port) "gonna exec =~a\n" (procedure? l/l))
        (if (procedure? l/l) (format (current-error-port) "source=~a\n" (procedure-source l/l)))
        (if (not (procedure? l/l)) '() (l/l f g t d))
        (format (current-error-port) "done\n" )
        (if (not (procedure? l/l)) '() (l/l f g t d))))

But here it stops again... (procedure-source l/l) yields #f, so all I
know is that I create a lambda somewhere that tries to invoke the string
"eval_apply".  How can I get some help to find the source location of
that?

Greetings,
Jan


l/l=#<procedure 13000a0 at ice-9/eval.scm:342:13 (a b c d)>
gonna exec =#t
source=#f
Backtrace:
In srfi/srfi-1.scm:
   592:29 19 (map1 (#<procedure 19c30c0 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 18 (map1 (#<procedure 1adbd20 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 17 (map1 (#<procedure 15201c0 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 16 (map1 (#<procedure 1530980 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 15 (map1 (#<procedure 1be2e40 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 14 (map1 (#<procedure 1be2620 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 13 (map1 (#<procedure 1548820 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 12 (map1 (#<procedure 1548660 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 11 (map1 (#<procedure 1577980 at ice-9/eval.scm:342:13 (a b c d)> #<p?> ?))
   592:29 10 (map1 (#<procedure 1577820 at ice-9/eval.scm:342:13 (a b c d)> "ap?" ?))
   592:29  9 (map1 ("apply" #<procedure 13000a0 at ice-9/eval.scm:342:13 (a b c?> ?))
   592:17  8 (map1 (#<procedure 13000a0 at ice-9/eval.scm:342:13 (a b c d)> #<pr?>))
In ice-9/eval.scm:
    608:8  7 (_ #(#(#<directory (mes elf-util) ec6000> () () 0 1) #<procedure 13?>))
   293:34  6 (_ #(#(#<directory (mes libc-i386) f39d80>) () () 0 1 0 ((#<p?> ?) ?)))
In srfi/srfi-1.scm:
   679:15  5 (append-map _ _ . _)
   592:17  4 (map1 ((#<procedure 1a2ef40 at ice-9/eval.scm:342:13 (a b c d)> # ?) ?))
   679:15  3 (append-map _ _ . _)
   592:29  2 (map1 (#<procedure 1a2ef40 at ice-9/eval.scm:342:13 (a b c d)> "ev?" ?))
   592:17  1 (map1 ("eval_apply" #<procedure 1a41b20 at ice-9/eval.scm:342:13 (?> ?))
In unknown file:
           0 (_ () () 0 1)

ERROR: ERROR: Wrong type to apply: "eval_apply"

-- 
Jan Nieuwenhuizen <janneke@gnu.org> | GNU LilyPond http://lilypond.org
Freelance IT http://JoyofSource.com | Avatar®  http://AvatarAcademy.nl  

Re: debugging help: how to read/use a backtrace?

[Andy Wingo]

On Sat 21 Jan 2017 11:21, Jan Nieuwenhuizen <janneke@gnu.org> writes:

> I often find myself struggling to pinpoint an error location from
> Guile's backtrace (see below) and I am starting to wonder if there is
> something that I'm missing.

I believe this is comprehensively cleaned up and improved in 2.1.x.
(Guile 2.0 tries to identify the procedure by looking at slot 0; Guile
2.2 instead uses the instruction pointer of the frame.)  Can you
confirm?

Andy

Re: debugging help: how to read/use a backtrace?

[Jan Nieuwenhuizen]

Andy Wingo writes:

> On Sat 21 Jan 2017 11:21, Jan Nieuwenhuizen <janneke@gnu.org> writes:
>
>> I often find myself struggling to pinpoint an error location from
>> Guile's backtrace (see below) and I am starting to wonder if there is
>> something that I'm missing.
>
> I believe this is comprehensively cleaned up and improved in 2.1.x.
> (Guile 2.0 tries to identify the procedure by looking at slot 0; Guile
> 2.2 instead uses the instruction pointer of the frame.)  Can you
> confirm?

Sadly no; this is 2.1.x (x=5 probably) as you can see from this bit

     l/l=#<procedure 13000a0 at ice-9/eval.scm:342:13 (a b c d)>

which points to

      ((4) (lambda (env)
             (lambda (a b c d)
               (body (make-env* env a b c d)))))

which in turn suggests that I am missing something/hitting problems
that most of you do not have?

Greetings,
Jan

-- 
Jan Nieuwenhuizen <janneke@gnu.org> | GNU LilyPond http://lilypond.org
Freelance IT http://JoyofSource.com | Avatar®  http://AvatarAcademy.nl  

Re: debugging help: how to read/use a backtrace?

[Andy Wingo]

On Tue 07 Mar 2017 16:42, Jan Nieuwenhuizen <janneke@gnu.org> writes:

> Andy Wingo writes:
>
>> On Sat 21 Jan 2017 11:21, Jan Nieuwenhuizen <janneke@gnu.org> writes:
>>
>>> I often find myself struggling to pinpoint an error location from
>>> Guile's backtrace (see below) and I am starting to wonder if there is
>>> something that I'm missing.
>>
>> I believe this is comprehensively cleaned up and improved in 2.1.x.
>> (Guile 2.0 tries to identify the procedure by looking at slot 0; Guile
>> 2.2 instead uses the instruction pointer of the frame.)  Can you
>> confirm?
>
> Sadly no; this is 2.1.x (x=5 probably) as you can see from this bit
>
>      l/l=#<procedure 13000a0 at ice-9/eval.scm:342:13 (a b c d)>

What is this l/l syntax?

The way the procedure prints indicates that you have an interpreted
procedure instead of a compiled procedure.  Debugging will be not as
good.  Of course performance also will not be as good.  Still, in theory
these procedures are decorated with properties to indicate their name,
etc, at least when you print the procedure itself:

   scheme@(guile-user)> ,o interp #t
   scheme@(guile-user)> (define foo (lambda (x y z) (list x y z)))
   scheme@(guile-user)> foo
   $1 = #<procedure foo (a b c)>

In a backtrace it could be that the procedure slot was re-used and so
you just have the IP of the procedure's code (at ice-9/eval.scm:342:13)
but that code corresponds to many closures, and the closure itself is
gone.

In summary, debugging interpreted procedures can improve but I suspect
it will never be as good as compiled procedures.

Andy