1.. _hld-trace-log:
2
3Tracing and Logging High-Level Design
4#####################################
5
6Both Trace and Log are built on top of a mechanism named shared
7buffer (sbuf).
8
9Shared Buffer
10*************
11
12Shared Buffer is a ring buffer divided into predetermined-size slots. There
13are two use scenarios of sbuf:
14
15- sbuf can serve as a lockless ring buffer to share data from ACRN HV to
16  Service VM in non-overwritten mode. (Writing will fail if an overrun
17  happens.)
18- sbuf can serve as a conventional ring buffer in hypervisor in
19  over-written mode. A lock is required to synchronize access by the
20  producer and consumer.
21
22Both ACRNTrace and ACRNLog use sbuf as a lockless ring buffer.  The sbuf
23is allocated by Service VM and assigned to HV via a hypercall. To hold pointers
24to sbuf passed down via hypercall, an array ``sbuf[ACRN_SBUF_ID_MAX]``
25is defined in per_cpu region of HV, with predefined sbuf ID to identify
26the usage, such as ACRNTrace, ACRNLog, etc.
27
28For each physical CPU, there is a dedicated sbuf. Only a single producer
29is allowed to put data into that sbuf in HV, and a single consumer is
30allowed to get data from sbuf in Service VM. Therefore, no lock is required to
31synchronize access by the producer and consumer.
32
33sbuf APIs
34=========
35
36The sbuf APIs are defined in ``hypervisor/include/debug/sbuf.h``.
37
38
39ACRN Trace
40**********
41
42ACRNTrace is a tool running on the Service VM to capture trace
43data. It allows developers to add performance profiling trace points at
44key locations to get a picture of what is going on inside the
45hypervisor.  Scripts to analyze the collected trace data are also
46provided.
47
48As shown in :numref:`acrntrace-arch`, ACRNTrace is built using
49Shared Buffers (sbuf), and consists of three parts from bottom layer
50up:
51
52- **ACRNTrace userland app**: Userland application collecting trace data to
53  files (Per Physical CPU)
54
55- **Service VM Trace Module**: allocates/frees sbufs, creates device for each
56  sbuf, sets up sbuf shared between Service VM and HV, and provides a dev node for the
57  userland app to retrieve trace data from sbuf
58
59- **Trace APIs**: provide APIs to generate trace event and insert to sbuf.
60
61.. figure:: images/log-image50.png
62   :align: center
63   :name: acrntrace-arch
64
65   Architectural diagram of ACRNTrace
66
67Trace APIs
68==========
69
70See ``hypervisor/include/debug/trace.h``
71for trace_entry struct and function APIs.
72
73
74Service VM Trace Module
75=======================
76
77The Service VM trace module is responsible for:
78
79- allocating sbuf in Service VM memory range for each physical CPU, and assign
80  the GPA of sbuf to ``per_cpu sbuf[ACRN_TRACE]``
81- create a misc device for each physical CPU
82- provide mmap operation to map entire sbuf to userspace for high
83  flexible and efficient access.
84
85On Service VM shutdown, the trace module is responsible to remove misc devices, free
86sbufs, and set ``per_cpu sbuf[ACRN_TRACE]`` to null.
87
88ACRNTrace Application
89=====================
90
91ACRNTrace application includes a binary to retrieve trace data from
92sbuf, and Python scripts to convert trace data from raw format into
93readable text, and do analysis.
94
95With a debug build, trace components are initialized at boot
96time. After initialization, HV writes trace event date into sbuf
97until sbuf is full, which can happen easily if the ACRNTrace app is not
98consuming trace data from sbuf on Service VM user space.
99
100Once ACRNTrace is launched, for each physical CPU a consumer thread is
101created to periodically read RAW trace data from sbuf and write to a
102file.
103
104These are the Python scripts provided:
105
106- **acrntrace_format.py** converts RAW trace data to human-readable
107  text offline according to given format;
108
109- **acrnalyze.py** analyzes trace data (as output by acrntrace)
110  based on given analyzer filters, such as vm_exit or IRQ, and generates a
111  report.
112
113See :ref:`acrntrace` for details and usage.
114
115ACRN Log
116********
117
118``acrnlog`` is a tool used to capture ACRN hypervisor log to files on
119Service VM filesystem. It can run as a Service VM service at boot, capturing two
120kinds of logs:
121
122-  Current runtime logs;
123-  Logs remaining in the buffer, from the last crashed run.
124
125Architectural Diagram
126=====================
127
128Similar to the design of ACRN Trace, ACRN Log is built on top of
129Shared Buffer (sbuf), and consists of three parts from bottom layer
130up:
131
132- **ACRN Log app**: Userland application collecting hypervisor log to
133  files;
134- **Service VM ACRN Log Module**: constructs/frees sbufs at reserved memory
135  area, creates dev for current/last logs, sets up sbuf shared between
136  Service VM and HV, and provides a dev node for the userland app to
137  retrieve logs
138- **ACRN log support in HV**: put logs at specified loglevel to sbuf.
139
140.. figure:: images/log-image73.png
141   :align: center
142
143   Architectural diagram of ACRN Log
144
145
146ACRN Log Support in Hypervisor
147==============================
148
149To support ``acrnlog``, the following adaption was made to hypervisor log
150system:
151
152- log messages with severity level higher than a specified value will
153  be put into sbuf when calling ``logmsg`` in hypervisor
154- allocate sbuf to accommodate early hypervisor logs before Service VM
155  can allocate and set up sbuf
156
157There are 6 different loglevels, as shown below. The specified
158severity loglevel is stored in ``mem_loglevel``, initialized
159by :option:`hv.DEBUG_OPTIONS.MEM_LOGLEVEL`. The loglevel can
160be set to a new value
161at runtime via hypervisor shell command ``loglevel``.
162
163.. code-block:: c
164
165   #define LOG_FATAL     1U
166   #define LOG_ACRN      2U
167   #define LOG_ERROR     3U
168   #define LOG_WARNING   4U
169   #define LOG_INFO      5U
170   #define LOG_DEBUG     6U
171
172
173The element size of sbuf for logs is fixed at 80 bytes, and the max size
174of a single log message is 320 bytes. Log messages with a length between
17580 and 320 bytes will be separated into multiple sbuf elements. Log
176messages with length larger than 320 will be truncated.
177
178For security, Service VM allocates sbuf in its memory range and assigns it to
179the hypervisor.
180
181Service VM ACRN Log Module
182==========================
183
184ACRNLog module provides one kernel option ``hvlog=$size@$pbase`` to configure
185the size and base address of hypervisor log buffer. This space will be further divided
186into two buffers with equal size: last log buffer and current log buffer.
187
188On Service VM boot, Service VM acrnlog module is responsible to:
189
190- examine if there are log messages remaining from last crashed
191  run by checking the magic number of each sbuf
192
193- if there are previous crash logs, construct sbuf and create misc devices for
194  these last logs
195
196- construct sbuf in the usable buf range for each physical CPU,
197  assign the GPA of sbuf to ``per_cpu sbuf[ACRN_LOG]`` and create a misc
198  device for each physical CPU
199
200- the misc devices implement read() file operation to allow
201  userspace app to read one sbuf element.
202
203When checking the validity of sbuf for last logs examination, it sets the
204current sbuf with magic number ``0x5aa57aa71aa13aa3``, and changes the
205magic number of last sbuf to ``0x5aa57aa71aa13aa2``, to distinguish which is
206the current/last.
207
208On Service VM shutdown, the module is responsible to remove misc devices,
209free sbufs, and set ``per_cpu sbuf[ACRN_TRACE]`` to null.
210
211ACRN Log Application
212====================
213
214ACRNLog application reads log messages from sbuf for each physical
215CPU and combines them into log files with log messages in ascending
216order by the global sequence number. If the sequence number is not
217continuous, a warning of "incontinuous logs" will be inserted.
218
219To avoid using up storage space, the size of a single log file and
220the total number of log files are both limited. By default, log file
221size limitation is 1MB and file number limitation is 4.
222
223If there are last log devices, ACRN log will read out the log
224messages, combine them, and save them into last log files.
225
226See :ref:`acrnlog` for usage details.
227