AnubisProfiling
Version 6 (Caine -, 04/24/2008 10:02 PM)
1 | 6 | Caine - | |
---|---|---|---|
2 | 6 | Caine - | h1. Anubis Profiling |
3 | 6 | Caine - | |
4 | 1 | Anonymous | Profiling functionnalities have been added to Anubis 1.8. |
5 | 1 | Anonymous | |
6 | 1 | Anonymous | |
7 | 6 | Caine - | h2. Documentation |
8 | 1 | Anonymous | |
9 | 6 | Caine - | To use them, you first have to compile your ADM with the profiling instructions, using *-profile* option into the command line. A good idea is to use the *-sc* option to, as it can help you to identify the different functions and their location into source code. |
10 | 6 | Caine - | |
11 | 6 | Caine - | Once compiled, you just have to start your ADM with the [[VirtualMachine]]. At the end of the execution (you can use CTRL + C to end your ADM), the VM will output (on stderr) plain text information about profiling. On big software, that a good idea to redirect stderr to a file (using '2> filename' on command line). |
12 | 6 | Caine - | |
13 | 1 | Anonymous | Some options are available to format the output : |
14 | 1 | Anonymous | ||-profile:csv ||Use CSV (Comma Separated Values) output insteed of plain text|| |
15 | 1 | Anonymous | ||-csv_sep:<sep> ||Allows to define a separator for CSV output (ex: '-csv_sep:;' to have a semi-colon insteed a comma)|| |
16 | 1 | Anonymous | |
17 | 1 | Anonymous | |
18 | 6 | Caine - | h2. Examples |
19 | 6 | Caine - | |
20 | 6 | Caine - | |
21 | 6 | Caine - | Plain text output for fibonnacci.anubis |
22 | 6 | Caine - | |
23 | 6 | Caine - | Command line : _anbexec fib 29_ |
24 | 6 | Caine - | <pre> |
25 | 1 | Anonymous | *** PROFILING DATA *** |
26 | 1 | Anonymous | *** Full executing time = 10.362 s |
27 | 1 | Anonymous | Function fib() [offset = 541]: |
28 | 1 | Anonymous | hits = 1 |
29 | 1 | Anonymous | time (excluding children) = 0.002 s (0.0%) |
30 | 1 | Anonymous | max (including children) = 10.361 s (100.0%) |
31 | 1 | Anonymous | Function fib() [offset = 173]: |
32 | 1 | Anonymous | hits = 1664079 |
33 | 1 | Anonymous | time (excluding children) = 10.360 s (100.0%) |
34 | 1 | Anonymous | max (including children) = 10.360 s (100.0%) |
35 | 1 | Anonymous | Function +() [offset = 89]: |
36 | 1 | Anonymous | hits = 1 |
37 | 1 | Anonymous | time (excluding children) = 0.000 s (0.0%) |
38 | 1 | Anonymous | max (including children) = 0.000 s (0.0%) |
39 | 6 | Caine - | </pre> |
40 | 1 | Anonymous | |
41 | 6 | Caine - | CSV output for fibonnacci.anubis |
42 | 6 | Caine - | |
43 | 6 | Caine - | Command line : _anbexec fib 29 --profile:csv_ |
44 | 1 | Anonymous | ||Function||Offset||Hits||Time (excl. children)||Time %||Max (inc. children)||Max %|| |
45 | 1 | Anonymous | ||fib||541||1||0.001657||0.0||10.623458||100.0|| |
46 | 1 | Anonymous | ||fib||173||1664079||10.621774||100.0||10.621774||100.0|| |
47 | 1 | Anonymous | ||+||89||1||0.000027||0.0||0.000027||0.0|| |
48 | 1 | Anonymous | |
49 | 6 | Caine - | |
50 | 6 | Caine - | h2. About Terminal Calls |
51 | 6 | Caine - | |
52 | 1 | Anonymous | Terminal calls can be a problem for profiling. |
53 | 1 | Anonymous | |
54 | 1 | Anonymous | First, they can't be representated by recursive calls because we can have an infinite succession of these calls. |
55 | 1 | Anonymous | |
56 | 6 | Caine - | Other approach is to do a 'fake' return just before a [[TerminalCall]]. But resulting profiling information is not really usable because the calls arborescence is broken. |
57 | 2 | Anonymous | |
58 | 6 | Caine - | So the choosen approach was to consider that all subsequent [[TerminalCalls]] made from a function are simply like if this was the same function. Helped by some examples, I will try to show you how it works. |
59 | 2 | Anonymous | |
60 | 2 | Anonymous | |
61 | 6 | Caine - | 1. [[TerminalCall]] used as loop |
62 | 4 | Anonymous | If a terminal call is used as a loop implementation, this strategy is really fine because the function will be seen as if it was called only once and its execution time will include all loop interations. |
63 | 6 | Caine - | 2. [[TerminalCall]] used as automate |
64 | 3 | Anonymous | For the automate, profiling data are incomplete but not so bad... Only the automate entry function will be seen, but its execution time will include all subsequent calls into the automate. So we can have the automate executing time, but not the details of the functions composing it. |
65 | 6 | Caine - | 3. Functions that are simply terminating by a [[TerminalCall]] to another function. |
66 | 6 | Caine - | In this case, the second fonction will not be seen and it execution time will be include into its caller. So some fonction can never appear because the compiler have otimized its call to a [[TerminalCall]]. This is the _worse_ case because some functions were _hidden_. |
67 | 1 | Anonymous | |
68 | 3 | Anonymous | Example: |
69 | 6 | Caine - | <pre> |
70 | 3 | Anonymous | global define |
71 | 3 | Anonymous | One |
72 | 3 | Anonymous | fib |
73 | 3 | Anonymous | ( |
74 | 3 | Anonymous | List(String) args |
75 | 3 | Anonymous | ) = |
76 | 3 | Anonymous | if args is |
77 | 3 | Anonymous | { |
78 | 3 | Anonymous | [ ] then print("Usage: fib <interger>\n"), |
79 | 3 | Anonymous | |
80 | 3 | Anonymous | [h . t] then |
81 | 3 | Anonymous | if string_to_integer(h) is |
82 | 3 | Anonymous | { |
83 | 3 | Anonymous | failure then print("Argument must be a integer.\n"), |
84 | 3 | Anonymous | success(n) then print("Fib("+h+") = " + fib(n) + "\n") |
85 | 3 | Anonymous | } |
86 | 3 | Anonymous | }. |
87 | 6 | Caine - | </pre> |
88 | 6 | Caine - | The _print()_ function will never appear on profiling data because it's always used as [[TerminalCall]] of the _fib()_ function. So its executing time will be included to the _fib()_ function. |