Mirrors/perf-little-book
1
0
Fork 0
mirror of https://github.com/NanXiao/perf-little-book.git synced 2026-07-17 16:35:13 +00:00
Code Issues Projects Releases Wiki Activity

Initial commit

Browse source
This commit is contained in:
Nan Xiao 2019-04-12 14:11:46 +08:00
commit f20b1c6c8f
16 changed files with 604 additions and 0 deletions
Download patch file Download diff file Expand all files Collapse all files

16
README.md Normal file
View file

@ -0,0 +1,16 @@
# Perf little book
When talking about `perf` in `Linux`, it actually refers to `2` things:
a) `Perf_events` (also be called as `perf` for short): a subsystem which was merged into Linux `kernel` since `2.6.31`;
b) A powerful and comprehensive user-space tool: `perf`, which leverages `perf_events` subsystem to do performance analysis.
`Perf` is a really powerful tool. As Brendan Greeg wrote in his [Choosing a Linux Tracer (2015)](http://www.brendangregg.com/blog/2015-07-08/choosing-a-linux-tracer.html):
> If there's one tracer I'd recommend people learn, it'd be perf, as it can solve a ton of issues, and is relatively safe.
In this small tutorial, I will give a whirlwind tool of the user-space `perf` utility.

14
SUMMARY.md Normal file
View file

@ -0,0 +1,14 @@
* [Install and run perf](posts/install-and-run-perf.md)
* [What is profiling](posts/what-is-profiling.md)
* [An example of profiling application](posts/an-example-of-profiling-application.md)
* [The targets of profiling](posts/the-targets-of-profiling.md)
* [How to specify monitoring events](posts/how-to-specify-monitoring-events.md)
* [Count events](posts/count-events.md)
* [Profile memory access](posts/profile-memory-access.md)
* [Check cache false sharing](posts/check-cache-false-sharing.md)
* [Profile system in real time](posts/profile-system-in-real-time.md)
* [Trace system calls of command](posts/trace-system-calls-of-command.md)
* [Measure scheduler latency](posts/measure-scheduler-latency.md)
* [Use ftrace](posts/use-ftrace.md)
* [Show performance difference](posts/show-performance-difference.md)
* [The end](posts/the-end.md)

132
posts/an-example-of-profiling-application.md Normal file
View file

@ -0,0 +1,132 @@
# An example of profiling application
Let's see a simple example:
$ cat add_vec.cpp
#include <algorithm>
#include <iostream>
#include <vector>
constexpr int vec_size = 10000;
void mul(std::vector<int>& a, std::vector<int>& b, std::vector<int>& c)
{
std::transform(
a.begin(),
a.end(),
b.begin(),
c.begin(),
[](auto op1, auto op2) {return op1 * op2;}
);
}
std::vector<int> A(vec_size, 1);
std::vector<int> B(vec_size, 2);
std::vector<int> C(vec_size);
int main()
{
mul(A, B, C);
for (auto const& v : C)
{
if (v != 2)
{
std::cout << "Oops, something happened!\n";
return 1;
}
}
return 0;
}
Build and run "`perf record`" command to profile it:
$ g++ add_vec.cpp -o add_vec
$ perf record ./add_vec
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.003 MB perf.data (27 samples) ]
A "perf.data" file will be generated. Use "`perf report`" command to analyze it:
$ perf report
Samples: 27 of event 'cycles:uppp', Event count (approx.): 2149376
Overhead Command Shared Object Symbol
33.67% add_vec ld-2.28.so [.] do_lookup_x
26.37% add_vec ld-2.28.so [.] _dl_lookup_symbol_x
11.43% add_vec [unknown] [k] 0xffffffffb2200a87
9.16% add_vec libc-2.28.so [.] _dl_addr
8.43% add_vec add_vec [.] main
4.21% add_vec ld-2.28.so [.] _dl_relocate_object
2.76% add_vec libc-2.28.so [.] strlen
2.45% add_vec ld-2.28.so [.] strcmp
1.52% add_vec ld-2.28.so [.] _dl_next_ld_env_entry
At least from output, `do_lookup_x` in `ld-2.28.so` is sampled mostly. Highlight `main` function and press `a` (which will call "`perf annotate`" command to show annotated code):
Samples: 27 of event 'cycles:uppp', 4000 Hz, Event count (approx.): 2149376
main /home/xiaonan/perf_example/add_vec [Percent: local period]
Percent│ mov %rax,%rdi
│ → callq std::vector<int, std::allocator<int> >::begin
│ mov %rax,-0x28(%rbp)
│ mov -0x18(%rbp),%rax
│ mov %rax,%rdi
│ → callq std::vector<int, std::allocator<int> >::end
│ mov %rax,-0x20(%rbp)
│5c: lea -0x20(%rbp),%rdx
│ lea -0x28(%rbp),%rax
│ mov %rdx,%rsi
│ mov %rax,%rdi
│ → callq __gnu_cxx::operator!=<int*, std::vector<int, std::allocator<int> > >
│ test %al,%al
│ ↓ je b6
│ lea -0x28(%rbp),%rax
│ mov %rax,%rdi
│ → callq __gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > >::operator*
│ mov %rax,-0x10(%rbp)
│ mov -0x10(%rbp),%rax
100.00 │ mov (%rax),%eax
│ cmp $0x2,%eax
│ ↓ je a8
......
If you want to map the assembly code to source code, try to build program with `-g` option:
$ g++ add_vec.cpp -g -o add_vec
Another useful option of using "`perf record`" is `-g`, which records function call stack information.
$ perf record -g ./add_vec
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.004 MB perf.data (28 samples) ]
$ perf report
Samples: 28 of event 'cycles:uppp', Event count (approx.): 2044515
Children Self Command Shared Object Symbol
+ 48.61% 0.00% add_vec [unknown] [.] 0x5541f689495641d7 ▒
+ 48.61% 0.00% add_vec libc-2.28.so [.] __libc_start_main ▒
- 48.61% 18.12% add_vec add_vec [.] main ▒
- 30.48% main ▒
mul ◆
- std::transform<__gnu_cxx::__normal_iterator<int*, std::vector<int, std::allocator<int> > >, __gnu_cxx::__normal▒
+ __gnu_cxx::operator!=<int*, std::vector<int, std::allocator<int> > > ▒
- 18.12% 0x5541f689495641d7 ▒
__libc_start_main ▒
main
......
This time, every line had a '`+`' at the beginning which can show the call stack clearly (from upper lever to lower). Take `main` function as an example:
int main()
{
mul(A, B, C);
for (auto const& v : C)
{
if (v != 2)
{
std::cout << "Oops, something happened!\n";
return 1;
}
}
return 0;
}
The percentage of `mul` function's consume time is ~`30.48%`, `for-loop` accounts for ~`18.12%`. For column "`Children`", it denotes all the time spent in this function; while column "`Self`" will exclude other sub-function calls, e.g., `main` will exclude `mul`.

121
posts/check-cache-false-sharing.md Normal file
View file

@ -0,0 +1,121 @@
# Check cache false sharing
Generally speaking, cache false sharing is one processor modifies the data in one cache line, the cache protocol requires other processors who access the same data need to refresh the cache line. "`perf c2c`" command is used to debug this issue.
Check following code:
$ cat false_share.c
#include <omp.h>
#define N 100000000
#define THRAED_NUM 8
int values[N];
int main(void)
{
int sum[THRAED_NUM];
#pragma omp parallel for
for (int i = 0; i < THRAED_NUM; i++)
{
for (int j = 0; j < N; j++)
{
sum[i] += values[j] >> i;
}
}
return 0;
}
The size of `sum` array is `64` bytes on my `X64` platform, and resides in one cache line. Because all `8` threads will write it simultaneously:
sum[i] += values[j] >> i;
It will cause cache false sharing issue. Build and use "`perf c2c record`" command to profile it:
$ gcc -fopenmp -g false_share.c -o false_share
$ perf c2c record ./false_share
Use "`perf c2c report`" to analyze it, and "`HITM`" event is the central issue:
$ perf c2c report --stdio
......
=================================================
Trace Event Information
=================================================
Total records : 65407
......
LLC Misses to Local DRAM : 36.9%
LLC Misses to Remote DRAM : 33.8%
LLC Misses to Remote cache (HIT) : 0.0%
LLC Misses to Remote cache (HITM) : 29.2%
......
=================================================
Shared Cache Line Distribution Pareto
=================================================
#
# ----- HITM ----- -- Store Refs -- --------- Data address --------- ---------- cycles ---------- Total cpu Shared
# Num Rmt Lcl L1 Hit L1 Miss Offset Node PA cnt Code address rmt hitm lcl hitm load records cnt Symbol Object Source:Line Node
# ..... ....... ....... ....... ....... .................. .... ...... .................. ........ ........ ........ ....... ........ .................. ........... ................ ....
#
-------------------------------------------------------------
0 41 446 159354 22984 0x7fff35cd5c40
-------------------------------------------------------------
58.54% 59.19% 0.00% 0.00% 0x18 0 1 0x55bfa7082232 1734 1122 1150 72662 14 [.] main._omp_fn.0 false_share false_share.c:17 0 1
41.46% 38.57% 0.00% 0.00% 0x18 0 1 0x55bfa7082264 1341 1186 1151 71575 14 [.] main._omp_fn.0 false_share false_share.c:17 0 1
0.00% 0.00% 3.90% 1.41% 0x20 0 1 0x55bfa708226d 0 0 0 6541 1 [.] main._omp_fn.0 false_share false_share.c:17 1
0.00% 0.67% 0.00% 0.00% 0x24 0 1 0x55bfa708223b 0 4398 42 1484 1 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 13.84% 14.21% 0x24 0 1 0x55bfa708226d 0 0 0 25327 2 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.67% 0.00% 0.00% 0x28 0 1 0x55bfa708223b 0 1262 43 1498 1 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 13.99% 14.04% 0x28 0 1 0x55bfa708226d 0 0 0 25520 2 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.22% 0.00% 0.00% 0x2c 0 1 0x55bfa708223b 0 694 44 1661 1 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 13.60% 16.43% 0x2c 0 1 0x55bfa708226d 0 0 0 25449 1 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 14.00% 13.86% 0x30 0 1 0x55bfa708226d 0 0 0 25501 2 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.22% 0.00% 0.00% 0x34 0 1 0x55bfa708223b 0 1742 42 1548 1 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 13.14% 12.81% 0x34 0 1 0x55bfa708226d 0 0 0 23880 2 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.22% 0.00% 0.00% 0x38 0 1 0x55bfa708223b 0 286 42 1467 1 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 14.08% 13.62% 0x38 0 1 0x55bfa708226d 0 0 0 25569 2 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.22% 0.00% 0.00% 0x3c 0 1 0x55bfa708223b 0 278 44 1420 2 [.] main._omp_fn.0 false_share false_share.c:17 0
0.00% 0.00% 13.44% 13.62% 0x3c 0 1 0x55bfa708226d 0 0 0 24551 2 [.] main._omp_fn.0 false_share false_share.c:17 0
The nifty feature is the report shows which line of source code causes cache false sharing.
Modify the code to avoid false sharing:
#include <omp.h>
#define N 100000000
#define THRAED_NUM 8
int values[N];
int main(void)
{
int sum[THRAED_NUM];
#pragma omp parallel for
for (int i = 0; i < THRAED_NUM; i++)
{
int local_sum;
for (int j = 0; j < N; j++)
{
local_sum += values[j] >> i;
}
sum[i] = local_sum;
}
return 0;
}
This time the "`perf c2c report`" outputs a very beautiful summary:
=================================================
Trace Event Information
=================================================
......
LLC Misses to Local DRAM : 88.7%
LLC Misses to Remote DRAM : 9.9%
LLC Misses to Remote cache (HIT) : 0.0%
LLC Misses to Remote cache (HITM) : 1.4%
......

29
posts/count-events.md Normal file
View file

@ -0,0 +1,29 @@
# Count events
`perf stat` is used to count interested events:
# perf stat
^C
Performance counter stats for 'system wide':
2376.91 msec cpu-clock # 2.000 CPUs utilized
123 context-switches # 0.052 K/sec
1 cpu-migrations # 0.000 K/sec
0 page-faults # 0.000 K/sec
102707402 cycles # 0.043 GHz (50.10%)
34857921 instructions # 0.34 insn per cycle (75.00%)
7832558 branches # 3.295 M/sec (75.02%)
168058 branch-misses # 2.15% of all branches (74.88%)
1.188558385 seconds time elapsed
The above example shows some default events which "`perf stat`" will count. `-I` option can be used to set the frequency (unit is `ms`) of displaying result, and `--interval-count` is to specify how many times you want to run "`perf stat`". Check following example:
# perf stat -I 1000 --interval-count 5 -e cycles
# time counts unit events
1.000454837 5005909 cycles
2.001134074 3579497 cycles
3.001690949 4350491 cycles
4.002221214 3504926 cycles
5.002936768 4941014 cycles

50
posts/how-to-specify-monitoring-events.md Normal file
View file

@ -0,0 +1,50 @@
# How to specify monitoring events
The power of `perf` embodies it can monitor various of events (hardware, software, etc). Currently, `4` subcommands support `-e` option which can specify events: `perf record`, `perf stat`, `perf top` and `perf trace`. Use `perf list` to show available events:
# perf list
List of pre-defined events (to be used in -e):
branch-instructions OR branches [Hardware event]
branch-misses [Hardware event]
bus-cycles [Hardware event]
cache-misses [Hardware event]
cache-references [Hardware event]
cpu-cycles OR cycles [Hardware event]
instructions [Hardware event]
ref-cycles [Hardware event]
alignment-faults [Software event]
bpf-output [Software event]
context-switches OR cs [Software event]
cpu-clock [Software event]
......
`Perf` also provides plentiful formats of specifying interested events:
(1) Standard event name:
This is the most straightforward method: just use event name showed in "`perf list`". E.g.:"`perf stat -e cache-misses`".
(2) Raw PMU event:
PMU, abbreviated for "Performance Monitoring Unit", are hardware counters which record CPU utilities. PMU events are defined in `/sys/bus/event_source/devices/<pmu>/events/` directory. Either Use "`pmu/param1=0xxx,param2/`" or "`rNNNN`" (`r` denotes raw, and `N` is a hex digit. It is composed of "event + mask"). Still use "cache-misses" as an example:
# cat /sys/bus/event_source/devices/cpu/events/cache-misses
event=0x2e,umask=0x41
So both following instructions monitor "cache-misses" event:
# perf stat -e cpu/event=0x2e,umask=0x41/
# perf stat -e r412e
(3) Hardware breakpoint:
The format is "`mem:addr[/len][:access]`", and access can be `r` (read), `w` (write) and `x` (execute). E.g., profile write accesses in `[0x1000~1008)`:
# perf stat -e mem:0x1000/8:w
(4) Event group. E.g,:
# perf stat -e "{LLC-load-misses,cache-misses}"

42
posts/install-and-run-perf.md Normal file
View file

@ -0,0 +1,42 @@
# Install and run perf
Most `Linux` distros enable `perf_events` subsystem in kernel and ship `perf` utility by default. If not, the distro should provide package already. E.g., On `Arch Linux`, setting up `perf` is easy:
# pacman -S perf
BTW, [Acme](https://github.com/acmel) is the maintainer of `perf`, so you can always build and try state-of-the-art feature from his `perf/core` branch:
# git clone git://git.kernel.org/pub/scm/linux/kernel/git/acme/linux -b perf/core
# cd linux/tools/perf
# make menuconfig
# make
When `perf` is ready, you can launch it in terminal:
# perf
usage: perf [--version] [--help] [OPTIONS] COMMAND [ARGS]
The most commonly used perf commands are:
annotate Read perf.data (created by perf record) and display annotated code
archive Create archive with object files with build-ids found in perf.data file
bench General framework for benchmark suites
......
This will list all supported `perf` commands (The `main` function code of `perf` is [here](https://github.com/torvalds/linux/blob/54c490164523de90c42b1d89e7de3befe3284d1b/tools/perf/perf.c#L424)).
There is a `/proc/sys/kernel/perf_event_paranoid` file which controls use of the performance events system by unprivileged users (without `CAP_SYS_ADMIN`), and the default value is 2:
# cat /proc/sys/kernel/perf_event_paranoid
2
The meaning of its value is like following:
> -1: Allow use of (almost) all events by all users
Ignore mlock limit after perf_event_mlock_kb without CAP_IPC_LOCK
>\>=0: Disallow ftrace function tracepoint by users without CAP_SYS_ADMIN
Disallow raw tracepoint access by users without CAP\_SYS\_ADMIN
\>=1: Disallow CPU event access by users without CAP\_SYS\_ADMIN
\>=2: Disallow kernel profiling by users without CAP\_SYS\_ADMIN
This means you may not use some functions of `perf` if you are not privileged user (e.g., `perf mem`). So if you meet something strange, such as `perf` can't sample data, please try run as privileged user (i.e., `sudo`) or check the value of `/proc/sys/kernel/perf_event_paranoid` file.

24
posts/measure-scheduler-latency.md Normal file
View file

@ -0,0 +1,24 @@
# Measure scheduler latency
`perf sched` can be used to measure scheduler latencies. E.g,:
# perf sched record sleep 10
# perf sched latency
-----------------------------------------------------------------------------------------------------------------
Task | Runtime ms | Switches | Average delay ms | Maximum delay ms | Maximum delay at |
-----------------------------------------------------------------------------------------------------------------
sleep:11599 | 1.367 ms | 2 | avg: 0.040 ms | max: 0.056 ms | max at: 271543.365213 s
perf:11598 | 0.808 ms | 1 | avg: 0.039 ms | max: 0.039 ms | max at: 271553.366926 s
rcuc/0:11 | 0.000 ms | 110 | avg: 0.029 ms | max: 0.046 ms | max at: 271551.278028 s
dhcpcd:416 | 0.113 ms | 1 | avg: 0.029 ms | max: 0.029 ms | max at: 271545.077962 s
rcu_preempt:10 | 0.000 ms | 334 | avg: 0.029 ms | max: 0.065 ms | max at: 271546.574674 s
kworker/u4:1-ev:11597 | 3.255 ms | 61 | avg: 0.026 ms | max: 0.065 ms | max at: 271548.704707 s
kworker/1:1H-kb:218 | 0.066 ms | 2 | avg: 0.026 ms | max: 0.028 ms | max at: 271548.704684 s
ksoftirqd/0:9 | 3.141 ms | 217 | avg: 0.025 ms | max: 0.067 ms | max at: 271550.464711 s
kworker/0:3-mem:8765 | 1.355 ms | 38 | avg: 0.024 ms | max: 0.099 ms | max at: 271550.464690 s
jbd2/sda-8:231 | 0.542 ms | 6 | avg: 0.021 ms | max: 0.042 ms | max at: 271549.775918 s
systemd:1 | 0.211 ms | 1 | avg: 0.020 ms | max: 0.020 ms | max at: 271543.826050 s
......
`perf sched latency` shows the latency statistics for every task: average, minimum and maximum values.

28
posts/profile-memory-access.md Normal file
View file

@ -0,0 +1,28 @@
# Profile memory access
`perf mem` command can be used to profile memory access. I.e, `perf mem record` samples while `perf mem report` shows the results. By default, `perf mem record` will count both load and store operations, and `-t` option can be used to specify one of them (e.g, `-t load`). Check following example:
# perf mem record ./stream
# perf mem report --stdio
# To display the perf.data header info, please use --header/--header-only options.
#
#
# Total Lost Samples: 0
#
# Samples: 4K of event 'cpu/mem-loads,ldlat=30/P'
# Total weight : 203745
# Sort order : local_weight,mem,sym,dso,symbol_daddr,dso_daddr,snoop,tlb,locked
#
# Overhead Samples Local Weight Memory access Symbol Shared Object Data Symbol Data Object Snoop TLB access Locked
# ........ ............ ............ ........................ ................................ ................. ...................... ................. ............ ...................... ......
#
9.03% 575 32 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
8.97% 554 33 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
7.19% 431 34 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
6.79% 395 35 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
5.35% 303 36 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
4.16% 229 37 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
3.71% 199 38 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
3.08% 153 41 L1 or L1 hit [.] main stream [.] 0x00007ffcac77e3c8 [stack] None L1 or L2 hit No
......

27
posts/profile-system-in-real-time.md Normal file
View file

@ -0,0 +1,27 @@
# Profile system in real time
Just like `top` command:
# top
top - 17:38:28 up 1 day, 8:44, 2 users, load average: 0.00, 0.00, 0.00
Tasks: 95 total, 1 running, 94 sleeping, 0 stopped, 0 zombie
%Cpu(s): 0.0 us, 3.1 sy, 0.0 ni, 96.9 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st
MiB Mem : 3898.8 total, 2528.2 free, 85.2 used, 1285.3 buff/cache
MiB Swap: 0.0 total, 0.0 free, 0.0 used. 3541.0 avail Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
4395 root 20 0 10336 3352 2904 R 6.2 0.1 0:00.01 top
1 root 20 0 35804 9920 7708 S 0.0 0.2 0:03.06 systemd
......
`perf top` command show system activity in real time:
# perf top
Samples: 2K of event 'cycles:pp', 4000 Hz, Event count (approx.): 1153602589 lost: 0/0 drop: 0/0
Overhead Shared Object Symbol
7.21% [kernel] [k] acpi_processor_ffh_cstate_enter
6.67% libc-2.28.so [.] __GI_____strtoull_l_internal
6.65% [kernel] [k] vsnprintf
5.64% [kernel] [k] kallsyms_expand_symbol.constprop.1
5.00% perf [.] rb_next
......

22
posts/show-performance-difference.md Normal file
View file

@ -0,0 +1,22 @@
# Show performance difference
`perf diff` command is used to displays the performance difference amongst two or more `perf.data` files captured via `perf record` command. If no input files provided, it will compare `perf.data` and `perf.data.old` by default. Check following example:
# perf diff
# Event 'cycles:pp'
#
# Baseline Delta Abs Shared Object Symbol
# ........ ......... .................. ..............................................
#
20.49% -0.28% stream [.] main._omp_fn.4
20.53% -0.26% stream [.] main._omp_fn.5
24.62% -0.25% stream [.] main._omp_fn.7
0.44% -0.21% [kernel.kallsyms] [k] preempt_count_sub
24.70% -0.20% stream [.] main._omp_fn.6
0.91% -0.17% stream [.] main._omp_fn.2
+0.12% [kernel.kallsyms] [k] task_tick_fair
+0.09% [kernel.kallsyms] [k] perf_event_task_tick
0.01% +0.08% [kernel.kallsyms] [k] sugov_should_update_freq
0.25% +0.08% [kernel.kallsyms] [k] get_page_from_freelist
......
`Baseline` is from `perf.data.old`, and `perf diff` only show events comparison result matching both specified files.

3
posts/the-end.md Normal file
View file

@ -0,0 +1,3 @@
# The end
If this small manual helps you, please give it a star in [github](https://github.com/NanXiao/perf-little-book). :-)

40
posts/the-targets-of-profiling.md Normal file
View file

@ -0,0 +1,40 @@
# The targets of profiling
[An example of profiling application](an-example-of-profiling-application.md) demonstrates how to profile a program. Besides it, `perf` can also profile targets based on other qualifications:
<table>
<tr>
<th>Target</th>
<th>Option</th>
</tr>
<tr>
<th>Program</th>
<th>"perf record program".</th>
</tr>
<tr>
<th>Process</th>
<th>"perf record -p pid". Pid is process ID.</th>
</tr>
<tr>
<th>Thread</th>
<th>"perf record -t tid". Tid is thread ID.</th>
</tr>
<tr>
<th>User</th>
<th>"perf record -t uid". Uid can be user ID or name.</th>
</tr>
<tr>
<th>CPU</th>
<th>"perf record -C cpuid". Cpuid the CPU ID.</th>
</tr>
<tr>
<th>System-wide</th>
<th>"perf record -a". Profile all CPUs in the system. This is the default behaviour.</th>
</tr>
</table>
More words about `-a` option: Since it is the default behavior when no target is designated, "`perf record -a`" is synonym to "`perf record`". A common example is to profile the system in `10` seconds:
# perf record -F 99 -a sleep 10
`-F` option denotes the sampling frequency. Use an odd number, such as `99`, is to avoid lockstep sampling (Please refer [perf CPU Sampling](http://www.brendangregg.com/blog/2014-06-22/perf-cpu-sample.html) and [What is lockstep sampling?](https://stackoverflow.com/questions/45470758/what-is-lockstep-sampling)).

18
posts/trace-system-calls-of-command.md Normal file
View file

@ -0,0 +1,18 @@
# Trace system calls of command
`perf trace` works like `strace`, which show system calls of command:
# perf trace ls
? ( ): ls/14593 ... [continued]: execve()) = 0
0.045 ( 0.003 ms): ls/14593 brk() = 0x55699fe1a000
0.051 ( 0.002 ms): ls/14593 arch_prctl(option: 0x3001, arg2: 0x7ffcf8e915b0) = -1 EINVAL (Invalid argument)
0.077 ( 0.005 ms): ls/14593 access(filename: 0xd87603a0, mode: R) = -1 ENOENT (No such file or directory)
0.092 ( 0.006 ms): ls/14593 openat(dfd: CWD, filename: 0xd875d891, flags: RDONLY|CLOEXEC) = 3
0.100 ( 0.003 ms): ls/14593 fstat(fd: 3, statbuf: 0x7ffcf8e90790) = 0
0.105 ( 0.004 ms): ls/14593 mmap(len: 99497, prot: READ, flags: PRIVATE, fd: 3) = 0x7febd8722000
0.111 ( 0.002 ms): ls/14593 close(fd: 3) = 0
0.129 ( 0.006 ms): ls/14593 openat(dfd: CWD, filename: 0xd8766c70, flags: RDONLY|CLOEXEC) = 3
0.137 ( 0.003 ms): ls/14593 read(fd: 3, buf: 0x7ffcf8e90958, count: 832) = 832
0.143 ( 0.002 ms): ls/14593 fstat(fd: 3, statbuf: 0x7ffcf8e907f0) = 0
0.147 ( 0.004 ms): ls/14593 mmap(len: 8192, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS) = 0x7febd8720000
......

29
posts/use-ftrace.md Normal file
View file

@ -0,0 +1,29 @@
# Use ftrace
`perf ftrace` is a simple wrapper for kernel's `ftrace` functionality, and only supports single thread tracing now. Check following example:
# perf ftrace ./lock
2) | switch_mm_irqs_off() {
2) 1.792 us | load_new_mm_cr3();
2) 9.157 us | }
------------------------------------------
2) <idle>-0 => <...>-5785
------------------------------------------
2) | finish_task_switch() {
2) | _raw_spin_unlock_irq() {
2) ==========> |
2) | smp_irq_work_interrupt() {
2) | irq_enter() {
2) 0.612 us | rcu_irq_enter();
2) 0.631 us | irqtime_account_irq();
2) 0.457 us | preempt_count_add();
2) 3.818 us | }
2) | __wake_up() {
......
`-T` option can be used to specify only tracing interested functions:
# perf ftrace -T __kmalloc ./lock
20) + 17.698 us | __kmalloc();
20) 3.167 us | __kmalloc();
20) 0.952 us | __kmalloc();

9
posts/what-is-profiling.md Normal file
View file

@ -0,0 +1,9 @@
# What is profiling
Profiling should be an indispensable function for any performance analysis tool. But wait, what is profiling on earth? The following definition is from [Wikipedia](https://en.wikipedia.org/wiki/Profiling_(computer_programming)):
> In software engineering, profiling ("program profiling", "software profiling") is a form of dynamic program analysis that measures, for example, the space (memory) or time complexity of a program, the usage of particular instructions, or the frequency and duration of function calls. Most commonly, profiling information serves to aid program optimization.
> Profiling is achieved by instrumenting either the program source code or its binary executable form using a tool called a profiler (or code profiler). Profilers may use a number of different techniques, such as event-based, statistical, instrumented, and simulation methods.
As a profiler, `perf` provides two working mode: sampling (`perf record`) and counting (`perf stat`). Sampling is checking running system periodically to show the hotspot of the application, while counting is just a statistic of some events (mostly need support from underlying hardware).