acrn-hypervisor/doc/tutorials/debug.rst

241 lines
6.6 KiB
ReStructuredText

.. _acrn-debug:
ACRN Debugging Tools
####################
This document describes how to use ACRN tools to collect log
and trace data for debugging.
ACRN Console Command
********************
The ACRN console provides shell commands for a user to check system states
and environment settings. See the :ref:`acrnshell` documentation for a
full list of commands, or see a summary of available commands by using
the ``help`` command within the ACRN shell.
An Example
**********
As an example, we'll show how to obtain the interrupts of a passthrough USB device.
First, we can get the USB controller BDF number (0:15.0) through the
following command in the Service VM console::
lspci | grep "USB controller"
.. figure:: images/debug_image19.png
:align: center
USB controller BDF information
Second, we use the ``pt`` command in the ACRN console, and use this BDF number
to find the interrupt vector (VEC) "0x31".
.. figure:: images/debug_image20.png
:align: center
USB controller interrupt information
Finally we use the ``int`` command in the ACRN console, and use this
interrupt vector to find the interrupt number (909) on CPU3.
.. figure:: images/debug_image21.png
:align: center
USB controller interrupt number information
ACRN Log
********
ACRN log provides a console log and a mem log for a user to analyze.
We can use console log to debug directly, while mem log is a userland tool
used to capture an ACRN hypervisor log.
Turn on the Logging Info
========================
ACRN enables a console log by default.
To enable and start the mem log::
$ systemctl enable acrnlog
$ systemctl start acrnlog
Set and Grab Log
================
We have six (1-6) log levels for console log and mem log. The following
functions print different levels of console log and mem log::
pr_dbg("debug...level %d", LOG_DEBUG); //level 6
pr_info("info...level %d", LOG_INFO); //level 5
pr_warn("warn...level %d", LOG_WARNING); //level 4
pr_err("err...level %d", LOG_ERROR); //level 3
pr_acrnlog("acrnlog...level %d", LOG_ACRN); //level 2
pr_fatal("fatal...level %d", LOG_FATAL); //level 1
If the built-in logging doesn't provide enough information, you can add
additional logging in functions you want to debug, using the functions
noted above. For example, add the following code into function
``shell_cmd_help`` in the source file
``acrn-hypervisor/hypervisor/debug/shell.c``:
.. figure:: images/debug_image22.png
:align: center
shell_cmd_help added information
Once you have instrumented the code, you need to rebuild the hypervisor and
install it on your platform. Refer to :ref:`getting-started-building`
for detailed instructions on how to do that.
We set console log level to 5, and mem log level to 2 through the
command::
loglevel 5 2
Then we input ``help`` into the ACRN console (this is the command that we have
just instrumented with additional log information), and check the log as follows.
.. figure:: images/debug_image23.png
:align: center
console log information
Then we use the command, on the ACRN console::
vm_console
to switch to the Service VM console. Then we use the command::
cat /tmp/acrnlog/acrnlog_cur.0
and we will see the following log:
.. figure:: images/debug_image24.png
:align: center
mem log information
ACRN Trace
**********
ACRN trace is a tool running on the Service VM to capture trace
data. We can use the existing trace information to analyze, and we can
add self-defined tracing to analyze code that we care about.
Using Existing Trace Event ID to Analyze Trace
==============================================
As an example, we can use the existing vm_exit trace to analyze the
reason and times of each vm_exit after we have done some operations.
1. Run the following Service VM console command to collect
trace data::
# acrntrace -c
2. Check current directory, and confirm the directory contains four
trace files::
# ls
0 1 2 3
3. Use the command to get a summary of vmexit::
# acrnalyze.py -i /home/trace/acrntrace/20190219-001529/1 -o vmexit --vm_exit
.. note:: The acrnalyze.py script is in the
``misc/tools/acrntrace/scripts`` folder. The location
of the trace files produced by ``acrntrace`` may be different in your system.
.. figure:: images/debug_image28.png
:align: center
vmexit summary information
Using Self-Defined Trace Event ID to Analyze Trace
==================================================
For some undefined trace event ID, we can define it by ourselves as
shown in the following example:
1. Add the following new event ID into
``acrn-hypervisor/hypervisor/include/debug/trace.h``:
.. figure:: images/debug_image25.png
:align: center
trace event ID
2. Add the following format to
``misc/tools/acrntrace/scripts/formats``:
.. figure:: images/debug_image1.png
:align: center
acrntrace formatted information
.. note::
Formats:
``0x00000005``: event ID for trace test
``%(cpu)d``: corresponding CPU index with decimal format
``%(event)016x``: corresponding event id with hex format
``%(tsc)d``: corresponding event time stamp with decimal format
``%(1)08x``: corresponding first Long data in TRACE_2L
3. Add trace into function ``emulate_io`` in
``acrn-hypervisor/hypervisor/arch/x86/guest/io_emul.c`` that we want to
trace for the calling times of function ``emulate_io``:
.. figure:: images/debug_image2.png
:align: center
inserted trace information
4. After we have inserted the trace code addition, we need to rebuild
the ACRN hypervisor and install it on the platform. Refer to
:ref:`getting-started-building` for
detailed instructions on how to do that.
5. Now we can use the following command in the Service VM console
to generate acrntrace data into the current directory::
acrntrace -c
.. figure:: images/debug_image3.png
:align: center
trace collection
6. Run the console command::
# acrntrace_format.py \
formats /home/trace/acrntrace/20190219-001529/1 | grep "trace test"
.. note:: The acrnalyze.py script is in the
``misc/tools/acrntrace/scripts`` folder. The location
of the trace files produced by ``acrntrace`` may be different in your system.
and we will get the following log:
.. figure:: images/debug_image4.png
:align: center
trace collection
.. note::
The trace data may generate on any of the available CPUs, so
you'll need to check which CPU number was used and specify that
CPU to analyze its trace.