Cachegrind: a cache-miss profiler

To use this tool, you must specify --tool=cachegrind on the Valgrind command line.

Detailed technical documentation on how Cachegrind works is available here. If you want to know how to use it, you only need to read this page.

4.1  Cache profiling

Cachegrind is a tool for doing cache simulations and annotating your source line-by-line with the number of cache misses. In particular, it records: On a modern x86 machine, an L1 miss will typically cost around 10 cycles, and an L2 miss can cost as much as 200 cycles. Detailed cache profiling can be very useful for improving the performance of your program.

Also, since one instruction cache read is performed per instruction executed, you can find out how many instructions are executed per line, which can be useful for traditional profiling and test coverage.

Any feedback, bug-fixes, suggestions, etc, welcome.

4.2  Overview

First off, as for normal Valgrind use, you probably want to compile with debugging info (the -g flag). But by contrast with normal Valgrind use, you probably do want to turn optimisation on, since you should profile your program as it will be normally run. The two steps are:
  1. Run your program with valgrind --tool=cachegrind in front of the normal command line invocation. When the program finishes, Cachegrind will print summary cache statistics. It also collects line-by-line information in a file cachegrind.out.pid, where pid is the program's process id.

    This step should be done every time you want to collect information about a new program, a changed program, or about the same program with different input.

  2. Generate a function-by-function summary, and possibly annotate source files, using the supplied cg_annotate program. Source files to annotate can be specified manually, or manually on the command line, or "interesting" source files can be annotated automatically with the --auto=yes option. You can annotate C/C++ files or assembly language files equally easily.

    This step can be performed as many times as you like for each Step 2. You may want to do multiple annotations showing different information each time.

The steps are described in detail in the following sections.

4.3  Cache simulation specifics

Cachegrind uses a simulation for a machine with a split L1 cache and a unified L2 cache. This configuration is used for all (modern) x86-based machines we are aware of. Old Cyrix CPUs had a unified I and D L1 cache, but they are ancient history now.

The more specific characteristics of the simulation are as follows.

The cache configuration simulated (cache size, associativity and line size) is determined automagically using the CPUID instruction. If you have an old machine that (a) doesn't support the CPUID instruction, or (b) supports it in an early incarnation that doesn't give any cache information, then Cachegrind will fall back to using a default configuration (that of a model 3/4 Athlon). Cachegrind will tell you if this happens. You can manually specify one, two or all three levels (I1/D1/L2) of the cache from the command line using the --I1, --D1 and --L2 options.

Other noteworthy behaviour:

If you are interested in simulating a cache with different properties, it is not particularly hard to write your own cache simulator, or to modify the existing ones in vg_cachesim_I1.c, vg_cachesim_D1.c, vg_cachesim_L2.c and vg_cachesim_gen.c. We'd be interested to hear from anyone who does.

4.4  Profiling programs

To gather cache profiling information about the program ls -l, invoke Cachegrind like this:
valgrind --tool=cachegrind ls -l
The program will execute (slowly). Upon completion, summary statistics that look like this will be printed:
==31751== I   refs:      27,742,716
==31751== I1  misses:           276
==31751== L2  misses:           275
==31751== I1  miss rate:        0.0%
==31751== L2i miss rate:        0.0%
==31751== 
==31751== D   refs:      15,430,290  (10,955,517 rd + 4,474,773 wr)
==31751== D1  misses:        41,185  (    21,905 rd +    19,280 wr)
==31751== L2  misses:        23,085  (     3,987 rd +    19,098 wr)
==31751== D1  miss rate:        0.2% (       0.1%   +       0.4%)
==31751== L2d miss rate:        0.1% (       0.0%   +       0.4%)
==31751== 
==31751== L2 misses:         23,360  (     4,262 rd +    19,098 wr)
==31751== L2 miss rate:         0.0% (       0.0%   +       0.4%)
Cache accesses for instruction fetches are summarised first, giving the number of fetches made (this is the number of instructions executed, which can be useful to know in its own right), the number of I1 misses, and the number of L2 instruction (L2i) misses.

Cache accesses for data follow. The information is similar to that of the instruction fetches, except that the values are also shown split between reads and writes (note each row's rd and wr values add up to the row's total).

Combined instruction and data figures for the L2 cache follow that.

4.5  Output file

As well as printing summary information, Cachegrind also writes line-by-line cache profiling information to a file named cachegrind.out.pid. This file is human-readable, but is best interpreted by the accompanying program cg_annotate, described in the next section.

Things to note about the cachegrind.out.pid file:

Note that older versions of Cachegrind used a log file named cachegrind.out (i.e. no .pid suffix). The suffix serves two purposes. Firstly, it means you don't have to rename old log files that you don't want to overwrite. Secondly, and more importantly, it allows correct profiling with the --trace-children=yes option of programs that spawn child processes.

4.6  Cachegrind options

Cache-simulation specific options are:

4.7  Annotating C/C++ programs

Before using cg_annotate, it is worth widening your window to be at least 120-characters wide if possible, as the output lines can be quite long.

To get a function-by-function summary, run cg_annotate --pid in a directory containing a cachegrind.out.pid file. The --pid is required so that cg_annotate knows which log file to use when several are present.

The output looks like this:

--------------------------------------------------------------------------------
I1 cache:              65536 B, 64 B, 2-way associative
D1 cache:              65536 B, 64 B, 2-way associative
L2 cache:              262144 B, 64 B, 8-way associative
Command:               concord vg_to_ucode.c
Events recorded:       Ir I1mr I2mr Dr D1mr D2mr Dw D1mw D2mw
Events shown:          Ir I1mr I2mr Dr D1mr D2mr Dw D1mw D2mw
Event sort order:      Ir I1mr I2mr Dr D1mr D2mr Dw D1mw D2mw
Threshold:             99%
Chosen for annotation:
Auto-annotation:       on

--------------------------------------------------------------------------------
Ir         I1mr I2mr Dr         D1mr   D2mr  Dw        D1mw   D2mw
--------------------------------------------------------------------------------
27,742,716  276  275 10,955,517 21,905 3,987 4,474,773 19,280 19,098  PROGRAM TOTALS

--------------------------------------------------------------------------------
Ir        I1mr I2mr Dr        D1mr  D2mr  Dw        D1mw   D2mw    file:function
--------------------------------------------------------------------------------
8,821,482    5    5 2,242,702 1,621    73 1,794,230      0      0  getc.c:_IO_getc
5,222,023    4    4 2,276,334    16    12   875,959      1      1  concord.c:get_word
2,649,248    2    2 1,344,810 7,326 1,385         .      .      .  vg_main.c:strcmp
2,521,927    2    2   591,215     0     0   179,398      0      0  concord.c:hash
2,242,740    2    2 1,046,612   568    22   448,548      0      0  ctype.c:tolower
1,496,937    4    4   630,874 9,000 1,400   279,388      0      0  concord.c:insert
  897,991   51   51   897,831    95    30        62      1      1  ???:???
  598,068    1    1   299,034     0     0   149,517      0      0  ../sysdeps/generic/lockfile.c:__flockfile
  598,068    0    0   299,034     0     0   149,517      0      0  ../sysdeps/generic/lockfile.c:__funlockfile
  598,024    4    4   213,580    35    16   149,506      0      0  vg_clientmalloc.c:malloc
  446,587    1    1   215,973 2,167   430   129,948 14,057 13,957  concord.c:add_existing
  341,760    2    2   128,160     0     0   128,160      0      0  vg_clientmalloc.c:vg_trap_here_WRAPPER
  320,782    4    4   150,711   276     0    56,027     53     53  concord.c:init_hash_table
  298,998    1    1   106,785     0     0    64,071      1      1  concord.c:create
  149,518    0    0   149,516     0     0         1      0      0  ???:tolower@@GLIBC_2.0
  149,518    0    0   149,516     0     0         1      0      0  ???:fgetc@@GLIBC_2.0
   95,983    4    4    38,031     0     0    34,409  3,152  3,150  concord.c:new_word_node
   85,440    0    0    42,720     0     0    21,360      0      0  vg_clientmalloc.c:vg_bogus_epilogue
First up is a summary of the annotation options: Then follows summary statistics for the whole program. These are similar to the summary provided when running valgrind --tool=cachegrind.

Then follows function-by-function statistics. Each function is identified by a file_name:function_name pair. If a column contains only a dot it means the function never performs that event (eg. the third row shows that strcmp() contains no instructions that write to memory). The name ??? is used if the the file name and/or function name could not be determined from debugging information. If most of the entries have the form ???:??? the program probably wasn't compiled with -g. If any code was invalidated (either due to self-modifying code or unloading of shared objects) its counts are aggregated into a single cost centre written as (discarded):(discarded).

It is worth noting that functions will come from three types of source files:

  1. From the profiled program (concord.c in this example).
  2. From libraries (eg. getc.c)
  3. From Valgrind's implementation of some libc functions (eg. vg_clientmalloc.c:malloc). These are recognisable because the filename begins with vg_, and is probably one of vg_main.c, vg_clientmalloc.c or vg_mylibc.c.
There are two ways to annotate source files -- by choosing them manually, or with the --auto=yes option. To do it manually, just specify the filenames as arguments to cg_annotate. For example, the output from running cg_annotate concord.c for our example produces the same output as above followed by an annotated version of concord.c, a section of which looks like:
--------------------------------------------------------------------------------
-- User-annotated source: concord.c
--------------------------------------------------------------------------------
Ir        I1mr I2mr Dr      D1mr  D2mr  Dw      D1mw   D2mw

[snip]

        .    .    .       .     .     .       .      .      .  void init_hash_table(char *file_name, Word_Node *table[])
        3    1    1       .     .     .       1      0      0  {
        .    .    .       .     .     .       .      .      .      FILE *file_ptr;
        .    .    .       .     .     .       .      .      .      Word_Info *data;
        1    0    0       .     .     .       1      1      1      int line = 1, i;
        .    .    .       .     .     .       .      .      .
        5    0    0       .     .     .       3      0      0      data = (Word_Info *) create(sizeof(Word_Info));
        .    .    .       .     .     .       .      .      .
    4,991    0    0   1,995     0     0     998      0      0      for (i = 0; i < TABLE_SIZE; i++)
    3,988    1    1   1,994     0     0     997     53     52          table[i] = NULL;
        .    .    .       .     .     .       .      .      .
        .    .    .       .     .     .       .      .      .      /* Open file, check it. */
        6    0    0       1     0     0       4      0      0      file_ptr = fopen(file_name, "r");
        2    0    0       1     0     0       .      .      .      if (!(file_ptr)) {
        .    .    .       .     .     .       .      .      .          fprintf(stderr, "Couldn't open '%s'.\n", file_name);
        1    1    1       .     .     .       .      .      .          exit(EXIT_FAILURE);
        .    .    .       .     .     .       .      .      .      }
        .    .    .       .     .     .       .      .      .
  165,062    1    1  73,360     0     0  91,700      0      0      while ((line = get_word(data, line, file_ptr)) != EOF)
  146,712    0    0  73,356     0     0  73,356      0      0          insert(data->;word, data->line, table);
        .    .    .       .     .     .       .      .      .
        4    0    0       1     0     0       2      0      0      free(data);
        4    0    0       1     0     0       2      0      0      fclose(file_ptr);
        3    0    0       2     0     0       .      .      .  }
(Although column widths are automatically minimised, a wide terminal is clearly useful.)

Each source file is clearly marked (User-annotated source) as having been chosen manually for annotation. If the file was found in one of the directories specified with the -I/--include option, the directory and file are both given.

Each line is annotated with its event counts. Events not applicable for a line are represented by a `.'; this is useful for distinguishing between an event which cannot happen, and one which can but did not.

Sometimes only a small section of a source file is executed. To minimise uninteresting output, Valgrind only shows annotated lines and lines within a small distance of annotated lines. Gaps are marked with the line numbers so you know which part of a file the shown code comes from, eg:

(figures and code for line 704)
-- line 704 ----------------------------------------
-- line 878 ----------------------------------------
(figures and code for line 878)
The amount of context to show around annotated lines is controlled by the --context option.

To get automatic annotation, run cg_annotate --auto=yes. cg_annotate will automatically annotate every source file it can find that is mentioned in the function-by-function summary. Therefore, the files chosen for auto-annotation are affected by the --sort and --threshold options. Each source file is clearly marked (Auto-annotated source) as being chosen automatically. Any files that could not be found are mentioned at the end of the output, eg:

--------------------------------------------------------------------------------
The following files chosen for auto-annotation could not be found:
--------------------------------------------------------------------------------
  getc.c
  ctype.c
  ../sysdeps/generic/lockfile.c
This is quite common for library files, since libraries are usually compiled with debugging information, but the source files are often not present on a system. If a file is chosen for annotation both manually and automatically, it is marked as User-annotated source. Use the -I/--include option to tell Valgrind where to look for source files if the filenames found from the debugging information aren't specific enough. Beware that cg_annotate can take some time to digest large cachegrind.out.pid files, e.g. 30 seconds or more. Also beware that auto-annotation can produce a lot of output if your program is large!

4.8  Annotating assembler programs

Valgrind can annotate assembler programs too, or annotate the assembler generated for your C program. Sometimes this is useful for understanding what is really happening when an interesting line of C code is translated into multiple instructions.

To do this, you just need to assemble your .s files with assembler-level debug information. gcc doesn't do this, but you can use the GNU assembler with the --gstabs option to generate object files with this information, eg:

as --gstabs foo.s
You can then profile and annotate source files in the same way as for C/C++ programs.

4.9  cg_annotate options

4.10  Warnings

There are a couple of situations in which cg_annotate issues warnings.

4.11  Things to watch out for

Some odd things that can occur during annotation: This list looks long, but these cases should be fairly rare.

Note: stabs is not an easy format to read. If you come across bizarre annotations that look like might be caused by a bug in the stabs reader, please let us know.

4.12  Accuracy

Valgrind's cache profiling has a number of shortcomings: Another thing worth nothing is that results are very sensitive. Changing the size of the valgrind.so file, the size of the program being profiled, or even the length of its name can perturb the results. Variations will be small, but don't expect perfectly repeatable results if your program changes at all.

While these factors mean you shouldn't trust the results to be super-accurate, hopefully they should be close enough to be useful.

4.13  Todo