AnubisProfiling

Version 2 (Anonymous, 08/29/2007 10:11 AM)

1 1 Anonymous
= Anubis Profiling =
2 1 Anonymous
Profiling functionnalities have been added to Anubis 1.8.
3 1 Anonymous
4 1 Anonymous
== Documentation ==
5 1 Anonymous
To use them, you fist 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 iddentify the different functions and their location into source code.
6 1 Anonymous
7 1 Anonymous
Once compiled, you juste have to start your ADM with the VirtualMachine. At the end of the execution (youy 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).
8 1 Anonymous
9 1 Anonymous
Some options are available to format the output :
10 1 Anonymous
||-profile:csv ||Use CSV (Comma Separated Values) output insteed of plain text||
11 1 Anonymous
||-csv_sep:<sep> ||Allows to define a separator for CSV output (ex: '-csv_sep:;' to have a semi-colon insteed a comma)||
12 1 Anonymous
13 1 Anonymous
== Examples ==
14 1 Anonymous
15 1 Anonymous
Plain text output for fibonnacci.anubis[[BR]]
16 1 Anonymous
Command line : ''anbexec fib 29''
17 1 Anonymous
{{{
18 1 Anonymous
*** PROFILING DATA ***
19 1 Anonymous
*** Full executing time = 10.362 s
20 1 Anonymous
Function fib() [offset = 541]:
21 1 Anonymous
   hits = 1
22 1 Anonymous
   time (excluding children) = 0.002 s (0.0%)
23 1 Anonymous
   max  (including children) = 10.361 s (100.0%)
24 1 Anonymous
Function fib() [offset = 173]:
25 1 Anonymous
   hits = 1664079
26 1 Anonymous
   time (excluding children) = 10.360 s (100.0%)
27 1 Anonymous
   max  (including children) = 10.360 s (100.0%)
28 1 Anonymous
Function +() [offset = 89]:
29 1 Anonymous
   hits = 1
30 1 Anonymous
   time (excluding children) = 0.000 s (0.0%)
31 1 Anonymous
   max  (including children) = 0.000 s (0.0%)
32 1 Anonymous
}}}
33 1 Anonymous
34 1 Anonymous
CSV output for fibonnacci.anubis[[BR]]
35 1 Anonymous
Command line : ''anbexec fib 29 --profile:csv''
36 1 Anonymous
||Function||Offset||Hits||Time (excl. children)||Time %||Max (inc. children)||Max %||
37 1 Anonymous
||fib||541||1||0.001657||0.0||10.623458||100.0||
38 1 Anonymous
||fib||173||1664079||10.621774||100.0||10.621774||100.0||
39 1 Anonymous
||+||89||1||0.000027||0.0||0.000027||0.0||
40 1 Anonymous
41 1 Anonymous
== About Terminal Calls ==
42 1 Anonymous
Terminal calls can be a problem for profiling. 
43 1 Anonymous
44 1 Anonymous
First, they can't be representated by recursive calls because we can have an infinite succession of these calls.
45 1 Anonymous
46 1 Anonymous
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.
47 1 Anonymous
48 1 Anonymous
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.
49 2 Anonymous
50 2 Anonymous
51 2 Anonymous
 1. TerminalCall used as loop
52 2 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.
53 2 Anonymous
 2. TerminalCall used as automate
54 2 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.
55 2 Anonymous
 3. Functions that are simply terminating by a TerminalCall to another function.
56 2 Anonymous
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''.
Redmine Appliance - Powered by TurnKey Linux