https://redis.io/docs/management/optimization/cpu-profiling/
Performance engineering guide for on-CPU profiling and tracing
Redis is developed with a great emphasis on performance. We do our best with every release to make sure you'll experience a very stable and fast product.
Nevertheless, if you're finding room to improve the efficiency of Redis or are pursuing a performance regression investigation you will need a concise methodical way of monitoring and analyzing Redis performance.
To do so you can rely on different methodologies (some more suited than other depending on the class of issues/analysis we intent to make). A curated list of methodologies and their steps are enumerated by Brendan Greg at the following link.
We recommend the Utilization Saturation and Errors (USE) Method for answering the question of what is your bottleneck. Check the following mapping between system resource, metric, and tools for a pratical deep dive: USE method.
This guide assumes you've followed one of the above methodologies to perform a complete check of system health, and identified the bottleneck being the CPU. If you have identified that most of the time is spent blocked on I/O, locks, timers, paging/swapping, etc., this guide is not for you.
For a proper On-CPU analysis, Redis (and any dynamically loaded library like Redis Modules) requires stack traces to be available to tracers, which you may need to fix first.
By default, Redis is compiled with the -O2 switch (which we intent to keep during profiling). This means that compiler optimizations are enabled. Many compilers omit the frame pointer as a runtime optimization (saving a register), thus breaking frame pointer-based stack walking. This makes the Redis executable faster, but at the same time it makes Redis (like any other program) harder to trace, potentially wrongfully pinpointing on-CPU time to the last available frame pointer of a call stack that can get a lot deeper (but impossible to trace).
It's important that you ensure that:
-g-fno-omit-frame-pointer-O2You can do it as follows within redis main repo:
$ make REDIS_CFLAGS="-g -fno-omit-frame-pointer"
This document focuses specifically on on-CPU resource bottlenecks analysis, meaning we're interested in understanding where threads are spending CPU cycles while running on-CPU and, as importantly, whether those cycles are effectively being used for computation or stalled waiting (not blocked!) for memory I/O, and cache misses, etc.
For that we will rely on toolkits (perf, bcc tools), and hardware specific PMCs (Performance Monitoring Counters), to proceed with:
Hotspot analysis (pref or bcc tools): to profile code execution and determine which functions are consuming the most time and thus are targets for optimization. We'll present two options to collect, report, and visualize hotspots either with perf or bcc/BPF tracing tools.
Call counts analysis: to count events including function calls, enabling us to correlate several calls/components at once, relying on bcc/BPF tracing tools.
Hardware event sampling: crucial for understanding CPU behavior, including memory I/O, stall cycles, and cache misses.
The following steps rely on Linux perf_events (aka "perf"), bcc/BPF tracing tools, and Brendan Greg’s FlameGraph repo.
We assume beforehand you have:
difffolded.pl and flamegraph.pl files, to generated the collapsed stack traces and Flame Graphs.Profiling CPU usage by sampling stack traces at a timed interval is a fast and easy way to identify performance-critical code sections (hotspots).
To profile both user- and kernel-level stacks of redis-server for a specific length of time, for example 60 seconds, at a sampling frequency of 999 samples per second:
$ perf record -g --pid $(pgrep redis-server) -F 999 -- sleep 60
By default perf record will generate a perf.data file in the current working directory.
You can then report with a call-graph output (call chain, stack backtrace), with a minimum call graph inclusion threshold of 0.5%, with:
$ perf report -g "graph,0.5,caller"
See the perf report documentation for advanced filtering, sorting and aggregation capabilities.
Flame graphs allow for a quick and accurate visualization of frequent code-paths. They can be generated using Brendan Greg's open source programs on github, which create interactive SVGs from folded stack files.
Specifically, for perf we need to convert the generated perf.data into the captured stacks, and fold each of them into single lines. You can then render the on-CPU flame graph with:
$ perf script > redis.perf.stacks
$ stackcollapse-perf.pl redis.perf.stacks > redis.folded.stacks
$ flamegraph.pl redis.folded.stacks > redis.svg
By default, perf script will generate a perf.data file in the current working directory. See the perf script documentation for advanced usage.
See FlameGraph usage options for more advanced stack trace visualizations (like the differential one).
So that analysis of the perf.data contents can be possible on a machine other than the one on which collection happened, you need to export along with the perf.data file all object files with build-ids found in the record data file. This can be easily done with the help of perf-archive.sh script:
$ perf-archive.sh perf.data
Now please run:
$ tar xvf perf.data.tar.bz2 -C ~/.debug
on the machine where you need to run perf report.
Similarly to perf, as of Linux kernel 4.9, BPF-optimized profiling is now fully available with the promise of lower overhead on CPU (as stack traces are frequency counted in kernel context) and disk I/O resources during profiling.
Apart from that, and relying solely on bcc/BPF's profile tool, we have also removed the perf.data and intermediate steps if stack traces analysis is our main goal. You can use bcc's profile tool to output folded format directly, for flame graph generation:
$ /usr/share/bcc/tools/profile -F 999 -f --pid $(pgrep redis-server) --duration 60 > redis.folded.stacks
In that manner, we've remove any preprocessing and can render the on-CPU flame graph with a single command:
$ flamegraph.pl redis.folded.stacks > redis.svg
A function may consume significant CPU cycles either because its code is slow or because it's frequently called. To answer at what rate functions are being called, you can rely upon call counts analysis using BCC's funccount tool:
$ /usr/share/bcc/tools/funccount 'redis-server:(call*|*Read*|*Write*)' --pid $(pgrep redis-server) --duration 60
Tracing 64 functions for "redis-server:(call*|*Read*|*Write*)"... Hit Ctrl-C to end.
FUNC COUNT
call 334
handleClientsWithPendingWrites 388
clientInstallWriteHandler 388
postponeClientRead 514
handleClientsWithPendingReadsUsingThreads 735
handleClientsWithPendingWritesUsingThreads 735
prepareClientToWrite 1442
Detaching...
The above output shows that, while tracing, the Redis's call() function was called 334 times, handleClientsWithPendingWrites() 388 times, etc.
Many modern processors contain a performance monitoring unit (PMU) exposing Performance Monitoring Counters (PMCs). PMCs are crucial for understanding CPU behavior, including memory I/O, stall cycles, and cache misses, and provide low-level CPU performance statistics that aren't available anywhere else.
The design and functionality of a PMU is CPU-specific and you should assess your CPU supported counters and features by using perf list.
To calculate the number of instructions per cycle, the number of micro ops executed, the number of cycles during which no micro ops were dispatched, the number stalled cycles on memory, including a per memory type stalls, for the duration of 60s, specifically for redis process:
$ perf stat -e "cpu-clock,cpu-cycles,instructions,uops_executed.core,uops_executed.stall_cycles,cache-references,cache-misses,cycle_activity.stalls_total,cycle_activity.stalls_mem_any,cycle_activity.stalls_l3_miss,cycle_activity.stalls_l2_miss,cycle_activity.stalls_l1d_miss" --pid $(pgrep redis-server) -- sleep 60
Performance counter stats for process id '3038':
60046.411437 cpu-clock (msec) # 1.001 CPUs utilized
168991975443 cpu-cycles # 2.814 GHz (36.40%)
388248178431 instructions # 2.30 insn per cycle (45.50%)
443134227322 uops_executed.core # 7379.862 M/sec (45.51%)
30317116399 uops_executed.stall_cycles # 504.895 M/sec (45.51%)
670821512 cache-references # 11.172 M/sec (45.52%)
23727619 cache-misses # 3.537 % of all cache refs (45.43%)
30278479141 cycle_activity.stalls_total # 504.251 M/sec (36.33%)
19981138777 cycle_activity.stalls_mem_any # 332.762 M/sec (36.33%)
725708324 cycle_activity.stalls_l3_miss # 12.086 M/sec (36.33%)
8487905659 cycle_activity.stalls_l2_miss # 141.356 M/sec (36.32%)
10011909368 cycle_activity.stalls_l1d_miss # 166.736 M/sec (36.31%)
60.002765665 seconds time elapsed
It's important to know that there are two very different ways in which PMCs can be used (counting and sampling), and we've focused solely on PMCs counting for the sake of this analysis. Brendan Greg clearly explains it on the following link.