diff options
author | Michael Opdenacker <michael.opdenacker@bootlin.com> | 2021-04-15 17:58:45 +0200 |
---|---|---|
committer | Richard Purdie <richard.purdie@linuxfoundation.org> | 2021-04-23 16:39:03 +0100 |
commit | 773536c333248214f8f41eff698d8bfd3c687249 (patch) | |
tree | 526a86685e2d035455505f8ba45450bc70060e4b /documentation/profile-manual | |
parent | 21b42cc54f37fcbfdfa3ea69694b4f2003433d02 (diff) | |
download | poky-773536c333248214f8f41eff698d8bfd3c687249.tar.gz |
manuals: simplify code insertion
This replaces instances of ": ::" by "::", which
generates identical HTML output
(From yocto-docs rev: 1f410dfc7c16c09af612de659f8574ef6cff4636)
Signed-off-by: Michael Opdenacker <michael.opdenacker@bootlin.com>
Signed-off-by: Richard Purdie <richard.purdie@linuxfoundation.org>
Diffstat (limited to 'documentation/profile-manual')
-rw-r--r-- | documentation/profile-manual/intro.rst | 10 | ||||
-rw-r--r-- | documentation/profile-manual/usage.rst | 184 |
2 files changed, 97 insertions, 97 deletions
diff --git a/documentation/profile-manual/intro.rst b/documentation/profile-manual/intro.rst index 4e1008b05e..9c8fa3dbfa 100644 --- a/documentation/profile-manual/intro.rst +++ b/documentation/profile-manual/intro.rst | |||
@@ -39,12 +39,12 @@ an 'sdk' image e.g. :: | |||
39 | $ bitbake core-image-sato-sdk | 39 | $ bitbake core-image-sato-sdk |
40 | 40 | ||
41 | or alternatively by adding 'tools-profile' to the EXTRA_IMAGE_FEATURES line in | 41 | or alternatively by adding 'tools-profile' to the EXTRA_IMAGE_FEATURES line in |
42 | your local.conf: :: | 42 | your local.conf:: |
43 | 43 | ||
44 | EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile" | 44 | EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile" |
45 | 45 | ||
46 | If you use the 'tools-profile' method, you don't need to build an sdk image - | 46 | If you use the 'tools-profile' method, you don't need to build an sdk image - |
47 | the tracing and profiling tools will be included in non-sdk images as well e.g.: :: | 47 | the tracing and profiling tools will be included in non-sdk images as well e.g.:: |
48 | 48 | ||
49 | $ bitbake core-image-sato | 49 | $ bitbake core-image-sato |
50 | 50 | ||
@@ -55,7 +55,7 @@ the tracing and profiling tools will be included in non-sdk images as well e.g.: | |||
55 | 55 | ||
56 | You can prevent that by setting the | 56 | You can prevent that by setting the |
57 | :term:`INHIBIT_PACKAGE_STRIP` | 57 | :term:`INHIBIT_PACKAGE_STRIP` |
58 | variable to "1" in your ``local.conf`` when you build the image: :: | 58 | variable to "1" in your ``local.conf`` when you build the image:: |
59 | 59 | ||
60 | INHIBIT_PACKAGE_STRIP = "1" | 60 | INHIBIT_PACKAGE_STRIP = "1" |
61 | 61 | ||
@@ -65,11 +65,11 @@ If you've already built a stripped image, you can generate debug | |||
65 | packages (xxx-dbg) which you can manually install as needed. | 65 | packages (xxx-dbg) which you can manually install as needed. |
66 | 66 | ||
67 | To generate debug info for packages, you can add dbg-pkgs to | 67 | To generate debug info for packages, you can add dbg-pkgs to |
68 | EXTRA_IMAGE_FEATURES in local.conf. For example: :: | 68 | EXTRA_IMAGE_FEATURES in local.conf. For example:: |
69 | 69 | ||
70 | EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile dbg-pkgs" | 70 | EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile dbg-pkgs" |
71 | 71 | ||
72 | Additionally, in order to generate the right type of debuginfo, we also need to | 72 | Additionally, in order to generate the right type of debuginfo, we also need to |
73 | set :term:`PACKAGE_DEBUG_SPLIT_STYLE` in the ``local.conf`` file: :: | 73 | set :term:`PACKAGE_DEBUG_SPLIT_STYLE` in the ``local.conf`` file:: |
74 | 74 | ||
75 | PACKAGE_DEBUG_SPLIT_STYLE = 'debug-file-directory' | 75 | PACKAGE_DEBUG_SPLIT_STYLE = 'debug-file-directory' |
diff --git a/documentation/profile-manual/usage.rst b/documentation/profile-manual/usage.rst index c42f5b64b2..825290c3f8 100644 --- a/documentation/profile-manual/usage.rst +++ b/documentation/profile-manual/usage.rst | |||
@@ -48,7 +48,7 @@ For this section, we'll assume you've already performed the basic setup | |||
48 | outlined in the ":ref:`profile-manual/intro:General Setup`" section. | 48 | outlined in the ":ref:`profile-manual/intro:General Setup`" section. |
49 | 49 | ||
50 | In particular, you'll get the most mileage out of perf if you profile an | 50 | In particular, you'll get the most mileage out of perf if you profile an |
51 | image built with the following in your ``local.conf`` file: :: | 51 | image built with the following in your ``local.conf`` file:: |
52 | 52 | ||
53 | INHIBIT_PACKAGE_STRIP = "1" | 53 | INHIBIT_PACKAGE_STRIP = "1" |
54 | 54 | ||
@@ -62,7 +62,7 @@ Basic Perf Usage | |||
62 | 62 | ||
63 | The perf tool is pretty much self-documenting. To remind yourself of the | 63 | The perf tool is pretty much self-documenting. To remind yourself of the |
64 | available commands, simply type 'perf', which will show you basic usage | 64 | available commands, simply type 'perf', which will show you basic usage |
65 | along with the available perf subcommands: :: | 65 | along with the available perf subcommands:: |
66 | 66 | ||
67 | root@crownbay:~# perf | 67 | root@crownbay:~# perf |
68 | 68 | ||
@@ -110,7 +110,7 @@ applets in Yocto. :: | |||
110 | The quickest and easiest way to get some basic overall data about what's | 110 | The quickest and easiest way to get some basic overall data about what's |
111 | going on for a particular workload is to profile it using 'perf stat'. | 111 | going on for a particular workload is to profile it using 'perf stat'. |
112 | 'perf stat' basically profiles using a few default counters and displays | 112 | 'perf stat' basically profiles using a few default counters and displays |
113 | the summed counts at the end of the run: :: | 113 | the summed counts at the end of the run:: |
114 | 114 | ||
115 | root@crownbay:~# perf stat wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 115 | root@crownbay:~# perf stat wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
116 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) | 116 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) |
@@ -139,7 +139,7 @@ Also, note that 'perf stat' isn't restricted to a fixed set of counters | |||
139 | - basically any event listed in the output of 'perf list' can be tallied | 139 | - basically any event listed in the output of 'perf list' can be tallied |
140 | by 'perf stat'. For example, suppose we wanted to see a summary of all | 140 | by 'perf stat'. For example, suppose we wanted to see a summary of all |
141 | the events related to kernel memory allocation/freeing along with cache | 141 | the events related to kernel memory allocation/freeing along with cache |
142 | hits and misses: :: | 142 | hits and misses:: |
143 | 143 | ||
144 | root@crownbay:~# perf stat -e kmem:* -e cache-references -e cache-misses wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 144 | root@crownbay:~# perf stat -e kmem:* -e cache-references -e cache-misses wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
145 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) | 145 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) |
@@ -191,7 +191,7 @@ directory. :: | |||
191 | To see the results in a | 191 | To see the results in a |
192 | 'text-based UI' (tui), simply run 'perf report', which will read the | 192 | 'text-based UI' (tui), simply run 'perf report', which will read the |
193 | perf.data file in the current working directory and display the results | 193 | perf.data file in the current working directory and display the results |
194 | in an interactive UI: :: | 194 | in an interactive UI:: |
195 | 195 | ||
196 | root@crownbay:~# perf report | 196 | root@crownbay:~# perf report |
197 | 197 | ||
@@ -217,7 +217,7 @@ Before we do that, however, let's try running a different profile, one | |||
217 | which shows something a little more interesting. The only difference | 217 | which shows something a little more interesting. The only difference |
218 | between the new profile and the previous one is that we'll add the -g | 218 | between the new profile and the previous one is that we'll add the -g |
219 | option, which will record not just the address of a sampled function, | 219 | option, which will record not just the address of a sampled function, |
220 | but the entire callchain to the sampled function as well: :: | 220 | but the entire callchain to the sampled function as well:: |
221 | 221 | ||
222 | root@crownbay:~# perf record -g wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 222 | root@crownbay:~# perf record -g wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
223 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) | 223 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) |
@@ -293,7 +293,7 @@ busybox binary, which is actually stripped out by the Yocto build | |||
293 | system. | 293 | system. |
294 | 294 | ||
295 | One way around that is to put the following in your ``local.conf`` file | 295 | One way around that is to put the following in your ``local.conf`` file |
296 | when you build the image: :: | 296 | when you build the image:: |
297 | 297 | ||
298 | INHIBIT_PACKAGE_STRIP = "1" | 298 | INHIBIT_PACKAGE_STRIP = "1" |
299 | 299 | ||
@@ -302,26 +302,26 @@ what can we do to get perf to resolve the symbols? Basically we need to | |||
302 | install the debuginfo for the BusyBox package. | 302 | install the debuginfo for the BusyBox package. |
303 | 303 | ||
304 | To generate the debug info for the packages in the image, we can add | 304 | To generate the debug info for the packages in the image, we can add |
305 | ``dbg-pkgs`` to :term:`EXTRA_IMAGE_FEATURES` in ``local.conf``. For example: :: | 305 | ``dbg-pkgs`` to :term:`EXTRA_IMAGE_FEATURES` in ``local.conf``. For example:: |
306 | 306 | ||
307 | EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile dbg-pkgs" | 307 | EXTRA_IMAGE_FEATURES = "debug-tweaks tools-profile dbg-pkgs" |
308 | 308 | ||
309 | Additionally, in order to generate the type of debuginfo that perf | 309 | Additionally, in order to generate the type of debuginfo that perf |
310 | understands, we also need to set | 310 | understands, we also need to set |
311 | :term:`PACKAGE_DEBUG_SPLIT_STYLE` | 311 | :term:`PACKAGE_DEBUG_SPLIT_STYLE` |
312 | in the ``local.conf`` file: :: | 312 | in the ``local.conf`` file:: |
313 | 313 | ||
314 | PACKAGE_DEBUG_SPLIT_STYLE = 'debug-file-directory' | 314 | PACKAGE_DEBUG_SPLIT_STYLE = 'debug-file-directory' |
315 | 315 | ||
316 | Once we've done that, we can install the | 316 | Once we've done that, we can install the |
317 | debuginfo for BusyBox. The debug packages once built can be found in | 317 | debuginfo for BusyBox. The debug packages once built can be found in |
318 | ``build/tmp/deploy/rpm/*`` on the host system. Find the busybox-dbg-...rpm | 318 | ``build/tmp/deploy/rpm/*`` on the host system. Find the busybox-dbg-...rpm |
319 | file and copy it to the target. For example: :: | 319 | file and copy it to the target. For example:: |
320 | 320 | ||
321 | [trz@empanada core2]$ scp /home/trz/yocto/crownbay-tracing-dbg/build/tmp/deploy/rpm/core2_32/busybox-dbg-1.20.2-r2.core2_32.rpm root@192.168.1.31: | 321 | [trz@empanada core2]$ scp /home/trz/yocto/crownbay-tracing-dbg/build/tmp/deploy/rpm/core2_32/busybox-dbg-1.20.2-r2.core2_32.rpm root@192.168.1.31: |
322 | busybox-dbg-1.20.2-r2.core2_32.rpm 100% 1826KB 1.8MB/s 00:01 | 322 | busybox-dbg-1.20.2-r2.core2_32.rpm 100% 1826KB 1.8MB/s 00:01 |
323 | 323 | ||
324 | Now install the debug rpm on the target: :: | 324 | Now install the debug rpm on the target:: |
325 | 325 | ||
326 | root@crownbay:~# rpm -i busybox-dbg-1.20.2-r2.core2_32.rpm | 326 | root@crownbay:~# rpm -i busybox-dbg-1.20.2-r2.core2_32.rpm |
327 | 327 | ||
@@ -382,7 +382,7 @@ traditional tools can also make use of the expanded possibilities now | |||
382 | available to them, and in some cases have, as mentioned previously). | 382 | available to them, and in some cases have, as mentioned previously). |
383 | 383 | ||
384 | We can get a list of the available events that can be used to profile a | 384 | We can get a list of the available events that can be used to profile a |
385 | workload via 'perf list': :: | 385 | workload via 'perf list':: |
386 | 386 | ||
387 | root@crownbay:~# perf list | 387 | root@crownbay:~# perf list |
388 | 388 | ||
@@ -525,7 +525,7 @@ workload via 'perf list': :: | |||
525 | Only a subset of these would be of interest to us when looking at this | 525 | Only a subset of these would be of interest to us when looking at this |
526 | workload, so let's choose the most likely subsystems (identified by the | 526 | workload, so let's choose the most likely subsystems (identified by the |
527 | string before the colon in the Tracepoint events) and do a 'perf stat' | 527 | string before the colon in the Tracepoint events) and do a 'perf stat' |
528 | run using only those wildcarded subsystems: :: | 528 | run using only those wildcarded subsystems:: |
529 | 529 | ||
530 | root@crownbay:~# perf stat -e skb:* -e net:* -e napi:* -e sched:* -e workqueue:* -e irq:* -e syscalls:* wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 530 | root@crownbay:~# perf stat -e skb:* -e net:* -e napi:* -e sched:* -e workqueue:* -e irq:* -e syscalls:* wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
531 | Performance counter stats for 'wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2': | 531 | Performance counter stats for 'wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2': |
@@ -587,7 +587,7 @@ run using only those wildcarded subsystems: :: | |||
587 | 587 | ||
588 | 588 | ||
589 | Let's pick one of these tracepoints | 589 | Let's pick one of these tracepoints |
590 | and tell perf to do a profile using it as the sampling event: :: | 590 | and tell perf to do a profile using it as the sampling event:: |
591 | 591 | ||
592 | root@crownbay:~# perf record -g -e sched:sched_wakeup wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 592 | root@crownbay:~# perf record -g -e sched:sched_wakeup wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
593 | 593 | ||
@@ -644,14 +644,14 @@ individual steps that go into the higher-level behavior exposed by the | |||
644 | coarse-grained profiling data. | 644 | coarse-grained profiling data. |
645 | 645 | ||
646 | As a concrete example, we can trace all the events we think might be | 646 | As a concrete example, we can trace all the events we think might be |
647 | applicable to our workload: :: | 647 | applicable to our workload:: |
648 | 648 | ||
649 | root@crownbay:~# perf record -g -e skb:* -e net:* -e napi:* -e sched:sched_switch -e sched:sched_wakeup -e irq:* | 649 | root@crownbay:~# perf record -g -e skb:* -e net:* -e napi:* -e sched:sched_switch -e sched:sched_wakeup -e irq:* |
650 | -e syscalls:sys_enter_read -e syscalls:sys_exit_read -e syscalls:sys_enter_write -e syscalls:sys_exit_write | 650 | -e syscalls:sys_enter_read -e syscalls:sys_exit_read -e syscalls:sys_enter_write -e syscalls:sys_exit_write |
651 | wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 651 | wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
652 | 652 | ||
653 | We can look at the raw trace output using 'perf script' with no | 653 | We can look at the raw trace output using 'perf script' with no |
654 | arguments: :: | 654 | arguments:: |
655 | 655 | ||
656 | root@crownbay:~# perf script | 656 | root@crownbay:~# perf script |
657 | 657 | ||
@@ -735,7 +735,7 @@ two programming language bindings, one for Python and one for Perl. | |||
735 | 735 | ||
736 | Now that we have the trace data in perf.data, we can use 'perf script | 736 | Now that we have the trace data in perf.data, we can use 'perf script |
737 | -g' to generate a skeleton script with handlers for the read/write | 737 | -g' to generate a skeleton script with handlers for the read/write |
738 | entry/exit events we recorded: :: | 738 | entry/exit events we recorded:: |
739 | 739 | ||
740 | root@crownbay:~# perf script -g python | 740 | root@crownbay:~# perf script -g python |
741 | generated Python script: perf-script.py | 741 | generated Python script: perf-script.py |
@@ -755,7 +755,7 @@ with its parameters. For example: | |||
755 | print "skbaddr=%u, len=%u, name=%s\n" % (skbaddr, len, name), | 755 | print "skbaddr=%u, len=%u, name=%s\n" % (skbaddr, len, name), |
756 | 756 | ||
757 | We can run that script directly to print all of the events contained in the | 757 | We can run that script directly to print all of the events contained in the |
758 | perf.data file: :: | 758 | perf.data file:: |
759 | 759 | ||
760 | root@crownbay:~# perf script -s perf-script.py | 760 | root@crownbay:~# perf script -s perf-script.py |
761 | 761 | ||
@@ -833,7 +833,7 @@ result of all the per-event tallies. For that, we use the special | |||
833 | for event_name, count in counts.iteritems(): | 833 | for event_name, count in counts.iteritems(): |
834 | print "%-40s %10s\n" % (event_name, count) | 834 | print "%-40s %10s\n" % (event_name, count) |
835 | 835 | ||
836 | The end result is a summary of all the events recorded in the trace: :: | 836 | The end result is a summary of all the events recorded in the trace:: |
837 | 837 | ||
838 | skb__skb_copy_datagram_iovec 13148 | 838 | skb__skb_copy_datagram_iovec 13148 |
839 | irq__softirq_entry 4796 | 839 | irq__softirq_entry 4796 |
@@ -877,13 +877,13 @@ To do system-wide profiling or tracing, you typically use the -a flag to | |||
877 | 'perf record'. | 877 | 'perf record'. |
878 | 878 | ||
879 | To demonstrate this, open up one window and start the profile using the | 879 | To demonstrate this, open up one window and start the profile using the |
880 | -a flag (press Ctrl-C to stop tracing): :: | 880 | -a flag (press Ctrl-C to stop tracing):: |
881 | 881 | ||
882 | root@crownbay:~# perf record -g -a | 882 | root@crownbay:~# perf record -g -a |
883 | ^C[ perf record: Woken up 6 times to write data ] | 883 | ^C[ perf record: Woken up 6 times to write data ] |
884 | [ perf record: Captured and wrote 1.400 MB perf.data (~61172 samples) ] | 884 | [ perf record: Captured and wrote 1.400 MB perf.data (~61172 samples) ] |
885 | 885 | ||
886 | In another window, run the wget test: :: | 886 | In another window, run the wget test:: |
887 | 887 | ||
888 | root@crownbay:~# wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 | 888 | root@crownbay:~# wget http://downloads.yoctoproject.org/mirror/sources/linux-2.6.19.2.tar.bz2 |
889 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) | 889 | Connecting to downloads.yoctoproject.org (140.211.169.59:80) |
@@ -903,7 +903,7 @@ unresolvable symbols in the expanded Xorg callchain). | |||
903 | Note also that we have both kernel and userspace entries in the above | 903 | Note also that we have both kernel and userspace entries in the above |
904 | snapshot. We can also tell perf to focus on userspace but providing a | 904 | snapshot. We can also tell perf to focus on userspace but providing a |
905 | modifier, in this case 'u', to the 'cycles' hardware counter when we | 905 | modifier, in this case 'u', to the 'cycles' hardware counter when we |
906 | record a profile: :: | 906 | record a profile:: |
907 | 907 | ||
908 | root@crownbay:~# perf record -g -a -e cycles:u | 908 | root@crownbay:~# perf record -g -a -e cycles:u |
909 | ^C[ perf record: Woken up 2 times to write data ] | 909 | ^C[ perf record: Woken up 2 times to write data ] |
@@ -923,13 +923,13 @@ the entries associated with the libc-xxx.so DSO. | |||
923 | :align: center | 923 | :align: center |
924 | 924 | ||
925 | We can also use the system-wide -a switch to do system-wide tracing. | 925 | We can also use the system-wide -a switch to do system-wide tracing. |
926 | Here we'll trace a couple of scheduler events: :: | 926 | Here we'll trace a couple of scheduler events:: |
927 | 927 | ||
928 | root@crownbay:~# perf record -a -e sched:sched_switch -e sched:sched_wakeup | 928 | root@crownbay:~# perf record -a -e sched:sched_switch -e sched:sched_wakeup |
929 | ^C[ perf record: Woken up 38 times to write data ] | 929 | ^C[ perf record: Woken up 38 times to write data ] |
930 | [ perf record: Captured and wrote 9.780 MB perf.data (~427299 samples) ] | 930 | [ perf record: Captured and wrote 9.780 MB perf.data (~427299 samples) ] |
931 | 931 | ||
932 | We can look at the raw output using 'perf script' with no arguments: :: | 932 | We can look at the raw output using 'perf script' with no arguments:: |
933 | 933 | ||
934 | root@crownbay:~# perf script | 934 | root@crownbay:~# perf script |
935 | 935 | ||
@@ -952,7 +952,7 @@ do with what we're interested in, namely events that schedule 'perf' | |||
952 | itself in and out or that wake perf up. We can get rid of those by using | 952 | itself in and out or that wake perf up. We can get rid of those by using |
953 | the '--filter' option - for each event we specify using -e, we can add a | 953 | the '--filter' option - for each event we specify using -e, we can add a |
954 | --filter after that to filter out trace events that contain fields with | 954 | --filter after that to filter out trace events that contain fields with |
955 | specific values: :: | 955 | specific values:: |
956 | 956 | ||
957 | root@crownbay:~# perf record -a -e sched:sched_switch --filter 'next_comm != perf && prev_comm != perf' -e sched:sched_wakeup --filter 'comm != perf' | 957 | root@crownbay:~# perf record -a -e sched:sched_switch --filter 'next_comm != perf && prev_comm != perf' -e sched:sched_wakeup --filter 'comm != perf' |
958 | ^C[ perf record: Woken up 38 times to write data ] | 958 | ^C[ perf record: Woken up 38 times to write data ] |
@@ -1017,7 +1017,7 @@ perf isn't restricted to the fixed set of static tracepoints listed by | |||
1017 | 'perf list'. Users can also add their own 'dynamic' tracepoints anywhere | 1017 | 'perf list'. Users can also add their own 'dynamic' tracepoints anywhere |
1018 | in the kernel. For instance, suppose we want to define our own | 1018 | in the kernel. For instance, suppose we want to define our own |
1019 | tracepoint on do_fork(). We can do that using the 'perf probe' perf | 1019 | tracepoint on do_fork(). We can do that using the 'perf probe' perf |
1020 | subcommand: :: | 1020 | subcommand:: |
1021 | 1021 | ||
1022 | root@crownbay:~# perf probe do_fork | 1022 | root@crownbay:~# perf probe do_fork |
1023 | Added new event: | 1023 | Added new event: |
@@ -1031,7 +1031,7 @@ Adding a new tracepoint via | |||
1031 | 'perf probe' results in an event with all the expected files and format | 1031 | 'perf probe' results in an event with all the expected files and format |
1032 | in /sys/kernel/debug/tracing/events, just the same as for static | 1032 | in /sys/kernel/debug/tracing/events, just the same as for static |
1033 | tracepoints (as discussed in more detail in the trace events subsystem | 1033 | tracepoints (as discussed in more detail in the trace events subsystem |
1034 | section: :: | 1034 | section:: |
1035 | 1035 | ||
1036 | root@crownbay:/sys/kernel/debug/tracing/events/probe/do_fork# ls -al | 1036 | root@crownbay:/sys/kernel/debug/tracing/events/probe/do_fork# ls -al |
1037 | drwxr-xr-x 2 root root 0 Oct 28 11:42 . | 1037 | drwxr-xr-x 2 root root 0 Oct 28 11:42 . |
@@ -1056,7 +1056,7 @@ section: :: | |||
1056 | print fmt: "(%lx)", REC->__probe_ip | 1056 | print fmt: "(%lx)", REC->__probe_ip |
1057 | 1057 | ||
1058 | We can list all dynamic tracepoints currently in | 1058 | We can list all dynamic tracepoints currently in |
1059 | existence: :: | 1059 | existence:: |
1060 | 1060 | ||
1061 | root@crownbay:~# perf probe -l | 1061 | root@crownbay:~# perf probe -l |
1062 | probe:do_fork (on do_fork) | 1062 | probe:do_fork (on do_fork) |
@@ -1064,13 +1064,13 @@ existence: :: | |||
1064 | 1064 | ||
1065 | Let's record system-wide ('sleep 30' is a | 1065 | Let's record system-wide ('sleep 30' is a |
1066 | trick for recording system-wide but basically do nothing and then wake | 1066 | trick for recording system-wide but basically do nothing and then wake |
1067 | up after 30 seconds): :: | 1067 | up after 30 seconds):: |
1068 | 1068 | ||
1069 | root@crownbay:~# perf record -g -a -e probe:do_fork sleep 30 | 1069 | root@crownbay:~# perf record -g -a -e probe:do_fork sleep 30 |
1070 | [ perf record: Woken up 1 times to write data ] | 1070 | [ perf record: Woken up 1 times to write data ] |
1071 | [ perf record: Captured and wrote 0.087 MB perf.data (~3812 samples) ] | 1071 | [ perf record: Captured and wrote 0.087 MB perf.data (~3812 samples) ] |
1072 | 1072 | ||
1073 | Using 'perf script' we can see each do_fork event that fired: :: | 1073 | Using 'perf script' we can see each do_fork event that fired:: |
1074 | 1074 | ||
1075 | root@crownbay:~# perf script | 1075 | root@crownbay:~# perf script |
1076 | 1076 | ||
@@ -1163,7 +1163,7 @@ addressed by a Yocto bug: :yocto_bugs:`Bug 3388 - perf: enable man pages for | |||
1163 | basic 'help' functionality </show_bug.cgi?id=3388>`. | 1163 | basic 'help' functionality </show_bug.cgi?id=3388>`. |
1164 | 1164 | ||
1165 | The man pages in text form, along with some other files, such as a set | 1165 | The man pages in text form, along with some other files, such as a set |
1166 | of examples, can be found in the 'perf' directory of the kernel tree: :: | 1166 | of examples, can be found in the 'perf' directory of the kernel tree:: |
1167 | 1167 | ||
1168 | tools/perf/Documentation | 1168 | tools/perf/Documentation |
1169 | 1169 | ||
@@ -1197,7 +1197,7 @@ Basic ftrace usage | |||
1197 | 'ftrace' essentially refers to everything included in the /tracing | 1197 | 'ftrace' essentially refers to everything included in the /tracing |
1198 | directory of the mounted debugfs filesystem (Yocto follows the standard | 1198 | directory of the mounted debugfs filesystem (Yocto follows the standard |
1199 | convention and mounts it at /sys/kernel/debug). Here's a listing of all | 1199 | convention and mounts it at /sys/kernel/debug). Here's a listing of all |
1200 | the files found in /sys/kernel/debug/tracing on a Yocto system: :: | 1200 | the files found in /sys/kernel/debug/tracing on a Yocto system:: |
1201 | 1201 | ||
1202 | root@sugarbay:/sys/kernel/debug/tracing# ls | 1202 | root@sugarbay:/sys/kernel/debug/tracing# ls |
1203 | README kprobe_events trace | 1203 | README kprobe_events trace |
@@ -1222,12 +1222,12 @@ the ftrace documentation. | |||
1222 | 1222 | ||
1223 | We'll start by looking at some of the available built-in tracers. | 1223 | We'll start by looking at some of the available built-in tracers. |
1224 | 1224 | ||
1225 | cat'ing the 'available_tracers' file lists the set of available tracers: :: | 1225 | cat'ing the 'available_tracers' file lists the set of available tracers:: |
1226 | 1226 | ||
1227 | root@sugarbay:/sys/kernel/debug/tracing# cat available_tracers | 1227 | root@sugarbay:/sys/kernel/debug/tracing# cat available_tracers |
1228 | blk function_graph function nop | 1228 | blk function_graph function nop |
1229 | 1229 | ||
1230 | The 'current_tracer' file contains the tracer currently in effect: :: | 1230 | The 'current_tracer' file contains the tracer currently in effect:: |
1231 | 1231 | ||
1232 | root@sugarbay:/sys/kernel/debug/tracing# cat current_tracer | 1232 | root@sugarbay:/sys/kernel/debug/tracing# cat current_tracer |
1233 | nop | 1233 | nop |
@@ -1237,7 +1237,7 @@ The above listing of current_tracer shows that the | |||
1237 | there's actually no tracer currently in effect. | 1237 | there's actually no tracer currently in effect. |
1238 | 1238 | ||
1239 | echo'ing one of the available_tracers into current_tracer makes the | 1239 | echo'ing one of the available_tracers into current_tracer makes the |
1240 | specified tracer the current tracer: :: | 1240 | specified tracer the current tracer:: |
1241 | 1241 | ||
1242 | root@sugarbay:/sys/kernel/debug/tracing# echo function > current_tracer | 1242 | root@sugarbay:/sys/kernel/debug/tracing# echo function > current_tracer |
1243 | root@sugarbay:/sys/kernel/debug/tracing# cat current_tracer | 1243 | root@sugarbay:/sys/kernel/debug/tracing# cat current_tracer |
@@ -1247,7 +1247,7 @@ The above sets the current tracer to be the 'function tracer'. This tracer | |||
1247 | traces every function call in the kernel and makes it available as the | 1247 | traces every function call in the kernel and makes it available as the |
1248 | contents of the 'trace' file. Reading the 'trace' file lists the | 1248 | contents of the 'trace' file. Reading the 'trace' file lists the |
1249 | currently buffered function calls that have been traced by the function | 1249 | currently buffered function calls that have been traced by the function |
1250 | tracer: :: | 1250 | tracer:: |
1251 | 1251 | ||
1252 | root@sugarbay:/sys/kernel/debug/tracing# cat trace | less | 1252 | root@sugarbay:/sys/kernel/debug/tracing# cat trace | less |
1253 | 1253 | ||
@@ -1306,7 +1306,7 @@ great way to learn about how the kernel code works in a dynamic sense. | |||
1306 | 1306 | ||
1307 | It is a little more difficult to follow the call chains than it needs to | 1307 | It is a little more difficult to follow the call chains than it needs to |
1308 | be - luckily there's a variant of the function tracer that displays the | 1308 | be - luckily there's a variant of the function tracer that displays the |
1309 | callchains explicitly, called the 'function_graph' tracer: :: | 1309 | callchains explicitly, called the 'function_graph' tracer:: |
1310 | 1310 | ||
1311 | root@sugarbay:/sys/kernel/debug/tracing# echo function_graph > current_tracer | 1311 | root@sugarbay:/sys/kernel/debug/tracing# echo function_graph > current_tracer |
1312 | root@sugarbay:/sys/kernel/debug/tracing# cat trace | less | 1312 | root@sugarbay:/sys/kernel/debug/tracing# cat trace | less |
@@ -1442,7 +1442,7 @@ One especially important directory contained within the | |||
1442 | /sys/kernel/debug/tracing directory is the 'events' subdirectory, which | 1442 | /sys/kernel/debug/tracing directory is the 'events' subdirectory, which |
1443 | contains representations of every tracepoint in the system. Listing out | 1443 | contains representations of every tracepoint in the system. Listing out |
1444 | the contents of the 'events' subdirectory, we see mainly another set of | 1444 | the contents of the 'events' subdirectory, we see mainly another set of |
1445 | subdirectories: :: | 1445 | subdirectories:: |
1446 | 1446 | ||
1447 | root@sugarbay:/sys/kernel/debug/tracing# cd events | 1447 | root@sugarbay:/sys/kernel/debug/tracing# cd events |
1448 | root@sugarbay:/sys/kernel/debug/tracing/events# ls -al | 1448 | root@sugarbay:/sys/kernel/debug/tracing/events# ls -al |
@@ -1491,7 +1491,7 @@ subdirectories: :: | |||
1491 | Each one of these subdirectories | 1491 | Each one of these subdirectories |
1492 | corresponds to a 'subsystem' and contains yet again more subdirectories, | 1492 | corresponds to a 'subsystem' and contains yet again more subdirectories, |
1493 | each one of those finally corresponding to a tracepoint. For example, | 1493 | each one of those finally corresponding to a tracepoint. For example, |
1494 | here are the contents of the 'kmem' subsystem: :: | 1494 | here are the contents of the 'kmem' subsystem:: |
1495 | 1495 | ||
1496 | root@sugarbay:/sys/kernel/debug/tracing/events# cd kmem | 1496 | root@sugarbay:/sys/kernel/debug/tracing/events# cd kmem |
1497 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem# ls -al | 1497 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem# ls -al |
@@ -1513,7 +1513,7 @@ here are the contents of the 'kmem' subsystem: :: | |||
1513 | drwxr-xr-x 2 root root 0 Nov 14 23:19 mm_page_pcpu_drain | 1513 | drwxr-xr-x 2 root root 0 Nov 14 23:19 mm_page_pcpu_drain |
1514 | 1514 | ||
1515 | Let's see what's inside the subdirectory for a | 1515 | Let's see what's inside the subdirectory for a |
1516 | specific tracepoint, in this case the one for kmalloc: :: | 1516 | specific tracepoint, in this case the one for kmalloc:: |
1517 | 1517 | ||
1518 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem# cd kmalloc | 1518 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem# cd kmalloc |
1519 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# ls -al | 1519 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# ls -al |
@@ -1529,7 +1529,7 @@ tracepoint describes the event in memory, which is used by the various | |||
1529 | tracing tools that now make use of these tracepoint to parse the event | 1529 | tracing tools that now make use of these tracepoint to parse the event |
1530 | and make sense of it, along with a 'print fmt' field that allows tools | 1530 | and make sense of it, along with a 'print fmt' field that allows tools |
1531 | like ftrace to display the event as text. Here's what the format of the | 1531 | like ftrace to display the event as text. Here's what the format of the |
1532 | kmalloc event looks like: :: | 1532 | kmalloc event looks like:: |
1533 | 1533 | ||
1534 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# cat format | 1534 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# cat format |
1535 | name: kmalloc | 1535 | name: kmalloc |
@@ -1568,20 +1568,20 @@ The 'enable' file | |||
1568 | in the tracepoint directory is what allows the user (or tools such as | 1568 | in the tracepoint directory is what allows the user (or tools such as |
1569 | trace-cmd) to actually turn the tracepoint on and off. When enabled, the | 1569 | trace-cmd) to actually turn the tracepoint on and off. When enabled, the |
1570 | corresponding tracepoint will start appearing in the ftrace 'trace' file | 1570 | corresponding tracepoint will start appearing in the ftrace 'trace' file |
1571 | described previously. For example, this turns on the kmalloc tracepoint: :: | 1571 | described previously. For example, this turns on the kmalloc tracepoint:: |
1572 | 1572 | ||
1573 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# echo 1 > enable | 1573 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# echo 1 > enable |
1574 | 1574 | ||
1575 | At the moment, we're not interested in the function tracer or | 1575 | At the moment, we're not interested in the function tracer or |
1576 | some other tracer that might be in effect, so we first turn it off, but | 1576 | some other tracer that might be in effect, so we first turn it off, but |
1577 | if we do that, we still need to turn tracing on in order to see the | 1577 | if we do that, we still need to turn tracing on in order to see the |
1578 | events in the output buffer: :: | 1578 | events in the output buffer:: |
1579 | 1579 | ||
1580 | root@sugarbay:/sys/kernel/debug/tracing# echo nop > current_tracer | 1580 | root@sugarbay:/sys/kernel/debug/tracing# echo nop > current_tracer |
1581 | root@sugarbay:/sys/kernel/debug/tracing# echo 1 > tracing_on | 1581 | root@sugarbay:/sys/kernel/debug/tracing# echo 1 > tracing_on |
1582 | 1582 | ||
1583 | Now, if we look at the 'trace' file, we see nothing | 1583 | Now, if we look at the 'trace' file, we see nothing |
1584 | but the kmalloc events we just turned on: :: | 1584 | but the kmalloc events we just turned on:: |
1585 | 1585 | ||
1586 | root@sugarbay:/sys/kernel/debug/tracing# cat trace | less | 1586 | root@sugarbay:/sys/kernel/debug/tracing# cat trace | less |
1587 | # tracer: nop | 1587 | # tracer: nop |
@@ -1627,7 +1627,7 @@ but the kmalloc events we just turned on: :: | |||
1627 | <idle>-0 [000] ..s3 18156.400660: kmalloc: call_site=ffffffff81619b36 ptr=ffff88006d554800 bytes_req=512 bytes_alloc=512 gfp_flags=GFP_ATOMIC | 1627 | <idle>-0 [000] ..s3 18156.400660: kmalloc: call_site=ffffffff81619b36 ptr=ffff88006d554800 bytes_req=512 bytes_alloc=512 gfp_flags=GFP_ATOMIC |
1628 | matchbox-termin-1361 [001] ...1 18156.552800: kmalloc: call_site=ffffffff81614050 ptr=ffff88006db34800 bytes_req=576 bytes_alloc=1024 gfp_flags=GFP_KERNEL|GFP_REPEAT | 1628 | matchbox-termin-1361 [001] ...1 18156.552800: kmalloc: call_site=ffffffff81614050 ptr=ffff88006db34800 bytes_req=576 bytes_alloc=1024 gfp_flags=GFP_KERNEL|GFP_REPEAT |
1629 | 1629 | ||
1630 | To again disable the kmalloc event, we need to send 0 to the enable file: :: | 1630 | To again disable the kmalloc event, we need to send 0 to the enable file:: |
1631 | 1631 | ||
1632 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# echo 0 > enable | 1632 | root@sugarbay:/sys/kernel/debug/tracing/events/kmem/kmalloc# echo 0 > enable |
1633 | 1633 | ||
@@ -1669,12 +1669,12 @@ a per-CPU graphical display. It directly uses 'trace-cmd' as the | |||
1669 | plumbing that accomplishes all that underneath the covers (and actually | 1669 | plumbing that accomplishes all that underneath the covers (and actually |
1670 | displays the trace-cmd command it uses, as we'll see). | 1670 | displays the trace-cmd command it uses, as we'll see). |
1671 | 1671 | ||
1672 | To start a trace using kernelshark, first start kernelshark: :: | 1672 | To start a trace using kernelshark, first start kernelshark:: |
1673 | 1673 | ||
1674 | root@sugarbay:~# kernelshark | 1674 | root@sugarbay:~# kernelshark |
1675 | 1675 | ||
1676 | Then bring up the 'Capture' dialog by | 1676 | Then bring up the 'Capture' dialog by |
1677 | choosing from the kernelshark menu: :: | 1677 | choosing from the kernelshark menu:: |
1678 | 1678 | ||
1679 | Capture | Record | 1679 | Capture | Record |
1680 | 1680 | ||
@@ -1724,12 +1724,12 @@ ftrace Documentation | |||
1724 | -------------------- | 1724 | -------------------- |
1725 | 1725 | ||
1726 | The documentation for ftrace can be found in the kernel Documentation | 1726 | The documentation for ftrace can be found in the kernel Documentation |
1727 | directory: :: | 1727 | directory:: |
1728 | 1728 | ||
1729 | Documentation/trace/ftrace.txt | 1729 | Documentation/trace/ftrace.txt |
1730 | 1730 | ||
1731 | The documentation for the trace event subsystem can also be found in the kernel | 1731 | The documentation for the trace event subsystem can also be found in the kernel |
1732 | Documentation directory: :: | 1732 | Documentation directory:: |
1733 | 1733 | ||
1734 | Documentation/trace/events.txt | 1734 | Documentation/trace/events.txt |
1735 | 1735 | ||
@@ -1784,7 +1784,7 @@ which it extracts from the open syscall's argstr. | |||
1784 | Normally, to execute this | 1784 | Normally, to execute this |
1785 | probe, you'd simply install systemtap on the system you want to probe, | 1785 | probe, you'd simply install systemtap on the system you want to probe, |
1786 | and directly run the probe on that system e.g. assuming the name of the | 1786 | and directly run the probe on that system e.g. assuming the name of the |
1787 | file containing the above text is trace_open.stp: :: | 1787 | file containing the above text is trace_open.stp:: |
1788 | 1788 | ||
1789 | # stap trace_open.stp | 1789 | # stap trace_open.stp |
1790 | 1790 | ||
@@ -1825,7 +1825,7 @@ target, with arguments if necessary. | |||
1825 | In order to do this from a remote host, however, you need to have access | 1825 | In order to do this from a remote host, however, you need to have access |
1826 | to the build for the image you booted. The 'crosstap' script provides | 1826 | to the build for the image you booted. The 'crosstap' script provides |
1827 | details on how to do this if you run the script on the host without | 1827 | details on how to do this if you run the script on the host without |
1828 | having done a build: :: | 1828 | having done a build:: |
1829 | 1829 | ||
1830 | $ crosstap root@192.168.1.88 trace_open.stp | 1830 | $ crosstap root@192.168.1.88 trace_open.stp |
1831 | 1831 | ||
@@ -1885,7 +1885,7 @@ Running a Script on a Target | |||
1885 | ---------------------------- | 1885 | ---------------------------- |
1886 | 1886 | ||
1887 | Once you've done that, you should be able to run a systemtap script on | 1887 | Once you've done that, you should be able to run a systemtap script on |
1888 | the target: :: | 1888 | the target:: |
1889 | 1889 | ||
1890 | $ cd /path/to/yocto | 1890 | $ cd /path/to/yocto |
1891 | $ source oe-init-build-env | 1891 | $ source oe-init-build-env |
@@ -1903,17 +1903,17 @@ the target: :: | |||
1903 | You can also run generated QEMU images with a command like 'runqemu qemux86-64' | 1903 | You can also run generated QEMU images with a command like 'runqemu qemux86-64' |
1904 | 1904 | ||
1905 | Once you've done that, you can cd to whatever | 1905 | Once you've done that, you can cd to whatever |
1906 | directory contains your scripts and use 'crosstap' to run the script: :: | 1906 | directory contains your scripts and use 'crosstap' to run the script:: |
1907 | 1907 | ||
1908 | $ cd /path/to/my/systemap/script | 1908 | $ cd /path/to/my/systemap/script |
1909 | $ crosstap root@192.168.7.2 trace_open.stp | 1909 | $ crosstap root@192.168.7.2 trace_open.stp |
1910 | 1910 | ||
1911 | If you get an error connecting to the target e.g.: :: | 1911 | If you get an error connecting to the target e.g.:: |
1912 | 1912 | ||
1913 | $ crosstap root@192.168.7.2 trace_open.stp | 1913 | $ crosstap root@192.168.7.2 trace_open.stp |
1914 | error establishing ssh connection on remote 'root@192.168.7.2' | 1914 | error establishing ssh connection on remote 'root@192.168.7.2' |
1915 | 1915 | ||
1916 | Try ssh'ing to the target and see what happens: :: | 1916 | Try ssh'ing to the target and see what happens:: |
1917 | 1917 | ||
1918 | $ ssh root@192.168.7.2 | 1918 | $ ssh root@192.168.7.2 |
1919 | 1919 | ||
@@ -2038,7 +2038,7 @@ tracing. | |||
2038 | Collecting and viewing a trace on the target (inside a shell) | 2038 | Collecting and viewing a trace on the target (inside a shell) |
2039 | ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ | 2039 | ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ |
2040 | 2040 | ||
2041 | First, from the host, ssh to the target: :: | 2041 | First, from the host, ssh to the target:: |
2042 | 2042 | ||
2043 | $ ssh -l root 192.168.1.47 | 2043 | $ ssh -l root 192.168.1.47 |
2044 | The authenticity of host '192.168.1.47 (192.168.1.47)' can't be established. | 2044 | The authenticity of host '192.168.1.47 (192.168.1.47)' can't be established. |
@@ -2047,30 +2047,30 @@ First, from the host, ssh to the target: :: | |||
2047 | Warning: Permanently added '192.168.1.47' (RSA) to the list of known hosts. | 2047 | Warning: Permanently added '192.168.1.47' (RSA) to the list of known hosts. |
2048 | root@192.168.1.47's password: | 2048 | root@192.168.1.47's password: |
2049 | 2049 | ||
2050 | Once on the target, use these steps to create a trace: :: | 2050 | Once on the target, use these steps to create a trace:: |
2051 | 2051 | ||
2052 | root@crownbay:~# lttng create | 2052 | root@crownbay:~# lttng create |
2053 | Spawning a session daemon | 2053 | Spawning a session daemon |
2054 | Session auto-20121015-232120 created. | 2054 | Session auto-20121015-232120 created. |
2055 | Traces will be written in /home/root/lttng-traces/auto-20121015-232120 | 2055 | Traces will be written in /home/root/lttng-traces/auto-20121015-232120 |
2056 | 2056 | ||
2057 | Enable the events you want to trace (in this case all kernel events): :: | 2057 | Enable the events you want to trace (in this case all kernel events):: |
2058 | 2058 | ||
2059 | root@crownbay:~# lttng enable-event --kernel --all | 2059 | root@crownbay:~# lttng enable-event --kernel --all |
2060 | All kernel events are enabled in channel channel0 | 2060 | All kernel events are enabled in channel channel0 |
2061 | 2061 | ||
2062 | Start the trace: :: | 2062 | Start the trace:: |
2063 | 2063 | ||
2064 | root@crownbay:~# lttng start | 2064 | root@crownbay:~# lttng start |
2065 | Tracing started for session auto-20121015-232120 | 2065 | Tracing started for session auto-20121015-232120 |
2066 | 2066 | ||
2067 | And then stop the trace after awhile or after running a particular workload that | 2067 | And then stop the trace after awhile or after running a particular workload that |
2068 | you want to trace: :: | 2068 | you want to trace:: |
2069 | 2069 | ||
2070 | root@crownbay:~# lttng stop | 2070 | root@crownbay:~# lttng stop |
2071 | Tracing stopped for session auto-20121015-232120 | 2071 | Tracing stopped for session auto-20121015-232120 |
2072 | 2072 | ||
2073 | You can now view the trace in text form on the target: :: | 2073 | You can now view the trace in text form on the target:: |
2074 | 2074 | ||
2075 | root@crownbay:~# lttng view | 2075 | root@crownbay:~# lttng view |
2076 | [23:21:56.989270399] (+?.?????????) sys_geteuid: { 1 }, { } | 2076 | [23:21:56.989270399] (+?.?????????) sys_geteuid: { 1 }, { } |
@@ -2116,14 +2116,14 @@ You can now view the trace in text form on the target: :: | |||
2116 | 2116 | ||
2117 | You can now safely destroy the trace | 2117 | You can now safely destroy the trace |
2118 | session (note that this doesn't delete the trace - it's still there in | 2118 | session (note that this doesn't delete the trace - it's still there in |
2119 | ~/lttng-traces): :: | 2119 | ~/lttng-traces):: |
2120 | 2120 | ||
2121 | root@crownbay:~# lttng destroy | 2121 | root@crownbay:~# lttng destroy |
2122 | Session auto-20121015-232120 destroyed at /home/root | 2122 | Session auto-20121015-232120 destroyed at /home/root |
2123 | 2123 | ||
2124 | Note that the trace is saved in a directory of the same name as returned by | 2124 | Note that the trace is saved in a directory of the same name as returned by |
2125 | 'lttng create', under the ~/lttng-traces directory (note that you can change this by | 2125 | 'lttng create', under the ~/lttng-traces directory (note that you can change this by |
2126 | supplying your own name to 'lttng create'): :: | 2126 | supplying your own name to 'lttng create'):: |
2127 | 2127 | ||
2128 | root@crownbay:~# ls -al ~/lttng-traces | 2128 | root@crownbay:~# ls -al ~/lttng-traces |
2129 | drwxrwx--- 3 root root 1024 Oct 15 23:21 . | 2129 | drwxrwx--- 3 root root 1024 Oct 15 23:21 . |
@@ -2139,18 +2139,18 @@ generated by the lttng-ust build. | |||
2139 | 2139 | ||
2140 | The 'hello' test program isn't installed on the rootfs by the lttng-ust | 2140 | The 'hello' test program isn't installed on the rootfs by the lttng-ust |
2141 | build, so we need to copy it over manually. First cd into the build | 2141 | build, so we need to copy it over manually. First cd into the build |
2142 | directory that contains the hello executable: :: | 2142 | directory that contains the hello executable:: |
2143 | 2143 | ||
2144 | $ cd build/tmp/work/core2_32-poky-linux/lttng-ust/2.0.5-r0/git/tests/hello/.libs | 2144 | $ cd build/tmp/work/core2_32-poky-linux/lttng-ust/2.0.5-r0/git/tests/hello/.libs |
2145 | 2145 | ||
2146 | Copy that over to the target machine: :: | 2146 | Copy that over to the target machine:: |
2147 | 2147 | ||
2148 | $ scp hello root@192.168.1.20: | 2148 | $ scp hello root@192.168.1.20: |
2149 | 2149 | ||
2150 | You now have the instrumented lttng 'hello world' test program on the | 2150 | You now have the instrumented lttng 'hello world' test program on the |
2151 | target, ready to test. | 2151 | target, ready to test. |
2152 | 2152 | ||
2153 | First, from the host, ssh to the target: :: | 2153 | First, from the host, ssh to the target:: |
2154 | 2154 | ||
2155 | $ ssh -l root 192.168.1.47 | 2155 | $ ssh -l root 192.168.1.47 |
2156 | The authenticity of host '192.168.1.47 (192.168.1.47)' can't be established. | 2156 | The authenticity of host '192.168.1.47 (192.168.1.47)' can't be established. |
@@ -2159,35 +2159,35 @@ First, from the host, ssh to the target: :: | |||
2159 | Warning: Permanently added '192.168.1.47' (RSA) to the list of known hosts. | 2159 | Warning: Permanently added '192.168.1.47' (RSA) to the list of known hosts. |
2160 | root@192.168.1.47's password: | 2160 | root@192.168.1.47's password: |
2161 | 2161 | ||
2162 | Once on the target, use these steps to create a trace: :: | 2162 | Once on the target, use these steps to create a trace:: |
2163 | 2163 | ||
2164 | root@crownbay:~# lttng create | 2164 | root@crownbay:~# lttng create |
2165 | Session auto-20190303-021943 created. | 2165 | Session auto-20190303-021943 created. |
2166 | Traces will be written in /home/root/lttng-traces/auto-20190303-021943 | 2166 | Traces will be written in /home/root/lttng-traces/auto-20190303-021943 |
2167 | 2167 | ||
2168 | Enable the events you want to trace (in this case all userspace events): :: | 2168 | Enable the events you want to trace (in this case all userspace events):: |
2169 | 2169 | ||
2170 | root@crownbay:~# lttng enable-event --userspace --all | 2170 | root@crownbay:~# lttng enable-event --userspace --all |
2171 | All UST events are enabled in channel channel0 | 2171 | All UST events are enabled in channel channel0 |
2172 | 2172 | ||
2173 | Start the trace: :: | 2173 | Start the trace:: |
2174 | 2174 | ||
2175 | root@crownbay:~# lttng start | 2175 | root@crownbay:~# lttng start |
2176 | Tracing started for session auto-20190303-021943 | 2176 | Tracing started for session auto-20190303-021943 |
2177 | 2177 | ||
2178 | Run the instrumented hello world program: :: | 2178 | Run the instrumented hello world program:: |
2179 | 2179 | ||
2180 | root@crownbay:~# ./hello | 2180 | root@crownbay:~# ./hello |
2181 | Hello, World! | 2181 | Hello, World! |
2182 | Tracing... done. | 2182 | Tracing... done. |
2183 | 2183 | ||
2184 | And then stop the trace after awhile or after running a particular workload | 2184 | And then stop the trace after awhile or after running a particular workload |
2185 | that you want to trace: :: | 2185 | that you want to trace:: |
2186 | 2186 | ||
2187 | root@crownbay:~# lttng stop | 2187 | root@crownbay:~# lttng stop |
2188 | Tracing stopped for session auto-20190303-021943 | 2188 | Tracing stopped for session auto-20190303-021943 |
2189 | 2189 | ||
2190 | You can now view the trace in text form on the target: :: | 2190 | You can now view the trace in text form on the target:: |
2191 | 2191 | ||
2192 | root@crownbay:~# lttng view | 2192 | root@crownbay:~# lttng view |
2193 | [02:31:14.906146544] (+?.?????????) hello:1424 ust_tests_hello:tptest: { cpu_id = 1 }, { intfield = 0, intfield2 = 0x0, longfield = 0, netintfield = 0, netintfieldhex = 0x0, arrfield1 = [ [0] = 1, [1] = 2, [2] = 3 ], arrfield2 = "test", _seqfield1_length = 4, seqfield1 = [ [0] = 116, [1] = 101, [2] = 115, [3] = 116 ], _seqfield2_length = 4, seqfield2 = "test", stringfield = "test", floatfield = 2222, doublefield = 2, boolfield = 1 } | 2193 | [02:31:14.906146544] (+?.?????????) hello:1424 ust_tests_hello:tptest: { cpu_id = 1 }, { intfield = 0, intfield2 = 0x0, longfield = 0, netintfield = 0, netintfieldhex = 0x0, arrfield1 = [ [0] = 1, [1] = 2, [2] = 3 ], arrfield2 = "test", _seqfield1_length = 4, seqfield1 = [ [0] = 116, [1] = 101, [2] = 115, [3] = 116 ], _seqfield2_length = 4, seqfield2 = "test", stringfield = "test", floatfield = 2222, doublefield = 2, boolfield = 1 } |
@@ -2199,7 +2199,7 @@ You can now view the trace in text form on the target: :: | |||
2199 | . | 2199 | . |
2200 | 2200 | ||
2201 | You can now safely destroy the trace session (note that this doesn't delete the | 2201 | You can now safely destroy the trace session (note that this doesn't delete the |
2202 | trace - it's still there in ~/lttng-traces): :: | 2202 | trace - it's still there in ~/lttng-traces):: |
2203 | 2203 | ||
2204 | root@crownbay:~# lttng destroy | 2204 | root@crownbay:~# lttng destroy |
2205 | Session auto-20190303-021943 destroyed at /home/root | 2205 | Session auto-20190303-021943 destroyed at /home/root |
@@ -2244,7 +2244,7 @@ Basic blktrace Usage | |||
2244 | -------------------- | 2244 | -------------------- |
2245 | 2245 | ||
2246 | To record a trace, simply run the 'blktrace' command, giving it the name | 2246 | To record a trace, simply run the 'blktrace' command, giving it the name |
2247 | of the block device you want to trace activity on: :: | 2247 | of the block device you want to trace activity on:: |
2248 | 2248 | ||
2249 | root@crownbay:~# blktrace /dev/sdc | 2249 | root@crownbay:~# blktrace /dev/sdc |
2250 | 2250 | ||
@@ -2265,7 +2265,7 @@ dumps them to userspace for blkparse to merge and sort later). :: | |||
2265 | Total: 8660 events (dropped 0), 406 KiB data | 2265 | Total: 8660 events (dropped 0), 406 KiB data |
2266 | 2266 | ||
2267 | If you examine the files saved to disk, you see multiple files, one per CPU and | 2267 | If you examine the files saved to disk, you see multiple files, one per CPU and |
2268 | with the device name as the first part of the filename: :: | 2268 | with the device name as the first part of the filename:: |
2269 | 2269 | ||
2270 | root@crownbay:~# ls -al | 2270 | root@crownbay:~# ls -al |
2271 | drwxr-xr-x 6 root root 1024 Oct 27 22:39 . | 2271 | drwxr-xr-x 6 root root 1024 Oct 27 22:39 . |
@@ -2275,7 +2275,7 @@ with the device name as the first part of the filename: :: | |||
2275 | 2275 | ||
2276 | To view the trace events, simply invoke 'blkparse' in the directory | 2276 | To view the trace events, simply invoke 'blkparse' in the directory |
2277 | containing the trace files, giving it the device name that forms the | 2277 | containing the trace files, giving it the device name that forms the |
2278 | first part of the filenames: :: | 2278 | first part of the filenames:: |
2279 | 2279 | ||
2280 | root@crownbay:~# blkparse sdc | 2280 | root@crownbay:~# blkparse sdc |
2281 | 2281 | ||
@@ -2373,7 +2373,7 @@ Live Mode | |||
2373 | 2373 | ||
2374 | blktrace and blkparse are designed from the ground up to be able to | 2374 | blktrace and blkparse are designed from the ground up to be able to |
2375 | operate together in a 'pipe mode' where the stdout of blktrace can be | 2375 | operate together in a 'pipe mode' where the stdout of blktrace can be |
2376 | fed directly into the stdin of blkparse: :: | 2376 | fed directly into the stdin of blkparse:: |
2377 | 2377 | ||
2378 | root@crownbay:~# blktrace /dev/sdc -o - | blkparse -i - | 2378 | root@crownbay:~# blktrace /dev/sdc -o - | blkparse -i - |
2379 | 2379 | ||
@@ -2386,7 +2386,7 @@ identify and capture conditions of interest. | |||
2386 | 2386 | ||
2387 | There's actually another blktrace command that implements the above | 2387 | There's actually another blktrace command that implements the above |
2388 | pipeline as a single command, so the user doesn't have to bother typing | 2388 | pipeline as a single command, so the user doesn't have to bother typing |
2389 | in the above command sequence: :: | 2389 | in the above command sequence:: |
2390 | 2390 | ||
2391 | root@crownbay:~# btrace /dev/sdc | 2391 | root@crownbay:~# btrace /dev/sdc |
2392 | 2392 | ||
@@ -2401,19 +2401,19 @@ the traced device at all by providing native support for sending all | |||
2401 | trace data over the network. | 2401 | trace data over the network. |
2402 | 2402 | ||
2403 | To have blktrace operate in this mode, start blktrace on the target | 2403 | To have blktrace operate in this mode, start blktrace on the target |
2404 | system being traced with the -l option, along with the device to trace: :: | 2404 | system being traced with the -l option, along with the device to trace:: |
2405 | 2405 | ||
2406 | root@crownbay:~# blktrace -l /dev/sdc | 2406 | root@crownbay:~# blktrace -l /dev/sdc |
2407 | server: waiting for connections... | 2407 | server: waiting for connections... |
2408 | 2408 | ||
2409 | On the host system, use the -h option to connect to the target system, | 2409 | On the host system, use the -h option to connect to the target system, |
2410 | also passing it the device to trace: :: | 2410 | also passing it the device to trace:: |
2411 | 2411 | ||
2412 | $ blktrace -d /dev/sdc -h 192.168.1.43 | 2412 | $ blktrace -d /dev/sdc -h 192.168.1.43 |
2413 | blktrace: connecting to 192.168.1.43 | 2413 | blktrace: connecting to 192.168.1.43 |
2414 | blktrace: connected! | 2414 | blktrace: connected! |
2415 | 2415 | ||
2416 | On the target system, you should see this: :: | 2416 | On the target system, you should see this:: |
2417 | 2417 | ||
2418 | server: connection from 192.168.1.43 | 2418 | server: connection from 192.168.1.43 |
2419 | 2419 | ||
@@ -2424,7 +2424,7 @@ In another shell, execute a workload you want to trace. :: | |||
2424 | linux-2.6.19.2.tar.b 100% \|*******************************\| 41727k 0:00:00 ETA | 2424 | linux-2.6.19.2.tar.b 100% \|*******************************\| 41727k 0:00:00 ETA |
2425 | 2425 | ||
2426 | When it's done, do a Ctrl-C on the host system to stop the | 2426 | When it's done, do a Ctrl-C on the host system to stop the |
2427 | trace: :: | 2427 | trace:: |
2428 | 2428 | ||
2429 | ^C=== sdc === | 2429 | ^C=== sdc === |
2430 | CPU 0: 7691 events, 361 KiB data | 2430 | CPU 0: 7691 events, 361 KiB data |
@@ -2432,7 +2432,7 @@ trace: :: | |||
2432 | Total: 11800 events (dropped 0), 554 KiB data | 2432 | Total: 11800 events (dropped 0), 554 KiB data |
2433 | 2433 | ||
2434 | On the target system, you should also see a trace summary for the trace | 2434 | On the target system, you should also see a trace summary for the trace |
2435 | just ended: :: | 2435 | just ended:: |
2436 | 2436 | ||
2437 | server: end of run for 192.168.1.43:sdc | 2437 | server: end of run for 192.168.1.43:sdc |
2438 | === sdc === | 2438 | === sdc === |
@@ -2441,20 +2441,20 @@ just ended: :: | |||
2441 | Total: 11800 events (dropped 0), 554 KiB data | 2441 | Total: 11800 events (dropped 0), 554 KiB data |
2442 | 2442 | ||
2443 | The blktrace instance on the host will | 2443 | The blktrace instance on the host will |
2444 | save the target output inside a hostname-timestamp directory: :: | 2444 | save the target output inside a hostname-timestamp directory:: |
2445 | 2445 | ||
2446 | $ ls -al | 2446 | $ ls -al |
2447 | drwxr-xr-x 10 root root 1024 Oct 28 02:40 . | 2447 | drwxr-xr-x 10 root root 1024 Oct 28 02:40 . |
2448 | drwxr-sr-x 4 root root 1024 Oct 26 18:24 .. | 2448 | drwxr-sr-x 4 root root 1024 Oct 26 18:24 .. |
2449 | drwxr-xr-x 2 root root 1024 Oct 28 02:40 192.168.1.43-2012-10-28-02:40:56 | 2449 | drwxr-xr-x 2 root root 1024 Oct 28 02:40 192.168.1.43-2012-10-28-02:40:56 |
2450 | 2450 | ||
2451 | cd into that directory to see the output files: :: | 2451 | cd into that directory to see the output files:: |
2452 | 2452 | ||
2453 | $ ls -l | 2453 | $ ls -l |
2454 | -rw-r--r-- 1 root root 369193 Oct 28 02:44 sdc.blktrace.0 | 2454 | -rw-r--r-- 1 root root 369193 Oct 28 02:44 sdc.blktrace.0 |
2455 | -rw-r--r-- 1 root root 197278 Oct 28 02:44 sdc.blktrace.1 | 2455 | -rw-r--r-- 1 root root 197278 Oct 28 02:44 sdc.blktrace.1 |
2456 | 2456 | ||
2457 | And run blkparse on the host system using the device name: :: | 2457 | And run blkparse on the host system using the device name:: |
2458 | 2458 | ||
2459 | $ blkparse sdc | 2459 | $ blkparse sdc |
2460 | 2460 | ||
@@ -2517,25 +2517,25 @@ userspace tools. | |||
2517 | 2517 | ||
2518 | To enable tracing for a given device, use /sys/block/xxx/trace/enable, | 2518 | To enable tracing for a given device, use /sys/block/xxx/trace/enable, |
2519 | where xxx is the device name. This for example enables tracing for | 2519 | where xxx is the device name. This for example enables tracing for |
2520 | /dev/sdc: :: | 2520 | /dev/sdc:: |
2521 | 2521 | ||
2522 | root@crownbay:/sys/kernel/debug/tracing# echo 1 > /sys/block/sdc/trace/enable | 2522 | root@crownbay:/sys/kernel/debug/tracing# echo 1 > /sys/block/sdc/trace/enable |
2523 | 2523 | ||
2524 | Once you've selected the device(s) you want | 2524 | Once you've selected the device(s) you want |
2525 | to trace, selecting the 'blk' tracer will turn the blk tracer on: :: | 2525 | to trace, selecting the 'blk' tracer will turn the blk tracer on:: |
2526 | 2526 | ||
2527 | root@crownbay:/sys/kernel/debug/tracing# cat available_tracers | 2527 | root@crownbay:/sys/kernel/debug/tracing# cat available_tracers |
2528 | blk function_graph function nop | 2528 | blk function_graph function nop |
2529 | 2529 | ||
2530 | root@crownbay:/sys/kernel/debug/tracing# echo blk > current_tracer | 2530 | root@crownbay:/sys/kernel/debug/tracing# echo blk > current_tracer |
2531 | 2531 | ||
2532 | Execute the workload you're interested in: :: | 2532 | Execute the workload you're interested in:: |
2533 | 2533 | ||
2534 | root@crownbay:/sys/kernel/debug/tracing# cat /media/sdc/testfile.txt | 2534 | root@crownbay:/sys/kernel/debug/tracing# cat /media/sdc/testfile.txt |
2535 | 2535 | ||
2536 | And look at the output (note here that we're using 'trace_pipe' instead of | 2536 | And look at the output (note here that we're using 'trace_pipe' instead of |
2537 | trace to capture this trace - this allows us to wait around on the pipe | 2537 | trace to capture this trace - this allows us to wait around on the pipe |
2538 | for data to appear): :: | 2538 | for data to appear):: |
2539 | 2539 | ||
2540 | root@crownbay:/sys/kernel/debug/tracing# cat trace_pipe | 2540 | root@crownbay:/sys/kernel/debug/tracing# cat trace_pipe |
2541 | cat-3587 [001] d..1 3023.276361: 8,32 Q R 1699848 + 8 [cat] | 2541 | cat-3587 [001] d..1 3023.276361: 8,32 Q R 1699848 + 8 [cat] |
@@ -2554,7 +2554,7 @@ for data to appear): :: | |||
2554 | cat-3587 [001] d..1 3023.276497: 8,32 m N cfq3587 activate rq, drv=1 | 2554 | cat-3587 [001] d..1 3023.276497: 8,32 m N cfq3587 activate rq, drv=1 |
2555 | cat-3587 [001] d..2 3023.276500: 8,32 D R 1699848 + 8 [cat] | 2555 | cat-3587 [001] d..2 3023.276500: 8,32 D R 1699848 + 8 [cat] |
2556 | 2556 | ||
2557 | And this turns off tracing for the specified device: :: | 2557 | And this turns off tracing for the specified device:: |
2558 | 2558 | ||
2559 | root@crownbay:/sys/kernel/debug/tracing# echo 0 > /sys/block/sdc/trace/enable | 2559 | root@crownbay:/sys/kernel/debug/tracing# echo 0 > /sys/block/sdc/trace/enable |
2560 | 2560 | ||
@@ -2572,6 +2572,6 @@ section can be found here: | |||
2572 | 2572 | ||
2573 | The above manpages, along with manpages for the other blktrace utilities | 2573 | The above manpages, along with manpages for the other blktrace utilities |
2574 | (btt, blkiomon, etc) can be found in the /doc directory of the blktrace | 2574 | (btt, blkiomon, etc) can be found in the /doc directory of the blktrace |
2575 | tools git repo: :: | 2575 | tools git repo:: |
2576 | 2576 | ||
2577 | $ git clone git://git.kernel.dk/blktrace.git | 2577 | $ git clone git://git.kernel.dk/blktrace.git |