Profiling and Debugging

Parallel Algorithms

David Mayerich

Scalable Tissue Imaging and Modeling (STIM) Laboratory

Department of Electrical and Computer Engineering

Cullen College of Engineering

University of Houston

David Mayerich

STIM Laboratory, University of Houston

C Time Function

David Mayerich

STIM Laboratory, University of Houston

  • The time() function returns the number of seconds since 1 Jan 1970
     

  • Only 1 second resolution
     

  • This can be useful for quick-and-dirty timing because it's so simple
     
  • Don't use it for any practical profiling
#include <time.h>
// ...
time_t t0 = time(NULL);
// ...
// do something
// ...
time_t t1 = time(NULL);
// duration (1s resolution)
time_t duration = t1 - t0;

C++ High-Resolution Clocks

system_clock

  • real-world "clock" time

  • not monotonic:
    jumps with system settings (ex. DST)

Usage: time stamping events so they can be correlated with other measurements

David Mayerich

STIM Laboratory, University of Houston

steady_clock

  • measures duration

  • cannot be converted to a real-world time

  • always monotonic

Usage: precise timing of events that occur in your application

  • function calls
  • thread execution time
  • benchmarking

high_resolution_clock

  • clock with the highest-resolution possible

  • implementation-specific

High Resolution Timers

David Mayerich

STIM Laboratory, University of Houston

#include <chrono>

// record a time point
std::chrono::steady_clock::time_point start = std::chrono::steady_clock::now();

// do something

// record a second time point
std::chrono::steady_clock::time_point end = std::chrono::steady_clock::now();

// calculate a duration and specify the units
std::chrono::duration<double, std::milli> d = end - start;

// get the time in seconds
// resolution is system dependent, but around 20 – 40 ns
double elapsed = d.count();

<PA1 Example>

David Mayerich

STIM Laboratory, University of Houston

Debugging Symbols

  • Metadata embedded in an executable that references the source code

  • Allows a debugger to step through lines of source code as they are being executed

    • Assigns register names to source code variables

    • Associates operations with lines/locations in source code files

  • Symbols are provided by compiling in "Debug" mode:

    • set(CMAKE_BUILD_TYPE Debug)

    • or select "Debug" in Visual Studio

  • Note on Debug Modes:

    • the compiler does not perform standard optimizations
      (this maintains consistency between the source code and executable)

    • code will run 10x times slower on a good day

David Mayerich

STIM Laboratory, University of Houston

Call Stacks

  • The call stack keeps track of active subroutines in an executing program

  • stack frame / activation record:

    • function parameters: values passed into the function

    • local variables: variables declared within the function

    • return address: pointer to the command that called this subroutine

    • corresponds to symbols in "scope"

  • stack pointer: pointer to the current function location

David Mayerich

STIM Laboratory, University of Houston

  • The stack pointer is "popped" when a function returns:

Call Stack

sphere::Hit

CalculateClosestHit

cpuRenderScene

std::thread::_Invoke

raytrace (PID: 28267)

stack pointer

Tracing

  • Records significant events:

    • function entry/exit

    • operating system calls

    • external library events

  • Provided with timestamps

David Mayerich

STIM Laboratory, University of Houston

Disadvantages:

  • Significant performance hit

    • Recording details eats up performance, especially for short-running tasks

    • Not useful for evaluating performance

  • Can get dense for long-running or interactive programs with a lot of small things going on (ex. games)

Advantages:

  • Complete picture of program execution
  • Reproducible across multiple executions
  • Mostly useful for debugging

Tools

  • strace and ltrace
  • Visual Studio debugger

DEMO - Tracing, Debugging, Call Stacks

David Mayerich

STIM Laboratory, University of Houston

Sampling (Profiling)

  • Samples the call stack during execution at regular intervals (several ms)

  • Doesn't provide timing information for functions
    (you can often extrapolate this)

  • Much lower overhead than tracing

David Mayerich

STIM Laboratory, University of Houston

Disadvantages:

  • Data can be difficult to interpret: sampling provides a statistical distribution, not a timeline

  • Can miss very short subroutines that the program doesn't spend a lot of time in

  • Sampling isn't directly reproducible across different executions:

    • System occupancy due to other processes can change the results across runs

    • Changes in caching/memory locations can impact the results

Advantages:

  • Much better for measuring execution time
  • Shows you what subroutines are "occupying" the system
  • Works well for multi-threaded processes

Sampling Software

  • Sampling is generally performed using a "profiler"

    • Visual studio has one built in

    • perf is the most common Linux tool

  • It's useful to have symbol names present:

    • set(CMAKE_BUILD_TYPE RelWithDebInfo)

    • Perform optimizations but also store symbols and source code details

David Mayerich

STIM Laboratory, University of Houston

samply

  • Cross-platform sampler that uses Firefox as a GUI:
    https://github.com/mstange/samply
     
  • Record the samples during execution:
    samply record ./mie
     
  • Profiling usually requires some system-level access
    sudo sysctl kernel.perf_event_paranoid=1
    (Windows may ask you for admin privileges)

Flame Graph

A flame graph shows the statistical distribution of the call stack based on the acquired samples

David Mayerich

STIM Laboratory, University of Houston

call stack

time spent in function

Hot Path

  • The hot path is the code in your program that consumes the most time (occupancy)

David Mayerich

STIM Laboratory, University of Houston

99% of samples are in this function

debug symbols allow correlation between samples and source code

DEMO - samply, Flame Graphs

David Mayerich

STIM Laboratory, University of Houston