Profilers

Raw Times

Virtually every computer system in the world lets you discover the total CPU time it took to execute your program. The Unix system provides a time command. Its syntax and semantics vary from one kind of Unix to another, but on the linux machines it looks as follows:
• % time myprog
• 10.5u 0.5s 0:11 100% 41+46k 1+3io 0pf+0w
  
  The first three columns are user time in seconds (10.5), system time in seconds (0.5) and elapsed time in minutes and seconds (0:11). In this example, the program took in 10.5 seconds inside the visible parts of the program, 0.5 seconds in system calls, and 11 seconds of elapsed time. The elapsed time is often greater than the total of user and system times, since other users can be sharing the same processor. Also, programs that use a lot of disk I/O, user interaction, etc., generally take more elapsed time than the total CPU time. In this case, myprog managed to soak up 100% of the available CPU time Q the fourth column Q during the time it was running. This figure would be lower if the processor were shared with other users or if the program performed any significant I/O. We will ignore the other numbers, since they have to do with issues outside the province of this course. To make the time command a little easier to read, try using /bin/time; it presents its interesting fields in a somewhat simpler format (THIS ISN'T on the CSIF linux machines, but is on other unix machines):
• % /bin/time prime1
• 11.0 real 10.5 user 0.5 sys
  
  It is often useful to count individual parts of a program. For this you can use the clock function as in the following program which times how long it takes to initialize an array: timing.c If you run this program with input 10,000,000 you get:
  input n = the total size of the list
  10000000
  time= 0.04
  
  Note that this may give you better accuracy than time (more digits) however be aware that more digits are printed than are truly accurate. I would be suspicious of anything below .01 seconds. You might also try timing this same program when compiled using higher optimization: $ gcc -O4 time.c

  Profiling: Basic Blocks, Counting and Timing

  Two basic Unix utilities can be used for profiling:
  gprof and gcov. gprof computes the percentage time taken by each function.
  To use gprof on a file p1.c which contains a prime computing program (this has two main functions prime1 and prime2) do the following (comments are in {})
  
  %gcc -lm -pg p1.c {compile using the -pg option}
  prof.c: In function `root':
  %./a.out { execute program }
  %gprof a.out > out_file {save profile results to out_file}
  
  %more out_file
  Displays a profile of the program.
  gcov is a more extensive profiling routine. Full details are on the gcov web page (a link is also on the class web page).

  We give an example here.
  
  % gcc -lm -fprofile-arcs -ftest-coverage p1.c
  %./ a.out
  %gcov p1.c
  File 'p1.c'
  Lines executed:95.24% of 21
  p1.c:creating 'p1.c.gcov'
  
  The file p1.c.gcov now contains output from gcov which tells us how often each line in the program was executed. Such profiles are not terribly illuminating for small programs. But they can offer a great deal of insight into larger ones.