xref: /openbmc/openbmc-tools/tracing/README.md (revision e310dd91)
1# trace
2
3## Description
4
5The trace script automates the process of enabling named sets of tracepoints and
6dumping the trace file over the SSH connection, then cleaning up after itself.
7
8## Usage
9
10To run:
11
12```text
13Usage: ./trace [USER@]HOST EVENTSET [EVENTSET...]
14
15Valid EVENTSETs: fsi, occ, sbefifo, timer, sched
16```
17
18To stop the trace output and disable the tracepoints, hit `Return`.
19
20For example, capturing the defined tracepoints for the `sched` event set:
21
22```sh
23$ ./trace root@my-bmc sched
24+ set -eou pipefail
25+ set -x
26+ EVENT_fsi='fsi fsi_master_gpio'
27+ EVENT_occ='occ hwmon_occ'
28+ EVENT_sbefifo=sbefifo
29+ EVENT_timer='timer/timer_start timer/timer_cancel timer/timer_expire_entry timer/timer_expire_exit'
30+ EVENT_sched='sched/sched_switch sched/sched_wakeup sched/sched_wakeup_new sched/sched_waking'
31+ trap on_exit EXIT
32+ CAT_PID=1867
33+ for elem in sched
34+ eval 'trace=\${EVENT_${elem}}'
35++ trace='${EVENT_sched}'
36++ eval echo '${EVENT_sched}'
37+++ echo sched/sched_switch sched/sched_wakeup sched/sched_wakeup_new sched/sched_waking
38+ for event in '$(eval echo ${trace})'
39+ echo 1
40+ for event in '$(eval echo ${trace})'
41+ echo 1
42+ for event in '$(eval echo ${trace})'
43+ echo 1
44+ for event in '$(eval echo ${trace})'
45+ echo 1
46+ echo 1
47+ read
48+ cat /sys/kernel/debug/tracing/per_cpu/cpu0/trace_pipe
49              sh-1866  [000] d.h. 201821.030000: sched_waking: comm=rngd pid=987 prio=120 target_cpu=000
50              sh-1866  [000] dnh. 201821.030000: sched_wakeup: comm=rngd pid=987 prio=120 target_cpu=000
51              sh-1866  [000] dn.. 201821.030000: sched_waking: comm=ksoftirqd/0 pid=6 prio=120 target_cpu=000
52              sh-1866  [000] dn.. 201821.030000: sched_wakeup: comm=ksoftirqd/0 pid=6 prio=120 target_cpu=000
53              sh-1866  [000] d... 201821.030000: sched_switch: prev_comm=sh prev_pid=1866 prev_prio=120 prev_state=R ==> next_comm=rngd next_pid=987 next_prio=120
54            rngd-987   [000] d... 201821.030000: sched_switch: prev_comm=rngd prev_pid=987 prev_prio=120 prev_state=S ==> next_comm=ksoftirqd/0 next_pid=6 next_prio=120
55     ksoftirqd/0-6     [000] d... 201821.030000: sched_switch: prev_comm=ksoftirqd/0 prev_pid=6 prev_prio=120 prev_state=S ==> next_comm=sh next_pid=1866 next_prio=120
56              sh-1866  [000] d.h. 201821.030000: sched_waking: comm=phosphor-hwmon- pid=1188 prio=120 target_cpu=000
57              sh-1866  [000] dnh. 201821.030000: sched_wakeup: comm=phosphor-hwmon- pid=1188 prio=120 target_cpu=000
58              sh-1866  [000] d... 201821.030000: sched_switch: prev_comm=sh prev_pid=1866 prev_prio=120 prev_state=R ==> next_comm=phosphor-hwmon- next_pid=1188 next_prio=120
59 phosphor-hwmon--1188  [000] d... 201821.030000: sched_switch: prev_comm=phosphor-hwmon- prev_pid=1188 prev_prio=120 prev_state=D ==> next_comm=sh next_pid=1866 next_prio=120
60...
61<RETURN>
62...
63+ kill 1867
64+ on_exit
65+ for elem in sched
66+ eval 'trace=\${EVENT_${elem}}'
67++ trace='${EVENT_sched}'
68++ eval echo '${EVENT_sched}'
69+++ echo sched/sched_switch sched/sched_wakeup sched/sched_wakeup_new sched/sched_waking
70+ for event in '$(eval echo ${trace})'
71+ echo 0
72+ for event in '$(eval echo ${trace})'
73+ echo 0
74+ for event in '$(eval echo ${trace})'
75+ echo 0
76+ for event in '$(eval echo ${trace})'
77+ echo 0
78+ echo 0
79+ on_exit
80+ rm -f obmc-fsi-trace.Rz15GL
81```
82