< Previous post | Next post >

[2026-04-28][Daily]

Trying cachegrind on DAHL

For useful info, consult the valgrind manual.

What I benchmarked:

cd dahl/build
STARPU_NCUDA=0 valgrind --tool=cachegrind ./basic_cnn big-fashion 128 64 1
cg_annotate cachegrind.out.pid

Relevant results:

234,356,771,783 (100.0%)  PROGRAM TOTALS

--------------------------------------------------------------------------------
-- File:function summary
--------------------------------------------------------------------------------
  Ir____________________________  file:function

< 183,474,305,293 (78.3%, 78.3%)  /home/andrew/dahl/dahl/src/tasks/cpu/ml.c:
   97,216,869,376 (41.5%)           convolution_2d
   86,257,130,496 (36.8%)           convolution_2d_backward_filters

<  16,800,036,092  (7.2%, 85.5%)  /home/andrew/dahl/dahl/src/tasks/cpu/matrix.c:
    7,908,898,944  (3.4%)           matrix_vector_product
    4,446,645,248  (1.9%)           matrix_backward_max_pooling
    4,220,775,508  (1.8%)           matrix_max_pooling

<  16,161,662,504  (6.9%, 92.4%)  /home/andrew/dahl/dahl/src/tasks/cpu/vector.c:
    8,252,762,240  (3.5%)           vector_outer_product
    7,908,898,944  (3.4%)           vector_matrix_product

<   9,651,309,754  (4.1%, 96.5%)  /home/andrew/dahl/dahl/src/tasks/cpu/any.c:
    3,795,367,192  (1.6%)           any_relu
    3,291,274,240  (1.4%)           any_mul
    2,407,078,400  (1.0%)           any_add_value

<   3,636,805,120  (1.6%, 98.0%)  /home/andrew/dahl/dahl/src/tasks/cpu/block.c:block_sum_xy_axes

<   2,539,338,496  (1.1%, 99.1%)  /home/andrew/dahl/dahl/src/data_structures/block.c:
    2,539,254,400  (1.1%)           dahl_block_read_jpeg

<     671,846,400  (0.3%, 99.4%)  /home/andrew/dahl/dahl/src/data_structures/../../include/dahl_types.h:dahl_shape3d_to_index

So apparently 78% of my instructions concerns convolutions, which I'm clearly not surprised of! 41.5% vs 36.8% for forward and backward respectively. It even annotates specific lines in those functions:

/*              .         */ 
/*              .         */ void convolution_2d(void* buffers[3], void* cl_arg)
/*          4,608  (0.0%) */ {
/*              .         */     // Input block (because the image can have multiple channels)
/*         39,936  (0.0%) */     auto in = STARPU_BLOCK_GET(buffers[0]);
/*          1,024  (0.0%) */     auto in_p = (dahl_fp const*)in.ptr;
/*              .         */ 
/*              .         */     // Kernel block
/*         45,056  (0.0%) */     auto ker = STARPU_BLOCK_GET(buffers[1]);
/*          1,024  (0.0%) */     auto ker_p = (dahl_fp const*)ker.ptr;
/*              .         */ 
/*              .         */     // Output matrix
/*         43,008  (0.0%) */     auto out = STARPU_MATRIX_GET(buffers[2]);
/*          1,024  (0.0%) */     auto out_p = (dahl_fp*)out.ptr;
/*              .         */ 
/*          3,584  (0.0%) */     assert(out.nx == in.nx - ker.nx + 1);
/*          3,584  (0.0%) */     assert(out.ny == in.ny - ker.ny + 1);
/*          2,048  (0.0%) */     assert(in.nz == ker.nz);
/*              .         */ 
/*              .         */     // loop through i,j on axes x,y of the output matrix
/*        735,744  (0.0%) */     for (size_t j = 0; j < out.ny; j++)
/*              .         */     {
/*    197,409,792  (0.1%) */         for (size_t i = 0; i < out.nx; i++)
/*              .         */         {
/*     98,246,656  (0.0%) */             dahl_fp cell_res = 0.0F;
/*              .         */ 
/*              .         */             // loop through k,l,m on axes x,y,z of the kernel
/*    835,096,576  (0.4%) */             for (size_t m = 0; m < ker.nz; m++)
/*              .         */             {
/*  2,505,289,728  (1.1%) */                 for (size_t l = 0; l < ker.ny; l++)
/*              .         */                 {
/*  7,515,869,184  (3.2%) */                     for (size_t k = 0; k < ker.nx; k++)
/*              .         */                     {
/* 35,810,906,112 (15.3%) */                         dahl_fp kernel_value = ker_p[(m * ker.ldz) + (l * ker.ldy) + k];
/*              .         */                         // Here we add the offset of the slidding window (i,j) to (k,l)
/*              .         */                         // as they both correspond to (x,y).
/* 42,442,555,392 (18.1%) */                         dahl_fp in_value = in_p[(m * in.ldz) + ((l + j) * in.ldy) + k + i];
/*              .         */                         
/*  6,631,649,280  (2.8%) */                         cell_res += in_value * kernel_value;
/*              .         */                     }
/*              .         */                 }
/*              .         */             }
/*              .         */ 
/*  1,178,959,872  (0.5%) */             out_p[(j * out.ld) + i] = cell_res;
/*              .         */         }
/*              .         */     }
/*          6,144  (0.0%) */ }

Does that mean that dahl_fp in_value= in_p[(m * in.ldz) + ((l + j) * in.ldy) + k + i]; is reponsible for 18.1% of instructions in my code!?

Same for the backward one:

/*             .         */ void convolution_2d_backward_filters(void* buffers[3], void* cl_arg)
/*         4,608  (0.0%) */ {
/*             .         */     // Input block, here the orginal input of the forward pass
/*        39,936  (0.0%) */     auto in = STARPU_BLOCK_GET(buffers[0]);
/*         1,024  (0.0%) */     auto in_p = (dahl_fp const*)in.ptr;
/*             .         */ 
/*             .         */     // Kernel matrix, here the gradients output of the layer just after the convolution
/*        43,008  (0.0%) */     auto ker = STARPU_MATRIX_GET(buffers[1]);
/*         1,024  (0.0%) */     auto ker_p = (dahl_fp const*)ker.ptr;
/*             .         */ 
/*             .         */     // Output block, here the loss derivative of the convolution filters
/*        45,056  (0.0%) */     auto out = STARPU_BLOCK_GET(buffers[2]);
/*         1,024  (0.0%) */     auto out_p = (dahl_fp*)out.ptr;
/*             .         */ 
/*         3,584  (0.0%) */     assert(out.nx == in.nx - ker.nx + 1);
/*         3,584  (0.0%) */     assert(out.ny == in.ny - ker.ny + 1);
/*         2,048  (0.0%) */     assert(out.nz == in.nz);
/*             .         */ 
/*             .         */     // loop through i,j,k on axes x,y,z of the output block
/*         8,704  (0.0%) */     for (size_t k = 0; k < out.nz; k++)
/*             .         */     {
/*        26,112  (0.0%) */         for (size_t j = 0; j < out.ny; j++)
/*             .         */         {
/*        78,336  (0.0%) */             for (size_t i = 0; i < out.nx; i++)
/*             .         */             {
/*        27,648  (0.0%) */                 dahl_fp cell_res = 0.0F;
/*             .         */ 
/*             .         */                 // loop through l,m on axes x,y of the kernel
/*    19,865,088  (0.0%) */                 for (size_t m = 0; m < ker.ny; m++)
/*             .         */                 {
/* 5,330,064,384  (2.3%) */                     for (size_t l = 0; l < ker.nx; l++)
/*             .         */                     {
/*31,831,916,544 (13.6%) */                         dahl_fp kernel_value = ker_p[(m * ker.ld) + l];
/*             .         */                         // Here we use k, the index on the z axis of the output, as input owns as many channels.
/*             .         */                         // The kernel doesn't own a channel dimension in this function, so we ignore it.
/*             .         */                         // Then we add the offset of the slidding window (i,j) to (l,m)
/*             .         */                         // as they both correspond to (x,y).
/*42,442,555,392 (18.1%) */                         dahl_fp in_value = in_p[(k * in.ldz) + ((m + j) * in.ldy) + l + i];
/*             .         */ 
/* 6,631,649,280  (2.8%) */                         cell_res += in_value * kernel_value;
/*             .         */                     }
/*             .         */                 }
/*             .         */ 
/*             .         */                 // Set the corresponding value for index i,j,k
/*       787,968  (0.0%) */                 out_p[(k * out.ldz) + (j * out.ldy) + i] += cell_res;
/*             .         */             }
/*             .         */         }
/*             .         */     }
/*         6,144  (0.0%) */ }

Here we also have 18.1% for the similar line that computes in_value. This accounts roughly to 78% of code being run in convolutions, makes sense However we should note that cachegrind is a simulation, authors clearly state that:

However, the simulations are basic and unlikely to reflect the behaviour of a modern machine. For this reason they are off by default. If you really want cache and branch information, a profiler like perf that accesses hardware counters is a better choice.

It might be relevant for instructions count, but maybe not cache as we planned? In any ways we will use perf to actually benchmark, cachegrind simulation could be a suplement. Activating cache and branch sim:

.
==72444== Cachegrind, a high-precision tracing profiler
==72444== Copyright (C) 2002-2024, and GNU GPL'd, by Nicholas Nethercote et al.
==72444== Using Valgrind-3.23.0 and LibVEX; rerun with -h for copyright info
==72444== Command: ./basic_cnn big-fashion 128 64 1
==72444== 
--72444-- warning: L3 cache found, using its data for the LL simulation.
--72444-- warning: specified LL cache: line_size 64  assoc 11  total_size 34,603,008
--72444-- warning: simulated LL cache: line_size 64  assoc 17  total_size 35,651,584

...

==72444== 
==72444== I refs:        234,292,942,172
==72444== I1  misses:          9,149,080
==72444== LLi misses:            154,540
==72444== I1  miss rate:            0.00%
==72444== LLi miss rate:            0.00%
==72444== 
==72444== D refs:         90,684,801,247  (78,665,672,322 rd   + 12,019,128,925 wr)
==72444== D1  misses:        531,530,719  (   466,415,246 rd   +     65,115,473 wr)
==72444== LLd misses:        123,148,324  (    59,371,842 rd   +     63,776,482 wr)
==72444== D1  miss rate:             0.6% (           0.6%     +            0.5%  )
==72444== LLd miss rate:             0.1% (           0.1%     +            0.5%  )
==72444== 
==72444== LL refs:           540,679,799  (   475,564,326 rd   +     65,115,473 wr)
==72444== LL misses:         123,302,864  (    59,526,382 rd   +     63,776,482 wr)
==72444== LL miss rate:              0.0% (           0.0%     +            0.5%  )
==72444== 
==72444== Branches:       34,250,023,868  (34,237,189,662 cond +     12,834,206 ind)
==72444== Mispredicts:     1,004,753,017  ( 1,002,578,995 cond +      2,174,022 ind)
==72444== Mispred rate:              2.9% (           2.9%     +           16.9%   )
andrew@rammus ~/d/d/build (main) [nix] > 

Once again we can annotate the code to visualize where inneficiencies happens. Here I use cg_annotate --show=Bc,Bcm to only show conditional banch executed and conditional branch misspredicted.

34,237,189,662 (100.0%) 1,002,578,995 (100.0%)  PROGRAM TOTALS

--------------------------------------------------------------------------------
-- File:function summary
--------------------------------------------------------------------------------
  Bc___________________________ Bcm_______________________  file:function

< 25,358,145,104 (74.1%, 74.1%) 643,764,197 (64.2%, 64.2%)  /home/andrew/dahl/dahl/src/tasks/cpu/ml.c:
  13,411,053,568 (39.2%)        638,787,968 (63.7%)           convolution_2d
  11,947,035,648 (34.9%)          4,973,576  (0.5%)           convolution_2d_backward_filters

<  2,910,598,058  (8.5%, 82.6%) 168,864,463 (16.8%, 81.1%)  /home/andrew/dahl/dahl/src/tasks/cpu/matrix.c:
   1,461,425,280  (4.3%)         85,966,053  (8.6%)           matrix_vector_product
     712,491,520  (2.1%)         36,936,661  (3.7%)           matrix_backward_max_pooling
     712,491,520  (2.1%)         45,961,600  (4.6%)           matrix_max_pooling

<  2,922,851,302  (8.5%, 91.1%) 171,932,655 (17.1%, 98.2%)  /home/andrew/dahl/dahl/src/tasks/cpu/vector.c:
   1,461,425,280  (4.3%)         85,966,142  (8.6%)           vector_outer_product
   1,461,425,280  (4.3%)         85,966,414  (8.6%)           vector_matrix_product

<  1,904,455,612  (5.6%, 96.7%)     782,585  (0.1%, 98.3%)  /home/andrew/dahl/dahl/src/tasks/cpu/any.c:
     793,852,704  (2.3%)            779,097  (0.1%)           any_relu
     638,604,544  (1.9%)                155  (0.0%)           any_mul
     442,113,536  (1.3%)                883  (0.0%)           any_add_value

<    638,973,824  (1.9%, 98.5%)     184,368  (0.0%, 98.3%)  /home/andrew/dahl/dahl/src/tasks/cpu/block.c:block_sum_xy_axes

<    323,668,032  (0.9%, 99.5%)  12,491,064  (1.2%, 99.5%)  /home/andrew/dahl/dahl/src/data_structures/block.c:
     323,667,200  (0.9%)         12,491,064  (1.2%)           dahl_block_read_jpeg

<              0  (0.0%, 99.5%)           0  (0.0%, 99.5%)  /home/andrew/dahl/dahl/src/data_structures/../../include/dahl_types.h:dahl_shape3d_to_index

Again convolutions are guilty. Left is correct, right is miss prediction.

/*             .                   .         */ void convolution_2d(void* buffers[3], void* cl_arg)
/*             0                   0         */ {
/*             .                   .         */     // Input block (because the image can have multiple channels)
/*         4,608  (0.0%)         524  (0.0%) */     auto in = STARPU_BLOCK_GET(buffers[0]);
/*             0                   0         */     auto in_p = (dahl_fp const*)in.ptr;
/*             .                   .         */ 
/*             .                   .         */     // Kernel block
/*         5,632  (0.0%)          34  (0.0%) */     auto ker = STARPU_BLOCK_GET(buffers[1]);
/*             0                   0         */     auto ker_p = (dahl_fp const*)ker.ptr;
/*             .                   .         */ 
/*             .                   .         */     // Output matrix
/*         5,632  (0.0%)          31  (0.0%) */     auto out = STARPU_MATRIX_GET(buffers[2]);
/*             0                   0         */     auto out_p = (dahl_fp*)out.ptr;
/*             .                   .         */ 
/*           512  (0.0%)           0         */     assert(out.nx == in.nx - ker.nx + 1);
/*           512  (0.0%)          57  (0.0%) */     assert(out.ny == in.ny - ker.ny + 1);
/*           512  (0.0%)           2  (0.0%) */     assert(in.nz == ker.nz);
/*             .                   .         */ 
/*             .                   .         */     // loop through i,j on axes x,y of the output matrix
/*       183,808  (0.0%)         512  (0.0%) */     for (size_t j = 0; j < out.ny; j++)
/*             .                   .         */     {
/*    49,306,624  (0.1%)     183,298  (0.0%) */         for (size_t i = 0; i < out.nx; i++)
/*             .                   .         */         {
/*             0                   0         */             dahl_fp cell_res = 0.0F;
/*             .                   .         */ 
/*             .                   .         */             // loop through k,l,m on axes x,y,z of the kernel
/*   196,493,312  (0.6%)  49,123,333  (4.9%) */             for (size_t m = 0; m < ker.nz; m++)
/*             .                   .         */             {
/*   589,479,936  (1.7%) 147,370,002 (14.7%) */                 for (size_t l = 0; l < ker.ny; l++)
/*             .                   .         */                 {
/* 1,768,439,808  (5.2%) 442,109,972 (44.1%) */                     for (size_t k = 0; k < ker.nx; k++)
/*             .                   .         */                     {
/* 5,305,319,424 (15.5%)         193  (0.0%) */                         dahl_fp kernel_value = ker_p[(m * ker.ldz) + (l * ker.ldy) + k];
/*             .                   .         */                         // Here we add the offset of the slidding window (i,j) to (k,l)
/*             .                   .         */                         // as they both correspond to (x,y).
/* 5,305,319,424 (15.5%)           4  (0.0%) */                         dahl_fp in_value = in_p[(m * in.ldz) + ((l + j) * in.ldy) + k + i];
/*             .                   .         */                         
/*             0                   0         */                         cell_res += in_value * kernel_value;
/*             .                   .         */                     }
/*             .                   .         */                 }
/*             .                   .         */             }
/*             .                   .         */ 
/*   196,493,312  (0.6%)           4  (0.0%) */             out_p[(j * out.ld) + i] = cell_res;
/*             .                   .         */         }
/*             .                   .         */     }
/*           512  (0.0%)           2  (0.0%) */ }

The backward one however does not suffer that much from branch missprediction, which is really interesting.

/*             .                   .         */ void convolution_2d_backward_filters(void* buffers[3], void* cl_arg)
/*             0                   0         */ {
/*             .                   .         */     // Input block, here the orginal input of the forward pass
/*         4,608  (0.0%)         526  (0.0%) */     auto in = STARPU_BLOCK_GET(buffers[0]);
/*             0                   0         */     auto in_p = (dahl_fp const*)in.ptr;
/*             .                   .         */ 
/*             .                   .         */     // Kernel matrix, here the gradients output of the layer just after the convolution
/*         5,632  (0.0%)           7  (0.0%) */     auto ker = STARPU_MATRIX_GET(buffers[1]);
/*             0                   0         */     auto ker_p = (dahl_fp const*)ker.ptr;
/*             .                   .         */ 
/*             .                   .         */     // Output block, here the loss derivative of the convolution filters
/*         5,632  (0.0%)         263  (0.0%) */     auto out = STARPU_BLOCK_GET(buffers[2]);
/*             0                   0         */     auto out_p = (dahl_fp*)out.ptr;
/*             .                   .         */ 
/*           512  (0.0%)         512  (0.0%) */     assert(out.nx == in.nx - ker.nx + 1);
/*           512  (0.0%)         512  (0.0%) */     assert(out.ny == in.ny - ker.ny + 1);
/*           512  (0.0%)           4  (0.0%) */     assert(out.nz == in.nz);
/*             .                   .         */ 
/*             .                   .         */     // loop through i,j,k on axes x,y,z of the output block
/*         2,048  (0.0%)         512  (0.0%) */     for (size_t k = 0; k < out.nz; k++)
/*             .                   .         */     {
/*         6,144  (0.0%)       2,051  (0.0%) */         for (size_t j = 0; j < out.ny; j++)
/*             .                   .         */         {
/*        18,432  (0.0%)       5,128  (0.0%) */             for (size_t i = 0; i < out.nx; i++)
/*             .                   .         */             {
/*             0                   0         */                 dahl_fp cell_res = 0.0F;
/*             .                   .         */ 
/*             .                   .         */                 // loop through l,m on axes x,y of the kernel
/*     4,962,816  (0.0%)      13,832  (0.0%) */                 for (size_t m = 0; m < ker.ny; m++)
/*             .                   .         */                 {
/* 1,331,278,848  (3.9%)   4,948,998  (0.5%) */                     for (size_t l = 0; l < ker.nx; l++)
/*             .                   .         */                     {
/* 5,305,319,424 (15.5%)       1,222  (0.0%) */                         dahl_fp kernel_value = ker_p[(m * ker.ld) + l];
/*             .                   .         */                         // Here we use k, the index on the z axis of the output, as input owns as many channels.
/*             .                   .         */                         // The kernel doesn't own a channel dimension in this function, so we ignore it.
/*             .                   .         */                         // Then we add the offset of the slidding window (i,j) to (l,m)
/*             .                   .         */                         // as they both correspond to (x,y).
/* 5,305,319,424 (15.5%)           5  (0.0%) */                         dahl_fp in_value = in_p[(k * in.ldz) + ((m + j) * in.ldy) + l + i];
/*             .                   .         */ 
/*             0                   0         */                         cell_res += in_value * kernel_value;
/*             .                   .         */                     }
/*             .                   .         */                 }
/*             .                   .         */ 
/*             .                   .         */                 // Set the corresponding value for index i,j,k
/*       110,592  (0.0%)           2  (0.0%) */                 out_p[(k * out.ldz) + (j * out.ldy) + i] += cell_res;
/*             .                   .         */             }
/*             .                   .         */         }
/*             .                   .         */     }
/*           512  (0.0%)           2  (0.0%) */ }

< Previous post | Next post >