Ocaml native code debugging

t-caml-valid-callgraph.png Maintenant que le bug Improve gnu ELF est corrigé, kcachegrind nous génère de beaux callgraphs.

Ce patch consistait à ajouter des instructions .size (dans l'assembleur ELF) pour que valgrind interprète tous les symboles (camT_entry, camlT_foo, camlT_bar, ...) et puisse ainsi afficher leurs noms au lieu d'un nombre hexadécimal!

Les standards ELF pour le debug

Maintenant, nous souhaiterions que ces outils puissent savoir de manière standard dans quels fichiers et à quelles lignes sont déclarés les fonctions. (Le nom du fichier est bien présent dans les symboles, mais cela ne permet pas d'exploiter le plein potentiel de ces outils)

Voyons un peu comment se débrouille GCC :

  int bar(int a) {
        return 1+a;
  }
  

  int foo(int a) {
        return 2+bar(a);
  }


  int main() {
        foo(3);
  }


  $ gcc -O0 -g -S t.c

  .globl bar
        .type   bar, @function
  bar:
  .LFB2:
        .file 1 "t.c"
        .loc 1 1 0
        pushq   %rbp
  .LCFI0:
        movq    %rsp, %rbp
  .LCFI1:
        movl    %edi, -4(%rbp)
        .loc 1 2 0
        movl    -4(%rbp), %eax
        incl    %eax
        .loc 1 3 0
        leave
        ret
  .LFE2:
        .size   bar, .-bar
  .globl foo
        .type   foo, @function

Les instructions clés sont .file et .loc :

-> .file $identifiant$ "$chemin_du_fichier"

-> .loc $identifiant_de_fichier$ $ligne$ $colonne$

Solution proposée

Le module du compilateur qui génère les instructions est : asmcomp/i386/emit.mlp
Et plus particulièrement la fonction fundecl :

  let fundecl fundecl =
    function_name := fundecl.fun_name;
    fastcode_flag := fundecl.fun_fast;
    (* ... *)
    `   .globl  {emit_symbol fundecl.fun_name}
`;
    `{emit_symbol fundecl.fun_name}:
`;
    if !Clflags.gprofile then emit_profile();
    let n = frame_size() - 4 in
    if n > 0 then
      ` subl    ${emit_int n}, %esp
`;
    `{emit_label !tailrec_entry_point}:
`;
    emit_all true fundecl.fun_body;
    List.iter emit_call_gc !call_gc_sites;
    emit_call_bound_errors ();
    List.iter emit_float_constant !float_constants;
    match Config.system with
      "linux_elf" | "bsd_elf" | "gnu" ->
        `       .type   {emit_symbol fundecl.fun_name},@function
`;
        `       .size   {emit_symbol fundecl.fun_name},.-{emit_symbol fundecl.fun_name}
`
    | _ -> ()

Hors nous n'avons à disposition que la variable fundecl :

  type fundecl = 
  { fun_name: string;
    fun_body: instruction;
    fun_fast: bool } 
  type instruction =
  { mutable desc: instruction_desc;
    mutable next: instruction;
    arg: Reg.t array;
    res: Reg.t array;
    dbg: Debuginfo.t;
    live: Reg.Set.t }

Il y a bien un attribut dbg sur les instructions mais il est rarement renseigné. (une compilation avec l'option -dlinear permet de le voir)

J'ai décidé d'ajouter un attribut fun_dbg : Debuginfo.t sur fundecl et de le remplir dans toutes les phases de compilation. Il serait peut être plus judicieux de travailler sur l'attribut dbg des instructions ? (car cela permettrait par la suite d'indiquer les lignes de chaque instruction à valgrind, mais aussi gdb!) Ce patch n'est pas optimisé car il répète l'instruction .file pour chaque .loc, donc à chaque entête de fonction, nous avons un .file et un .loc.

-> Patch sur la branche release311

Voyons maintenant ce qu'apporte ce patch.

Résultats avec gdb

  $ ocamlopt -g -inline 0 t.ml
  $ gdb a.out
  (gdb) break t.ml:6
  Breakpoint 1 at 0x8049940: file t.ml, line 6.
  (gdb) run
  Starting program: /home/alex/callgraph/a.out 
  

  Breakpoint 1, camlT__foo_60 () at t.ml:6
  6       let foo i  =
  Current language:  auto; currently asm


  (gdb) backtrace
  #0  camlT__foo_60 () at t.ml:7
  #1  0x0804c570 in camlT__entry () at t.ml:12
  #2  0x0806e4b7 in caml_start_program ()


  (gdb) step 1
  camlT__bar_58 () at t.ml:2
  2       let bar i =


  (gdb) list
  1
  2       let bar i =
  3               1+i
  4       ;;
  5
  6       let foo i  =
  7               2+(bar i )
  8       ;;
  9
  10      let () =

Résultats avec gprof

  $ ocamlopt -g -p -inline 0 t.ml
  $ ./a.out
  $ gprof -A
  *** File /home/alex/callgraph/t.ml:
                  

       1 -> let bar i =
                    Thread.delay 3.0;
                    1+i
            ;;
            
       1 -> let foo i  =
                    2+(bar i )
            ;;
            
            let () =
       1 ->         let closure() = 3 in
                    print_int ( foo (closure()) )
            ;;
            



  Top 10 Lines:


 Line      Count
    2          1
    7          1
   12          1



  Execution Summary:


    3   Executable lines in this file
    3   Lines executed



   100.00   Percent of the file executed


    3   Total number of line executions
 1.00   Average executions per line

Résultats avec valgrind/kcachegrind

  $ ocamlopt -g -inline 0 t.ml
  $ valgrind --tool=callgrind ./a.out
  $ callgrind_annotate callgrind.out.2152 t.ml

  -- User-annotated source: t.ml


  .
  8  let bar i =
  77,715  => thread.ml:camlThread__delay_75 (1x)
  .      Thread.delay 3.0;
  .      1+i
  .  ;;
  .
  3  let foo i  = 
  77,723  => t.ml:camlT__bar_58 (1x)
  .      2+(bar i )
  .  ;;
  .
  .  let () =
  13          let closure() = 3 in
  1,692  => pervasives.ml:camlPervasives__output_string_215 (1x)
  2,312  => pervasives.ml:camlPervasives__string_of_int_154 (1x)
  77,726  => t.ml:camlT__foo_60 (1x)
  .      print_int ( foo (closure()) )
  .  ;;
  .
  $ kcachegrind callgrind.out.2152

kcachegrind-file-and-line.png



Et après ?

On peut espérer encore un tas d'améliorations, comme :