6.2.4 Profiling
If you specify a with profile or with profile_time (
Windows only) directive, then a special listing of your program, called a
profile, will be produced by the interpreter when your program finishes execution. This listing is written to the file
ex.pro in the current directory.
There are two types of profiling available: execution-count profiling, and time profiling. You get
execution-count profiling when you specify with profile. You get
time profiling when you specify with profile_time. You can not mix the two types of profiling in a single run of your program. You need to make two separate runs.
We ran the sieve8k.ex benchmark program in demo\bench under both types of profiling. The results are in sieve8k.pro (execution-count profiling) and sieve8k.pro2 (time profiling).
Execution-count profiling shows precisely how many times each statement in your program was executed. If the statement was never executed the count field will be blank.
Time profiling shows an estimate of the total time spent executing each statement. This estimate is expressed as a percentage of the time spent profiling your program. If a statement was never sampled, the percentage field will be blank. If you see 0.00 it means the statement was sampled, but not enough to get a score of 0.01.
Only statements compiled with profile or with profile_time are shown in the listing. Normally you will specify either with profile or with profile_time at the top of your main .ex* file, so you can get a complete listing. View this file with the Euphoria editor to see a color display.
Profiling can help you in many ways:
- It lets you see which statements are heavily executed, as a clue to speeding up your program
- It lets you verify that your program is actually working the way you intended
- It can provide you with statistics about the input data
- It lets you see which sections of code were never tested -- don't let your users be the first!
Sometimes you will want to focus on a particular action performed by your program. For example, in the
Language War game, we found that the game in general was fast enough, but when a planet exploded, shooting 2500 pixels off in all directions, the game slowed down. We wanted to speed up the explosion routine. We did not care about the rest of the code. The solution was to call profile(0) at the beginning of Language War, just after with profile_time, to turn off profiling, and then to call profile(1) at the beginning of the explosion routine and profile(0) at the end of the routine. In this way we could run the game, creating numerous explosions, and logging a lot of samples, just for the explosion effect. If samples were charged against other lower-level routines, we knew that those samples occurred during an explosion. If we had simply profiled the whole program, the picture would not have been clear, as the lower-level routines would also have been used for moving ships, drawing phasors etc. profile() can help in the same way when you do execution-count profiling.