Skip to article frontmatterSkip to article content
Site not loading correctly?

This may be due to an incorrect BASE_URL configuration. See the MyST Documentation for reference.

Profiling

Profiling is the process of measuring where your code spends time and resources. For scientific applications that may run for days or weeks on large supercomputers, even small performance improvements in critical bottlenecks can lead to massive time and energy savings.

In this lecture, we will:

The original slides (by Jim Stone and Romain Teyssier) are available here.

Performance

The two principles of optimization

Measuring performance

We’re spoiled by Moore’s Law

In 1965, Gordon Moore predicted that the transistor density in integrated circuits would double every two years. In practice, performance has doubled roughly every 18 months, as shown by the Top500 list of the fastest computers in the world:

But we are forced to use mass-produced commodity processors that were not designed for scientific computing. To use them efficiently, we need to understand how they work.

Processor design

CPU, sockets, cores and threads

Register-to-register architecture

Virtually all processors use a register-to-register architecture: data processed by the CPU enters and leaves via registers. The statement C = A + B becomes

Load  R1, A
Load  R2, B
Add   R3, R1, R2
Store R3, C

Each operation requires at least one clock period, so this example takes at least four clock periods.

Pipelining

The same sequence of instructions is often repeated many times (e.g. inside loops). Processors are designed so that different steps of the sequence can execute at the same time, like an assembly line:

Clock cycle123456789
instr. iIFIDMEEXWB
instr. i+1IFIDMEEXWB
instr. i+2IFIDMEEXWB
instr. i+3IFIDMEEXWB
instr. i+4IFIDMEEXWB

IF = instruction fetch, ID = instruction decode, ME = memory reference, EX = execute, WB = write back.

Vectorization (SIMD)

Memory design

Reading data from RAM is slow

Hierarchical memory: the cache

To hide this latency, processors use small and fast memories close to the cores, called caches:

Example of cache memory architecture for a 6-core socket.

Cache lines, hits and misses

Another common complaint: “My code runs fine on a small problem, but when I try a bigger problem, it slows to a crawl.” Most likely, the data structures no longer fit in cache (much slower) or in main memory (much, much slower). The following benchmark of y += alpha * x shows the drop in performance when the vectors no longer fit in cache:

Source: Eigen benchmark.

Write code to maximize cache hits

Always access data contiguously: order the loops so that the inner loop runs over neighboring elements in memory (stride of one).

In C and C++, arrays are stored in row-major order (m[0][0], m[0][1], m[0][2], ...), so the last index should vary fastest:

// row.c
#include <stdio.h>
#include <time.h>
int m[9999][9999];

int main() {
  clock_t start, stop;

  start = clock();
  for (int i = 0; i < 9999; i++)
    for (int j = 0; j < 9999; j++)
      m[i][j] = m[i][j] + (m[i][j] * m[i][j]);
  stop = clock();
  printf("The run-time of row major order is %lf\n",
         (double)(stop - start) / CLOCKS_PER_SEC);

  start = clock();
  for (int j = 0; j < 9999; j++)
    for (int i = 0; i < 9999; i++)
      m[i][j] = m[i][j] + (m[i][j] * m[i][j]);
  stop = clock();
  printf("The run-time of column major order is %lf\n",
         (double)(stop - start) / CLOCKS_PER_SEC);
  return 0;
}
$ gcc -Og -o row row.c
$ ./row
  The run-time of row major order is 0.257015
  The run-time of column major order is 0.690201

Fortran uses exactly the opposite convention: arrays are stored in column-major order (m(1,1), m(2,1), m(3,1), ...), so the first index should vary fastest:

! column.f90
program column
  integer :: i, j
  real :: tstart, tstop
  integer, dimension(1:9999, 1:9999) :: m

  call cpu_time(tstart)
  do i = 1, 9999
     do j = 1, 9999
        m(i,j) = m(i,j) + m(i,j)*m(i,j)
     end do
  end do
  call cpu_time(tstop)
  write(*,*) 'The run-time of row major order is', tstop - tstart

  call cpu_time(tstart)
  do j = 1, 9999
     do i = 1, 9999
        m(i,j) = m(i,j) + m(i,j)*m(i,j)
     end do
  end do
  call cpu_time(tstop)
  write(*,*) 'The run-time of column major order is', tstop - tstart
end program column
$ gfortran -Og column.f90 -o col
$ ./col
  The run-time of row major order is  0.916261017
  The run-time of column major order is  0.148454964

The same applies in Python: NumPy arrays are row-major by default (like C).

Also:

Role of compilers

Hardware is designed to optimize the instructions produced by compilers. Compilers can:

In short, compilers can do a lot, so let the compiler do the work.

Compiler options

For the GNU compilers (man gcc or man gfortran):

OptionDescription
-O0no optimization, useful for debugging
-O1conservative optimization, does not increase code size
-O2normal optimization, vectorization and loop optimization
-O3aggressive optimization, takes longer to compile and risky
-fopenmpactivate OpenMP parallelization
-gadd extra information for debuggers
gfortran -O3 -fopenmp -x f95-cpp-input -DNDIM=2 code.f90 -o code

Examples of compiler optimizations

! before
do i = 1, n
   a(i) = b(i) + d*c(i)
end do

! after
do i = 1, n-3, 4
   a(i)   = b(i)   + d*c(i)
   a(i+1) = b(i+1) + d*c(i+1)
   a(i+2) = b(i+2) + d*c(i+2)
   a(i+3) = b(i+3) + d*c(i+3)
end do
do j = i, n
   a(j) = b(j) + d*c(j)
end do
! before
do i = 1, n
   do j = 1, m
      a(i,j) = d(j)/2
   end do
end do

! after
tempdiv = 1/2.
do i = 1, n
   do j = 1, m
      a(i,j) = d(j)*tempdiv
   end do
end do
// before
for (i = 0; i < n; i++)
  for (j = 0; j < n; j++)
    a[i][j] += b[i][j];

// after
for (ii = 0; ii < n; ii += B)
  for (jj = 0; jj < n; jj += B)
    for (i = ii; i < ii + B; i++)
      for (j = jj; j < jj + B; j++)
        a[i][j] += b[i][j];

Algorithms and data structures

Most of the speed-up in scientific computing comes from algorithms, not from faster computers: iterative versus direct solvers, multigrid, conjugate gradient, FFT, tree codes, fast multipole methods...

The importance of scaling is illustrated by this example from Programming Pearls (Column 8), with 4 different algorithms for the same problem:

Problem size n1.3n31.3n^310n210n^247nlog⁡2n47 n \log_2 n48n48n
1031.3 secs10 msecs0.4 msecs0.05 msec
10422 mins1 sec6 msecs0.5 msecs
10515 days1.7 min78 msecs5 msecs
10641 yrs2.8 hrs0.94 secs48 msecs
10741 millennia1.7 wks11 secs0.48 secs

Profiling

What is a profile?

A profile measures where a program spends its time:

The term profile was invented by Donald Knuth in 1971.

When to worry about performance?

“Programmers waste enormous amounts of time thinking about, or worrying about, the speed of noncritical parts of their programs, and these attempts at efficiency have a strong negative impact when debugging and maintenance are considered. We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil. Yet we should not pass up our opportunities in that critical 3%. [...] It is often a mistake to make a priori judgments about what parts of a program are really critical, since the universal experience of programmers who have been using measurement tools has been that their intuitive guesses fail.”

Donald Knuth, 1974

Concentrate on the hot spots

Profiling with gprof

$ g++ -pg imageAccess.cpp -o imageAccess
$ ./imageAccess 400
$ gprof imageAccess

For a 400×400 image (1000 calls of each routine):

  %   cumulative   self              self     total
 time   seconds   seconds    calls  us/call  us/call  name
 34.47      0.22     0.22     1000   220.63   220.63  add1(Image&, int)
 26.64      0.39     0.17     1000   170.49   170.49  add2(Image&, int)
 17.24      0.50     0.11     1000   110.32   110.32  add3(Image&, int)
 12.54      0.58     0.08     1000    80.23    80.23  set(Image&, int)
  9.40      0.64     0.06     1000    60.17    60.17  Image::Image(int, int)

For a 4000×4000 image (only 10 calls of each routine):

  %   cumulative   self              self     total
 time   seconds   seconds    calls  ms/call  ms/call  name
 52.31      1.21     1.21       10   121.35   121.35  add1(Image&, int)
 17.72      1.62     0.41       10    41.12    41.12  Image::Image(int, int)
 10.37      1.87     0.24       10    24.07    24.07  add2(Image&, int)
  9.94      2.10     0.23       10    23.07    23.07  set(Image&, int)
  9.94      2.33     0.23       10    23.07    23.07  add3(Image&, int)

add1 is only a little slower than add2 on the small image, but becomes 5 times slower on the large one. Why? (Hint: think about the cache!)

Advanced profilers

See the Princeton Research Computing knowledge base to get started.

Lessons learned