Previous Contents Next

Exercises

Tracing Function Application

This exercise shows the evaluation of arguments at the moment of function application.
  1. Activate tracing of the function List.fold_left and evaluate the following expression:

    List.fold_left (-) 1 [2; 3; 4; 5];;
    What does the trace show you?

    # #trace List.fold_left ;;
    List.fold_left is now traced.

    # List.fold_left (-) 1 [2; 3; 4; 5] ;;
    List.fold_left <-- <fun>
    List.fold_left --> <fun>
    List.fold_left* <-- <poly>
    List.fold_left* --> <fun>
    List.fold_left** <-- [<poly>; <poly>; <poly>; <poly>]
    List.fold_left <-- <fun>
    List.fold_left --> <fun>
    List.fold_left* <-- <poly>
    List.fold_left* --> <fun>
    List.fold_left** <-- [<poly>; <poly>; <poly>]
    List.fold_left <-- <fun>
    List.fold_left --> <fun>
    List.fold_left* <-- <poly>
    List.fold_left* --> <fun>
    List.fold_left** <-- [<poly>; <poly>]
    List.fold_left <-- <fun>
    List.fold_left --> <fun>
    List.fold_left* <-- <poly>
    List.fold_left* --> <fun>
    List.fold_left** <-- [<poly>]
    List.fold_left <-- <fun>
    List.fold_left --> <fun>
    List.fold_left* <-- <poly>
    List.fold_left* --> <fun>
    List.fold_left** <-- []
    List.fold_left** --> <poly>
    List.fold_left** --> <poly>
    List.fold_left** --> <poly>
    List.fold_left** --> <poly>
    List.fold_left** --> <poly>
    - : int = -13


    La trace indique seulement le passage des arguments à la fonction List.fold_left, mais n'affiche pas les valeurs des arguments. La nature polymorphe des paramètres de List.fold_left empèche la trace de pouvoir afficher les valeurs des arguments passés.


  2. Define the function fold_left_int, identical to List.fold_left, but with type:

    (int -> int -> int) -> int -> int list -> int.
    Trace this function. Why is the output of the trace different?

# let rec fold_left_int f (r : int) (l : int list) =
match l with
[] -> r
| t::q -> fold_left_int f (f r t) q ;;
val fold_left_int : (int -> int -> int) -> int -> int list -> int = <fun>

# #trace fold_left_int ;;
fold_left_int is now traced.
# fold_left_int (-) 1 [2; 3; 4; 5] ;;
fold_left_int <-- <fun>
fold_left_int --> <fun>
fold_left_int* <-- 1
fold_left_int* --> <fun>
fold_left_int** <-- [2; 3; 4; 5]
fold_left_int <-- <fun>
fold_left_int --> <fun>
fold_left_int* <-- -1
fold_left_int* --> <fun>
fold_left_int** <-- [3; 4; 5]
fold_left_int <-- <fun>
fold_left_int --> <fun>
fold_left_int* <-- -4
fold_left_int* --> <fun>
fold_left_int** <-- [4; 5]
fold_left_int <-- <fun>
fold_left_int --> <fun>
fold_left_int* <-- -8
fold_left_int* --> <fun>
fold_left_int** <-- [5]
fold_left_int <-- <fun>
fold_left_int --> <fun>
fold_left_int* <-- -13
fold_left_int* --> <fun>
fold_left_int** <-- []
fold_left_int** --> -13
fold_left_int** --> -13
fold_left_int** --> -13
fold_left_int** --> -13
fold_left_int** --> -13
- : int = -13
# #untrace_all ;;
fold_left_int is no longer traced.
List.fold_left is no longer traced.
La fonction fold_left_int est monomorphe. Le mécanisme de trace connaît le type des arguments et peut alors les afficher lors de leur passage.

Performance Analysis

We continue the exercise proposed in chapter 9, page ??, where we compared the evolution of the heap of two programs (one tail recursive and the other not) for calculating primes. This time we will compare the execution times of each function with the profiling tools. This exercise shows the importance of inline expansion (see chapter 7).

  1. Compile the two programs erart and eranrt with profiling options using the bytecode compiler and the native code compiler respectively.
    $ ocamlcp -custom -o era_rt_bc unix.cma interval.ml trgc.ml eras2.ml era2_main.ml main_rt.ml -cclib -lunix
    $ ocamlcp -custom -o era_nrt unix.cma interval.ml trgc.ml eras.ml era2_main.ml main_nrt.ml -cclib -lunix
    $ ocamlopt -p -o era_rt_nat unix.cmxa interval.ml trgc.ml eras2.ml era2_main.ml main_rt.ml -cclib -lunix
    $  ocamlopt -p -o era_nrt_nat unix.cmxa interval.ml trgc.ml eras.ml era2_main.ml main_nrt.ml -cclib -lunix
    


  2. Execute the programs passing them the numbers 3000 4000 5000 6000 on the command line.
    $ era_rt_bc traceRT-BC 3000 4000 5000 6000
    $ era_nrt_bc traceNRT-BC 3000 4000 5000 6000
    $ era_rt_nat traceRT-NAT 3000 4000 5000 6000
    $ era_nrt_nat traceNRT-NAT 3000 4000 5000 6000
    


  3. Visualize the results with the ocamlprof and gprof commands. What can you say about the results? Compilateur de code-octet :

    La commande ocamlprof lit les informations du fichier camlprof.dump. Si plusieurs exécutions différentes ont été lancées, seule l'information de cette dernière est accessible.

    Voici les informations ressorties pour la version récursive terminale :
    $ ocamlprof eras2.ml
    (* fichier eras2.ml *)
    
    let erart l  = 
      (* 4 *) let rec erart_aux l r = (* 2436 *) match l with 
        [] -> (* 4 *) List.rev r
      | p::q -> (* 2432 *) erart_aux  (List.filter ( fun x -> (* 808410 *) x mod p <> 0) q) (p::r) 
      in 
        erart_aux l [] ;;
    
    let erart_go n = 
      (* 4 *) erart (Interval.interval (<)  (fun x -> (* 17992 *) x + 1) 2 n) ;;
    
    et pour la version récursive terminale :
    $ ocamlprof eras.ml
    (* fichier eras.ml *)
    
    let rec eras l  = (* 2436 *) match l with 
      [] -> (* 4 *) []
    | p::q -> (* 2432 *) p:: (eras (List.filter ( fun x -> (* 808410 *) x mod p <> 0) q)) ;;
    
    let era_go n = 
      (* 4 *) eras (Interval.interval (<)  (fun x -> (* 17992 *) x + 1) 2 n) ;;
    
    On s'aperçoit que dans les deux cas, il y a 2436 appels à la fonction principale, dont 4 avec une liste vide et 2432 dans l'autre cas.

    Attention le profilage rend invalide de nombreuses optimisations du compilateur.

    Compilateur natif :

    L'exécution d'un exécutable autonome natif compilé en mode -p produit un fichier gmon.out.

    $ gprof era_rt_nat 
    
    affiche tout d'abord le temps passé dans chaque fonction :
    Flat profile:
    
    Each sample counts as 0.01 seconds.
      %   cumulative   self              self     total           
     time   seconds   seconds    calls  us/call  us/call  name    
     44.44      0.12     0.12   808410     0.15     0.15  Eras2_fun_112
     18.52      0.17     0.05     2436    20.53    32.67  List_rev_append_57
     11.11      0.20     0.03     2432    12.34    73.68  List_find_213
      7.41      0.22     0.02      114   175.44   175.44  sweep_slice
      7.41      0.24     0.02       34   588.24   588.24  mark_slice
      3.70      0.25     0.01    76203     0.13     0.13  allocate_block
      3.70      0.26     0.01    64466     0.16     0.31  oldify
    ...
    
    puis le graphe d'appel.

    $ gprof era_nrt_nat 
    
    affiche tout d'abord le temps passé dans chaque fonction :
    Flat profile:
    
    Each sample counts as 0.01 seconds.
      %   cumulative   self              self     total           
     time   seconds   seconds    calls  us/call  us/call  name    
     42.42      0.14     0.14   808410     0.17     0.17  Eras_code_begin
     15.15      0.19     0.05     2432    20.56    95.63  List_find_213
     15.15      0.24     0.05     2432    20.56    39.31  List_rev_append_57
      6.06      0.26     0.02    93936     0.21     0.53  oldify
      6.06      0.28     0.02    74519     0.27     0.27  allocate_block
      6.06      0.30     0.02       37   540.54   540.54  mark_slice
      3.03      0.31     0.01    74519     0.13     0.40  alloc_shr
    ...
    
    L'outil ocamlprof compte le nombre d'appels ou de passage dans certaines parties d'une fonction sans indication de temps.

    Par contre , l'outil gprof est plus précis car il indique les temps passés dans chaque fonction.

    Attention les versions compilées avec l'option -p effectuent un travail supplémentaire qui est perceptible lors de mesures de temps. Les versions .exe sont compilées sans cette option.
    $ time era_rt.exe a1 3000 4000 5000 6000
    0.230u 0.010s 0:00.25 96.0%     0+0k 0+0io 129pf+0w
    $ time era_rt_nat a2 3000 4000 5000 6000
    0.510u 0.010s 0:00.52 100.0%    0+0k 0+0io 134pf+0w
    $ time era_nrt.exe a3 3000 4000 5000 6000
    0.220u 0.020s 0:00.24 100.0%    0+0k 0+0io 130pf+0w
    $ time era_nrt_nat a4 3000 4000 5000 6000
    0.520u 0.010s 0:00.53 100.0%    0+0k 0+0io 134pf+0w
    $ visu a1
    Nombre de Gc: mineur = 131, majeur = 20
    $ visu a2
    Nombre de Gc: mineur = 131, majeur = 20
    $ visu a3
    Nombre de Gc: mineur = 131, majeur = 23
    $ visu a4
    Nombre de Gc: mineur = 131, majeur = 23
    
    $ gprof era_rt_nat 
    

Previous Contents Next