[Caml-list] Exceptions and backtraces

[Caml-list] Exceptions and backtraces

[Anders Peter Fugmann]

Hi,

I'm trying to understand what to expect from backtraces when an 
exception is raised.

The library reference says:
---------------
val print_backtrace : out_channel -> unit

Printexc.print_backtrace oc prints an exception backtrace on the output 
channel oc. The backtrace lists the program locations where the 
most-recently raised exception was raised and where it was propagated 
through function calls.
---------------

The documentation seems to suggest that every function call site leading 
up to the exception would be part of the backtrace. However, when I 
execute the following program:
---------------
let trace () =
   let open Printexc in
   get_callstack 2
   |> backtrace_slots
   |> (function Some [| _;s |] -> s)
   |> Slot.location
   |> (function Some l -> l.line_number)
   |> Printf.printf "At Line: %d\n"

exception Stop
let a () = trace (); raise Stop
let b () = trace (); a ()
let ()   = trace (); b ()
--------------
The code produces (both byte and native compilation):
(ocaml 4.02.3 and 4.03-trunk)

At Line: 13
At Line: 12
At Line: 11
Fatal error: exception Exception.Stop
Raised at file "exception.ml", line 11, characters 27-31
Called from file "exception.ml", line 13, characters 21-25

The backtrace does not record the function call at line 12, even though 
the information is there (accessible though 'get_callstack'), so I 
assume that inlining is not causing the behaviour.

Is it expected that the backtrace does not contain a reference for line 
12, or is there some exception handling optimization I should be aware of?

/Anders

Re: [Caml-list] Exceptions and backtraces

[Anders Peter Fugmann]

It just occurred to me that the functions I made are tail recursive and 
which is why the middle function call is eliminated.

Maybe this should be mentioned in the documentation.

This might also be the reason to why we often see less useful 
backtraces, as the chain of function calls are tail recursive.

/Anders



On 09/09/15 21:18, Anders Peter Fugmann wrote:
> Hi,
>
> I'm trying to understand what to expect from backtraces when an
> exception is raised.
>
> The library reference says:
> ---------------
> val print_backtrace : out_channel -> unit
>
> Printexc.print_backtrace oc prints an exception backtrace on the output
> channel oc. The backtrace lists the program locations where the
> most-recently raised exception was raised and where it was propagated
> through function calls.
> ---------------
>
> The documentation seems to suggest that every function call site leading
> up to the exception would be part of the backtrace. However, when I
> execute the following program:
> ---------------
> let trace () =
>    let open Printexc in
>    get_callstack 2
>    |> backtrace_slots
>    |> (function Some [| _;s |] -> s)
>    |> Slot.location
>    |> (function Some l -> l.line_number)
>    |> Printf.printf "At Line: %d\n"
>
> exception Stop
> let a () = trace (); raise Stop
> let b () = trace (); a ()
> let ()   = trace (); b ()
> --------------
> The code produces (both byte and native compilation):
> (ocaml 4.02.3 and 4.03-trunk)
>
> At Line: 13
> At Line: 12
> At Line: 11
> Fatal error: exception Exception.Stop
> Raised at file "exception.ml", line 11, characters 27-31
> Called from file "exception.ml", line 13, characters 21-25
>
> The backtrace does not record the function call at line 12, even though
> the information is there (accessible though 'get_callstack'), so I
> assume that inlining is not causing the behaviour.
>
> Is it expected that the backtrace does not contain a reference for line
> 12, or is there some exception handling optimization I should be aware of?
>
> /Anders
>

Re: [Caml-list] Exceptions and backtraces

[Jesper Louis Andersen]

[-- Attachment #1: Type: text/plain, Size: 638 bytes --]

On Wed, Sep 9, 2015 at 9:59 PM, Anders Peter Fugmann <anders@fugmann.net>
wrote:

> It just occurred to me that the functions I made are tail recursive and
> which is why the middle function call is eliminated.


Or even worse, tail calling. This, and aggressive inlining are the two
things which most often rears its ugly head when hunting for why a piece of
code is breaking some invariant. You have to "guess" at what the compiler
did to the code base and reconstruct the code path from this.

On the other hand, you don't want to lose either of those two optimizations.

I agree it is worthwhile to document both behaviours.


-- 
J.

[-- Attachment #2: Type: text/html, Size: 1136 bytes --]

Re: [Caml-list] Exceptions and backtraces

[Anders Fugmann]

Yes. Tail call optimization and inlining will limit the usability of the 
stack traces.

I assume that inlining can be disabled with -inline 0 (and it is not a 
problem for bytecode).

The tail call optimization pass is more problematic in terms of produced 
stack trace, and I don't see any good solution to this.

Maybe it would be possible to just count number of function calls within 
the same stack frame. The back trace would then print the function call 
counts in addition to the regular stack trace.
Another possibility would be to only perform TCO on recursive functions.

/Anders


On 09/10/2015 11:45 AM, Jesper Louis Andersen wrote:
>
> On Wed, Sep 9, 2015 at 9:59 PM, Anders Peter Fugmann <anders@fugmann.net
> <mailto:anders@fugmann.net>> wrote:
>
>     It just occurred to me that the functions I made are tail recursive
>     and which is why the middle function call is eliminated.
>
>
> Or even worse, tail calling. This, and aggressive inlining are the two
> things which most often rears its ugly head when hunting for why a piece
> of code is breaking some invariant. You have to "guess" at what the
> compiler did to the code base and reconstruct the code path from this.
>
> On the other hand, you don't want to lose either of those two optimizations.
>
> I agree it is worthwhile to document both behaviours.
>
>
> --
> J.

Re: [Caml-list] Exceptions and backtraces

[Jesper Louis Andersen]

[-- Attachment #1: Type: text/plain, Size: 1130 bytes --]

On Thu, Sep 10, 2015 at 12:54 PM, Anders Fugmann <anders@fugmann.net> wrote:

> Another possibility would be to only perform TCO on recursive functions.


Disabling the optimizations works in some cases, but it considerably alters
the characteristics of the executed program. Programs that wouldn't reach
the stack limit suddenly does, and programs that would run fast are now
considerably slower.

In a controlled test situation it may be worthwhile to turn off
optimizations of this kind, but I've always had the feeling that this is
something you have to accept for the real world deployments when requesting
what a program is doing.

As long as you know what is happening, reconstructing the code flow path
usually isn't that hard. And OCaml isn't the only language in which this is
a problem. It hits Standard ML, Erlang, and Haskell too, the latter having
its own additional irregularities due to lazy evaluation. And inlining
optimizations have hit me when using DTrace on C code because the optimizer
decided to inline functions aggressively, which in turn removes those as
targets for function boundary tracing.


-- 
J.

[-- Attachment #2: Type: text/html, Size: 1632 bytes --]