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