281 lines
10 KiB
ReStructuredText
281 lines
10 KiB
ReStructuredText
.. SPDX-License-Identifier: GPL-2.0
|
|
|
|
==========================
|
|
Userspace debugging advice
|
|
==========================
|
|
|
|
This document provides a brief overview of common tools to debug the Linux
|
|
Kernel from userspace.
|
|
For debugging advice aimed at driver developers go :doc:`here
|
|
</process/debugging/driver_development_debugging_guide>`.
|
|
For general debugging advice, see :doc:`general advice document
|
|
</process/debugging/index>`.
|
|
|
|
.. contents::
|
|
:depth: 3
|
|
|
|
The following sections show you the available tools.
|
|
|
|
Dynamic debug
|
|
-------------
|
|
|
|
Mechanism to filter what ends up in the kernel log by dis-/en-abling log
|
|
messages.
|
|
|
|
Prerequisite: ``CONFIG_DYNAMIC_DEBUG``
|
|
|
|
Dynamic debug is only able to target:
|
|
|
|
- pr_debug()
|
|
- dev_dbg()
|
|
- print_hex_dump_debug()
|
|
- print_hex_dump_bytes()
|
|
|
|
Therefore the usability of this tool is, as of now, quite limited as there is
|
|
no uniform rule for adding debug prints to the codebase, resulting in a variety
|
|
of ways these prints are implemented.
|
|
|
|
Also, note that most debug statements are implemented as a variation of
|
|
dprintk(), which have to be activated via a parameter in respective module,
|
|
dynamic debug is unable to do that step for you.
|
|
|
|
Here is one example, that enables all available pr_debug()'s within the file::
|
|
|
|
$ alias ddcmd='echo $* > /proc/dynamic_debug/control'
|
|
$ ddcmd '-p; file v4l2-h264.c +p'
|
|
$ grep =p /proc/dynamic_debug/control
|
|
drivers/media/v4l2-core/v4l2-h264.c:372 [v4l2_h264]print_ref_list_b =p
|
|
"ref_pic_list_b%u (cur_poc %u%c) %s"
|
|
drivers/media/v4l2-core/v4l2-h264.c:333 [v4l2_h264]print_ref_list_p =p
|
|
"ref_pic_list_p (cur_poc %u%c) %s\n"
|
|
|
|
**When should you use this over Ftrace ?**
|
|
|
|
- When the code contains one of the valid print statements (see above) or when
|
|
you have added multiple pr_debug() statements during development
|
|
- When timing is not an issue, meaning if multiple pr_debug() statements in
|
|
the code won't cause delays
|
|
- When you care more about receiving specific log messages than tracing the
|
|
pattern of how a function is called
|
|
|
|
For the full documentation see :doc:`/admin-guide/dynamic-debug-howto`
|
|
|
|
Ftrace
|
|
------
|
|
|
|
Prerequisite: ``CONFIG_DYNAMIC_FTRACE``
|
|
|
|
This tool uses the tracefs file system for the control files and output files.
|
|
That file system will be mounted as a ``tracing`` directory, which can be found
|
|
in either ``/sys/kernel/`` or ``/sys/debug/kernel/``.
|
|
|
|
Some of the most important operations for debugging are:
|
|
|
|
- You can perform a function trace by adding a function name to the
|
|
``set_ftrace_filter`` file (which accepts any function name found within the
|
|
``available_filter_functions`` file) or you can specifically disable certain
|
|
functions by adding their names to the ``set_ftrace_notrace`` file (more info
|
|
at: :ref:`trace/ftrace:dynamic ftrace`).
|
|
- In order to find out where calls originate from you can activate the
|
|
``func_stack_trace`` option under ``options/func_stack_trace``.
|
|
- Tracing the children of a function call and showing the return values are
|
|
possible by adding the desired function in the ``set_graph_function`` file
|
|
(requires config ``FUNCTION_GRAPH_RETVAL``); more info at
|
|
:ref:`trace/ftrace:dynamic ftrace with the function graph tracer`.
|
|
|
|
For the full Ftrace documentation see :doc:`/trace/ftrace`
|
|
|
|
Or you could also trace for specific events by :ref:`using event tracing
|
|
<trace/events:2. using event tracing>`, which can be defined as described here:
|
|
:ref:`Creating a custom Ftrace tracepoint
|
|
<process/debugging/driver_development_debugging_guide:ftrace>`.
|
|
|
|
For the full Ftrace event tracing documentation see :doc:`/trace/events`
|
|
|
|
.. _read_ftrace_log:
|
|
|
|
Reading the ftrace log
|
|
~~~~~~~~~~~~~~~~~~~~~~
|
|
|
|
The ``trace`` file can be read just like any other file (``cat``, ``tail``,
|
|
``head``, ``vim``, etc.), the size of the file is limited by the
|
|
``buffer_size_kb`` (``echo 1000 > buffer_size_kb``). The
|
|
:ref:`trace/ftrace:trace_pipe` will behave similarly to the ``trace`` file, but
|
|
whenever you read from the file the content is consumed.
|
|
|
|
Kernelshark
|
|
~~~~~~~~~~~
|
|
|
|
A GUI interface to visualize the traces as a graph and list view from the
|
|
output of the `trace-cmd
|
|
<https://git.kernel.org/pub/scm/utils/trace-cmd/trace-cmd.git/>`__ application.
|
|
|
|
For the full documentation see `<https://kernelshark.org/Documentation.html>`__
|
|
|
|
Perf & alternatives
|
|
-------------------
|
|
|
|
The tools mentioned above provide ways to inspect kernel code, results,
|
|
variable values, etc. Sometimes you have to find out first where to look and
|
|
for those cases, a box of performance tracking tools can help you to frame the
|
|
issue.
|
|
|
|
Why should you do a performance analysis?
|
|
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
|
|
|
|
A performance analysis is a good first step when among other reasons:
|
|
|
|
- you cannot define the issue
|
|
- you do not know where it occurs
|
|
- the running system should not be interrupted or it is a remote system, where
|
|
you cannot install a new module/kernel
|
|
|
|
How to do a simple analysis with linux tools?
|
|
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
|
|
|
|
For the start of a performance analysis, you can start with the usual tools
|
|
like:
|
|
|
|
- ``top`` / ``htop`` / ``atop`` (*get an overview of the system load, see
|
|
spikes on specific processes*)
|
|
- ``mpstat -P ALL`` (*look at the load distribution among CPUs*)
|
|
- ``iostat -x`` (*observe input and output devices utilization and performance*)
|
|
- ``vmstat`` (*overview of memory usage on the system*)
|
|
- ``pidstat`` (*similar to* ``vmstat`` *but per process, to dial it down to the
|
|
target*)
|
|
- ``strace -tp $PID`` (*once you know the process, you can figure out how it
|
|
communicates with the Kernel*)
|
|
|
|
These should help to narrow down the areas to look at sufficiently.
|
|
|
|
Diving deeper with perf
|
|
~~~~~~~~~~~~~~~~~~~~~~~
|
|
|
|
The **perf** tool provides a series of metrics and events to further dial down
|
|
on issues.
|
|
|
|
Prerequisite: build or install perf on your system
|
|
|
|
Gather statistics data for finding all files starting with ``gcc`` in ``/usr``::
|
|
|
|
# perf stat -d find /usr -name 'gcc*' | wc -l
|
|
|
|
Performance counter stats for 'find /usr -name gcc*':
|
|
|
|
1277.81 msec task-clock # 0.997 CPUs utilized
|
|
9 context-switches # 7.043 /sec
|
|
1 cpu-migrations # 0.783 /sec
|
|
704 page-faults # 550.943 /sec
|
|
766548897 cycles # 0.600 GHz (97.15%)
|
|
798285467 instructions # 1.04 insn per cycle (97.15%)
|
|
57582731 branches # 45.064 M/sec (2.85%)
|
|
3842573 branch-misses # 6.67% of all branches (97.15%)
|
|
281616097 L1-dcache-loads # 220.390 M/sec (97.15%)
|
|
4220975 L1-dcache-load-misses # 1.50% of all L1-dcache accesses (97.15%)
|
|
<not supported> LLC-loads
|
|
<not supported> LLC-load-misses
|
|
|
|
1.281746009 seconds time elapsed
|
|
|
|
0.508796000 seconds user
|
|
0.773209000 seconds sys
|
|
|
|
|
|
52
|
|
|
|
The availability of events and metrics depends on the system you are running.
|
|
|
|
For the full documentation see
|
|
`<https://perf.wiki.kernel.org/index.php/Main_Page>`__
|
|
|
|
Perfetto
|
|
~~~~~~~~
|
|
|
|
A set of tools to measure and analyze how well applications and systems perform.
|
|
You can use it to:
|
|
|
|
* identify bottlenecks
|
|
* optimize code
|
|
* make software run faster and more efficiently.
|
|
|
|
**What is the difference between perfetto and perf?**
|
|
|
|
* perf is tool as part of and specialized for the Linux Kernel and has CLI user
|
|
interface.
|
|
* perfetto cross-platform performance analysis stack, has extended
|
|
functionality into userspace and provides a WEB user interface.
|
|
|
|
For the full documentation see `<https://perfetto.dev/docs/>`__
|
|
|
|
Kernel panic analysis tools
|
|
---------------------------
|
|
|
|
To capture the crash dump please use ``Kdump`` & ``Kexec``. Below you can find
|
|
some advice for analysing the data.
|
|
|
|
For the full documentation see the :doc:`/admin-guide/kdump/kdump`
|
|
|
|
In order to find the corresponding line in the code you can use `faddr2line
|
|
<https://elixir.bootlin.com/linux/v6.11.6/source/scripts/faddr2line>`__; note
|
|
that you need to enable ``CONFIG_DEBUG_INFO`` for that to work.
|
|
|
|
An alternative to using ``faddr2line`` is the use of ``objdump`` (and its
|
|
derivatives for the different platforms like ``aarch64-linux-gnu-objdump``).
|
|
Take this line as an example:
|
|
|
|
``[ +0.000240] rkvdec_device_run+0x50/0x138 [rockchip_vdec]``.
|
|
|
|
We can find the corresponding line of code by executing::
|
|
|
|
aarch64-linux-gnu-objdump -dS drivers/staging/media/rkvdec/rockchip-vdec.ko | grep rkvdec_device_run\>: -A 40
|
|
0000000000000ac8 <rkvdec_device_run>:
|
|
ac8: d503201f nop
|
|
acc: d503201f nop
|
|
{
|
|
ad0: d503233f paciasp
|
|
ad4: a9bd7bfd stp x29, x30, [sp, #-48]!
|
|
ad8: 910003fd mov x29, sp
|
|
adc: a90153f3 stp x19, x20, [sp, #16]
|
|
ae0: a9025bf5 stp x21, x22, [sp, #32]
|
|
const struct rkvdec_coded_fmt_desc *desc = ctx->coded_fmt_desc;
|
|
ae4: f9411814 ldr x20, [x0, #560]
|
|
struct rkvdec_dev *rkvdec = ctx->dev;
|
|
ae8: f9418015 ldr x21, [x0, #768]
|
|
if (WARN_ON(!desc))
|
|
aec: b4000654 cbz x20, bb4 <rkvdec_device_run+0xec>
|
|
ret = pm_runtime_resume_and_get(rkvdec->dev);
|
|
af0: f943d2b6 ldr x22, [x21, #1952]
|
|
ret = __pm_runtime_resume(dev, RPM_GET_PUT);
|
|
af4: aa0003f3 mov x19, x0
|
|
af8: 52800081 mov w1, #0x4 // #4
|
|
afc: aa1603e0 mov x0, x22
|
|
b00: 94000000 bl 0 <__pm_runtime_resume>
|
|
if (ret < 0) {
|
|
b04: 37f80340 tbnz w0, #31, b6c <rkvdec_device_run+0xa4>
|
|
dev_warn(rkvdec->dev, "Not good\n");
|
|
b08: f943d2a0 ldr x0, [x21, #1952]
|
|
b0c: 90000001 adrp x1, 0 <rkvdec_try_ctrl-0x8>
|
|
b10: 91000021 add x1, x1, #0x0
|
|
b14: 94000000 bl 0 <_dev_warn>
|
|
*bad = 1;
|
|
b18: d2800001 mov x1, #0x0 // #0
|
|
...
|
|
|
|
Meaning, in this line from the crash dump::
|
|
|
|
[ +0.000240] rkvdec_device_run+0x50/0x138 [rockchip_vdec]
|
|
|
|
I can take the ``0x50`` as offset, which I have to add to the base address
|
|
of the corresponding function, which I find in this line::
|
|
|
|
0000000000000ac8 <rkvdec_device_run>:
|
|
|
|
The result of ``0xac8 + 0x50 = 0xb18``
|
|
And when I search for that address within the function I get the
|
|
following line::
|
|
|
|
*bad = 1;
|
|
b18: d2800001 mov x1, #0x0
|
|
|
|
**Copyright** ©2024 : Collabora
|