diff options
Diffstat (limited to 'documentation/profile-manual')
| -rw-r--r-- | documentation/profile-manual/usage.rst | 22 |
1 files changed, 22 insertions, 0 deletions
diff --git a/documentation/profile-manual/usage.rst b/documentation/profile-manual/usage.rst index 0fd703d8a5..0ff9d921fd 100644 --- a/documentation/profile-manual/usage.rst +++ b/documentation/profile-manual/usage.rst | |||
| @@ -197,6 +197,7 @@ in an interactive UI:: | |||
| 197 | 197 | ||
| 198 | .. image:: figures/perf-wget-flat-stripped.png | 198 | .. image:: figures/perf-wget-flat-stripped.png |
| 199 | :align: center | 199 | :align: center |
| 200 | :width: 70% | ||
| 200 | 201 | ||
| 201 | The above screenshot displays a 'flat' profile, one entry for each | 202 | The above screenshot displays a 'flat' profile, one entry for each |
| 202 | 'bucket' corresponding to the functions that were profiled during the | 203 | 'bucket' corresponding to the functions that were profiled during the |
| @@ -230,6 +231,7 @@ but the entire callchain to the sampled function as well:: | |||
| 230 | 231 | ||
| 231 | .. image:: figures/perf-wget-g-copy-to-user-expanded-stripped.png | 232 | .. image:: figures/perf-wget-g-copy-to-user-expanded-stripped.png |
| 232 | :align: center | 233 | :align: center |
| 234 | :width: 70% | ||
| 233 | 235 | ||
| 234 | Using the callgraph view, we can actually see not only which functions | 236 | Using the callgraph view, we can actually see not only which functions |
| 235 | took the most time, but we can also see a summary of how those functions | 237 | took the most time, but we can also see a summary of how those functions |
| @@ -266,6 +268,7 @@ busybox. | |||
| 266 | 268 | ||
| 267 | .. image:: figures/perf-wget-g-copy-from-user-expanded-stripped.png | 269 | .. image:: figures/perf-wget-g-copy-from-user-expanded-stripped.png |
| 268 | :align: center | 270 | :align: center |
| 271 | :width: 70% | ||
| 269 | 272 | ||
| 270 | The above screenshot shows the other half of the journey for the data - | 273 | The above screenshot shows the other half of the journey for the data - |
| 271 | from the wget program's userspace buffers to disk. To get the buffers to | 274 | from the wget program's userspace buffers to disk. To get the buffers to |
| @@ -283,6 +286,7 @@ let's expand the first entry containing BusyBox: | |||
| 283 | 286 | ||
| 284 | .. image:: figures/perf-wget-busybox-expanded-stripped.png | 287 | .. image:: figures/perf-wget-busybox-expanded-stripped.png |
| 285 | :align: center | 288 | :align: center |
| 289 | :width: 70% | ||
| 286 | 290 | ||
| 287 | Again, before we expanded we saw that the function was labeled with a | 291 | Again, before we expanded we saw that the function was labeled with a |
| 288 | hex value instead of a symbol as with most of the kernel entries. | 292 | hex value instead of a symbol as with most of the kernel entries. |
| @@ -330,6 +334,7 @@ their functions symbolically: | |||
| 330 | 334 | ||
| 331 | .. image:: figures/perf-wget-busybox-debuginfo.png | 335 | .. image:: figures/perf-wget-busybox-debuginfo.png |
| 332 | :align: center | 336 | :align: center |
| 337 | :width: 70% | ||
| 333 | 338 | ||
| 334 | If we expand one of the entries and press 'enter' on a leaf node, we're | 339 | If we expand one of the entries and press 'enter' on a leaf node, we're |
| 335 | presented with a menu of actions we can take to get more information | 340 | presented with a menu of actions we can take to get more information |
| @@ -337,6 +342,7 @@ related to that entry: | |||
| 337 | 342 | ||
| 338 | .. image:: figures/perf-wget-busybox-dso-zoom-menu.png | 343 | .. image:: figures/perf-wget-busybox-dso-zoom-menu.png |
| 339 | :align: center | 344 | :align: center |
| 345 | :width: 70% | ||
| 340 | 346 | ||
| 341 | One of these actions allows us to show a view that displays a | 347 | One of these actions allows us to show a view that displays a |
| 342 | busybox-centric view of the profiled functions (in this case we've also | 348 | busybox-centric view of the profiled functions (in this case we've also |
| @@ -344,6 +350,7 @@ expanded all the nodes using the 'E' key): | |||
| 344 | 350 | ||
| 345 | .. image:: figures/perf-wget-busybox-dso-zoom.png | 351 | .. image:: figures/perf-wget-busybox-dso-zoom.png |
| 346 | :align: center | 352 | :align: center |
| 353 | :width: 70% | ||
| 347 | 354 | ||
| 348 | Finally, we can see that now that the BusyBox debuginfo is installed, | 355 | Finally, we can see that now that the BusyBox debuginfo is installed, |
| 349 | the previously unresolved symbol in the ``sys_clock_gettime()`` entry | 356 | the previously unresolved symbol in the ``sys_clock_gettime()`` entry |
| @@ -354,6 +361,7 @@ function: | |||
| 354 | 361 | ||
| 355 | .. image:: figures/perf-wget-g-copy-to-user-expanded-debuginfo.png | 362 | .. image:: figures/perf-wget-g-copy-to-user-expanded-debuginfo.png |
| 356 | :align: center | 363 | :align: center |
| 364 | :width: 70% | ||
| 357 | 365 | ||
| 358 | At the lowest level of detail, we can dive down to the assembly level | 366 | At the lowest level of detail, we can dive down to the assembly level |
| 359 | and see which instructions caused the most overhead in a function. | 367 | and see which instructions caused the most overhead in a function. |
| @@ -362,6 +370,7 @@ with a menu: | |||
| 362 | 370 | ||
| 363 | .. image:: figures/perf-wget-busybox-annotate-menu.png | 371 | .. image:: figures/perf-wget-busybox-annotate-menu.png |
| 364 | :align: center | 372 | :align: center |
| 373 | :width: 70% | ||
| 365 | 374 | ||
| 366 | Selecting 'Annotate udhcpc_main', we get a detailed listing of | 375 | Selecting 'Annotate udhcpc_main', we get a detailed listing of |
| 367 | percentages by instruction for the udhcpc_main function. From the | 376 | percentages by instruction for the udhcpc_main function. From the |
| @@ -370,6 +379,7 @@ taken up by a couple tests and the move of a constant (1) to a register: | |||
| 370 | 379 | ||
| 371 | .. image:: figures/perf-wget-busybox-annotate-udhcpc.png | 380 | .. image:: figures/perf-wget-busybox-annotate-udhcpc.png |
| 372 | :align: center | 381 | :align: center |
| 382 | :width: 70% | ||
| 373 | 383 | ||
| 374 | As a segue into tracing, let's try another profile using a different | 384 | As a segue into tracing, let's try another profile using a different |
| 375 | counter, something other than the default 'cycles'. | 385 | counter, something other than the default 'cycles'. |
| @@ -593,6 +603,7 @@ and tell perf to do a profile using it as the sampling event:: | |||
| 593 | 603 | ||
| 594 | .. image:: figures/sched-wakeup-profile.png | 604 | .. image:: figures/sched-wakeup-profile.png |
| 595 | :align: center | 605 | :align: center |
| 606 | :width: 70% | ||
| 596 | 607 | ||
| 597 | The screenshot above shows the results of running a profile using | 608 | The screenshot above shows the results of running a profile using |
| 598 | sched:sched_switch tracepoint, which shows the relative costs of various | 609 | sched:sched_switch tracepoint, which shows the relative costs of various |
| @@ -894,6 +905,7 @@ other processes running on the system as well: | |||
| 894 | 905 | ||
| 895 | .. image:: figures/perf-systemwide.png | 906 | .. image:: figures/perf-systemwide.png |
| 896 | :align: center | 907 | :align: center |
| 908 | :width: 70% | ||
| 897 | 909 | ||
| 898 | In the snapshot above, we can see callchains that originate in libc, and | 910 | In the snapshot above, we can see callchains that originate in libc, and |
| 899 | a callchain from Xorg that demonstrates that we're using a proprietary X | 911 | a callchain from Xorg that demonstrates that we're using a proprietary X |
| @@ -911,6 +923,7 @@ record a profile:: | |||
| 911 | 923 | ||
| 912 | .. image:: figures/perf-report-cycles-u.png | 924 | .. image:: figures/perf-report-cycles-u.png |
| 913 | :align: center | 925 | :align: center |
| 926 | :width: 70% | ||
| 914 | 927 | ||
| 915 | Notice in the screenshot above, we see only userspace entries ([.]) | 928 | Notice in the screenshot above, we see only userspace entries ([.]) |
| 916 | 929 | ||
| @@ -921,6 +934,7 @@ the entries associated with the libc-xxx.so DSO. | |||
| 921 | 934 | ||
| 922 | .. image:: figures/perf-systemwide-libc.png | 935 | .. image:: figures/perf-systemwide-libc.png |
| 923 | :align: center | 936 | :align: center |
| 937 | :width: 70% | ||
| 924 | 938 | ||
| 925 | We can also use the system-wide -a switch to do system-wide tracing. | 939 | We can also use the system-wide -a switch to do system-wide tracing. |
| 926 | Here we'll trace a couple of scheduler events:: | 940 | Here we'll trace a couple of scheduler events:: |
| @@ -1116,6 +1130,7 @@ callgraphs from starting a few programs during those 30 seconds: | |||
| 1116 | 1130 | ||
| 1117 | .. image:: figures/perf-probe-do_fork-profile.png | 1131 | .. image:: figures/perf-probe-do_fork-profile.png |
| 1118 | :align: center | 1132 | :align: center |
| 1133 | :width: 70% | ||
| 1119 | 1134 | ||
| 1120 | .. admonition:: Tying it Together | 1135 | .. admonition:: Tying it Together |
| 1121 | 1136 | ||
| @@ -1684,6 +1699,7 @@ events (or even one or more complete subsystems) to trace: | |||
| 1684 | 1699 | ||
| 1685 | .. image:: figures/kernelshark-choose-events.png | 1700 | .. image:: figures/kernelshark-choose-events.png |
| 1686 | :align: center | 1701 | :align: center |
| 1702 | :width: 70% | ||
| 1687 | 1703 | ||
| 1688 | Note that these are exactly the same sets of events described in the | 1704 | Note that these are exactly the same sets of events described in the |
| 1689 | previous trace events subsystem section, and in fact is where trace-cmd | 1705 | previous trace events subsystem section, and in fact is where trace-cmd |
| @@ -1699,6 +1715,7 @@ will turn into the 'Stop' button after the trace has started): | |||
| 1699 | 1715 | ||
| 1700 | .. image:: figures/kernelshark-output-display.png | 1716 | .. image:: figures/kernelshark-output-display.png |
| 1701 | :align: center | 1717 | :align: center |
| 1718 | :width: 70% | ||
| 1702 | 1719 | ||
| 1703 | Notice that the right-hand pane shows the exact trace-cmd command-line | 1720 | Notice that the right-hand pane shows the exact trace-cmd command-line |
| 1704 | that's used to run the trace, along with the results of the trace-cmd | 1721 | that's used to run the trace, along with the results of the trace-cmd |
| @@ -1710,12 +1727,14 @@ detailed event listing below that: | |||
| 1710 | 1727 | ||
| 1711 | .. image:: figures/kernelshark-i915-display.png | 1728 | .. image:: figures/kernelshark-i915-display.png |
| 1712 | :align: center | 1729 | :align: center |
| 1730 | :width: 70% | ||
| 1713 | 1731 | ||
| 1714 | Here's another example, this time a display resulting from tracing 'all | 1732 | Here's another example, this time a display resulting from tracing 'all |
| 1715 | events': | 1733 | events': |
| 1716 | 1734 | ||
| 1717 | .. image:: figures/kernelshark-all.png | 1735 | .. image:: figures/kernelshark-all.png |
| 1718 | :align: center | 1736 | :align: center |
| 1737 | :width: 70% | ||
| 1719 | 1738 | ||
| 1720 | The tool is pretty self-explanatory, but for more detailed information | 1739 | The tool is pretty self-explanatory, but for more detailed information |
| 1721 | on navigating through the data, see the `kernelshark | 1740 | on navigating through the data, see the `kernelshark |
| @@ -1974,6 +1993,7 @@ with profiling data: | |||
| 1974 | 1993 | ||
| 1975 | .. image:: figures/sysprof-copy-to-user.png | 1994 | .. image:: figures/sysprof-copy-to-user.png |
| 1976 | :align: center | 1995 | :align: center |
| 1996 | :width: 70% | ||
| 1977 | 1997 | ||
| 1978 | The left pane shows a list of functions and processes. Selecting one of | 1998 | The left pane shows a list of functions and processes. Selecting one of |
| 1979 | those expands that function in the right pane, showing all its callees. | 1999 | those expands that function in the right pane, showing all its callees. |
| @@ -1988,6 +2008,7 @@ in the perf display shown in the perf section of this page. | |||
| 1988 | 2008 | ||
| 1989 | .. image:: figures/sysprof-copy-from-user.png | 2009 | .. image:: figures/sysprof-copy-from-user.png |
| 1990 | :align: center | 2010 | :align: center |
| 2011 | :width: 70% | ||
| 1991 | 2012 | ||
| 1992 | Similarly, the above is a snapshot of the Sysprof display of a | 2013 | Similarly, the above is a snapshot of the Sysprof display of a |
| 1993 | copy-from-user callchain. | 2014 | copy-from-user callchain. |
| @@ -1999,6 +2020,7 @@ left pane. In this case, the lower pane is showing all the callers of | |||
| 1999 | 2020 | ||
| 2000 | .. image:: figures/sysprof-callers.png | 2021 | .. image:: figures/sysprof-callers.png |
| 2001 | :align: center | 2022 | :align: center |
| 2023 | :width: 70% | ||
| 2002 | 2024 | ||
| 2003 | Double-clicking on one of those functions will in turn change the focus | 2025 | Double-clicking on one of those functions will in turn change the focus |
| 2004 | to the selected function, and so on. | 2026 | to the selected function, and so on. |
