Event Tracing (eventlib)#
Overview#
Event tracing in HVRTOS uses the eventlib library to capture and record system events for analysis.
Trace producers include:
Hypervisor kernel core code, which logs scheduler, interrupt, trap, and related kernel events
Sidekick code, which can emit sidekick-specific eventlib records
Native processes and non-core drivers that use eventlib to publish their own traces
These traces are useful for tracking CPU utilization across VMs, making performance optimizations, and debugging asynchronous operations. Users can utilize event traces to identify different aspects of CPU cycle consumption such as:
Physical CPU (PCPU) idle CPU cycles and CPU cycles spent in the Hypervisor.
Relative distribution of CPU cycle consumption for different VMs, Sidekick and VM Context Switches.
Event traces are integrated with NvLumos and Nsight Systems for visualization and analysis. For detailed information on using Nsight Systems, refer to the “Hypervisor Trace” chapter in the NVIDIA Nsight Systems User Guide.
Drive OS Profiles#
This feature is available in the following Drive OS profiles:
Profile |
Availability |
Notes |
|---|---|---|
|
✓ Available |
Automatically enabled for non-secure components (kernel, processes, VMs) |
|
✗ Not Available |
Not available in production and test builds |
Configuration#
Platform Configuration (platform_config.h)#
Event tracing is configured through the platform configuration, which is part of the Platform Configuration Table (PCT).
Field |
Description |
|---|---|
|
Size of the non-secure event trace buffer region. This is selected at integration time and the hypervisor enforces a maximum of 8 MB per physical CPU. |
|
Boot-time event group mask for non-secure traces. |
|
Size of the secure-world event trace buffer region, when secure tracing is enabled. |
|
Boot-time event group mask for secure-world traces. |
To enable Hypervisor event logging, set the following fields in platform_config.h:
# In platform_config.h for the PCT
.log_size = SZ_1_MB * PLAT_NR_CPU, // 1 MB per physical CPU (max: 8MB per CPU)
.trace_mask = ~0ULL, // Enable all Hypervisor events
To enable secure-world (Trusted OS) event logging:
.secure_log_size = SZ_1_MB, // 1 MB (max: 8MB)
.secure_trace_mask = ~0ULL, // Enable all secure world events
VM configuration (guest_config.h)#
Per-VM settings live in the PCT guest configuration (commonly edited through your platform’s guest_config.h, which initializes each guest_conf entry):
Field |
Description |
|---|---|
|
Set non-zero to enable. When non-zero, the hypervisor exposes event trace buffers to that VM by mapping the mempool to the VM. That lets software running inside the VM list trace buffers and read traces, for example by using |
|
Set non-zero to enable. When non-zero, the VM may read and update the global event trace mask at runtime through Eventlib HVCs. When zero, get/set mask requests from that VM are rejected even if |
log_access and can_access_trace_mask are independent: a VM can be allowed to read traces without being allowed to change the mask, or vice versa, depending on integration policy.
These configurations can be enabled simultaneously for multiple VMs in the system.
Example
// guest_config.h — fields inside each guest's configuration block
.log_access = 1U, // VM can access trace mempools / use eventlib_dump
.can_access_trace_mask = 1U, // VM can change which event groups are logged at runtime
Event masks and trace behavior#
Initial event mask (PCT)
The event mask is a bitmask of Event Group values. It selects which categories of events are written to the trace buffers. Set the boot-time mask in platform_config.h using trace_mask and secure_trace_mask as shown above.
Runtime event mask (privileged VM)
To change the mask after boot from software running in a VM, that VM must have ``can_access_trace_mask`` enabled; eventlib_dump issues the hypervisor HVCs that implement get/set. VMs without this permission cannot alter the global mask at runtime. The Debug Server events command uses a separate host-side path.
Trace buffer sizing (platform)
Event traces live in shared memory whose size is chosen at integration time in platform_config.h (log_size / secure_log_size). The hypervisor enforces a maximum of 8 MB per physical CPU and recommended to use the same size for both log_size and secure_log_size.
Limitations#
Limitation |
Description |
Impact |
|---|---|---|
Trace Buffer Wrap |
High-volume event combinations can wrap the trace buffer quickly and shorten the useful capture window |
Prefer the largest supported trace buffer when collecting broad or long-duration traces |
Sidekick Tracing Cost |
Sidekick eventlib producers trap into the hypervisor kernel to emit records |
Avoid describing those paths as lightweight when tracing at high rates |
Secure world Event mask |
Secure world event mask runtime change is not supported |
To modify the secure world event mask, the system must be reflashed with an updated PCT. |
Detailed Usage#
Collecting Event Traces#
Via Privileged Guest (eventlib_dump)#
Identifying Mempool IDs:
First, list all available eventlib producers and their mempool IDs:
eventlib_dump -L
This command lists all available writer names and mempool IDs in the format: <provider_name> <mempool_id>
Collecting Traces:
Use eventlib_dump with the mempool ID:
# Collect traces from a specific mempool
eventlib_dump -m <mempool_id> -o events.bin
# Continuous collection with delay
eventlib_dump -m <mempool_id> -c -d 10000 -o events.bin
# Print timestamps
eventlib_dump -m <mempool_id> -p cntvct -o events.bin
Common Options:
-m <id>: Shared memory segment ID (mempool ID) to use-c: Continuous mode (do not exit after dumping existing events)-d <msecs>: Delay in milliseconds when no events are available (default: 1)-o <filename>: Output file (use-for stdout)-p cntvct: Print timestamps using CNTVCT-L: List all available writer names and mempool IDs
Converting Traces:
Convert binary traces to text/JSON format using eventlib conversion tools. The output is sorted by timestamp:
${NV_WORKSPACE}/tools/perf/eventlib/eventlib_format -json ${NV_WORKSPACE}/foundation/meta/schemas/event/hv_events.json events.bin | sort -n -k1.2 > sorted_events.json
Troubleshooting:
Traces showing 0 bytes: Ensure bind step was completed and correct images were flashed. Verify mempool ID using
-Loption.Guest VM cannot list mempool IDs or read traces: Set ``log_access`` non-zero for that guest in
guest_config.hso trace-buffer descriptors are published to the VM server page.Guest cannot change which events are logged at runtime: Set ``can_access_trace_mask`` non-zero for that guest; without it, Eventlib HVCs to get/set the global trace mask are rejected by the hypervisor.
Example: CPU Usage Breakdown#
The following example shows a sequence of events for CPU usage on a given physical CPU:
vcpu_enter: VM starts executing (from Hypervisor to VM)
vcpu_exit: VM stops executing (from VM to Hypervisor)
trap_begin/trap_end: Trap handling within Hypervisor
vcpu_enter: Hypervisor enters idle state
vcpu_exit: Hypervisor exits idle state
pirq_begin: Physical interrupt begins
virq_begin/virq_end: Virtual interrupt forwarded to VM
pirq_end: Physical interrupt ends
vcpu_enter: VM resumes execution
Best Practices#
Selective Grouping: Enable only the event groups you need to capture the events of interest
Analysis Tools: Use Nsight Systems or NvLumos for efficient analysis of large trace files
Check Before Logging: Use the EventTracer API to check if specific event groups are enabled before logging events
Mempool Verification: Always verify mempool IDs using
eventlib_dump -Lbefore collecting tracesHigh-volume traces: If enabled groups still produce enough events to risk buffer wrap (see Limitations), use
eventlib_dumpto enable tracing only around well-defined checkpoints and disable afterward so records of interest are less likely to be overwritten before collection.
Event Trace Details#
Note
The following Event Groups, Event Types and Reserved Ids are subject to change in future releases.
Groups#
Events are organized into groups for filtering and control:
Group |
Mask |
Description |
|---|---|---|
|
|
Hypervisor infrequent core events (boot, initialization) |
|
|
Generic scheduling events (context switches, VM switches) |
|
|
Generic interrupt events |
|
|
Generic trap events (exceptions, system calls) |
|
|
VM profiling events (stack traces, PC samples) |
|
|
Runtime IST (Interrupt Service Thread) events |
|
|
Process thread events |
Types#
The following event types are logged by the Hypervisor. Events denoted by an asterisk (*) are only used in the Hypervisor logs.
vcpu_enter#
Logs the transition of a physical CPU from running the Hypervisor to running a VM/Process.
Format:
<timestamp> Event vcpu_enter: pcpuid=<pcpu-id> seqid=<seq-id> vcpuid=<vcpu-id>
from=<hypervisor-id> to=<id> ref_cnt=0
Example:
[1541306690] Event vcpu_enter: pcpuid=0 seqid=7364679 vcpuid=4 from=65534 to=0 ref_cnt=0
vcpu_exit#
Logs the transition of a physical CPU from running a VM/Process to running the Hypervisor.
Format:
<timestamp> Event vcpu_exit: pcpuid=<pcpu-id> seqid=<seq-id> vcpuid=<vcpu-id>
from=<id> to=<hypervisor-id> ref_cnt=0
Example:
[1541309562] Event vcpu_exit: pcpuid=0 seqid=7364680 vcpuid=4 from=0 to=65534 ref_cnt=0
vcpu_switch_begin / vcpu_switch_end#
Logs internal scheduler state transitions within the Hypervisor. These events are useful for measuring context switch overhead.
Format:
<timestamp> Event vcpu_switch_begin: pcpuid=<pcpu-id> seqid=<seq-id> from=<id> to=65535
<timestamp> Event vcpu_switch_end: pcpuid=<pcpu-id> seqid=<seq-id> to=<id>
pirq_begin / pirq_end#
Logs the beginning and ending of physical IRQ handling within the Hypervisor.
Format:
<timestamp> Event pirq_begin: pcpuid=<pcpu-id> seqid=<seq-id> irqid=<irq-id>
<timestamp> Event pirq_end: pcpuid=<pcpu-id> seqid=<seq-id> irqid=<irq-id>
Example:
[1541233813] Event pirq_begin: pcpuid=0 seqid=7364654 irqid=26
[1541233874] Event pirq_end: pcpuid=0 seqid=7364655 irqid=26
virq_begin / virq_end*#
Logs the beginning and ending of virtual IRQ forwarding within the Hypervisor.
Format:
<timestamp> Event virq_begin: pcpuid=<pcpu-id> seqid=<seq-id> irqid=<irq-id> vmid=<vm-id>
<timestamp> Event virq_end: pcpuid=<pcpu-id> seqid=<seq-id> irqid=<irq-id>
vmid=<vm-id> delivered=<delivery_status>
Example:
[1541234208] Event virq_begin: pcpuid=0 seqid=7364660 irqid=27 vmid=4
[1541234225] Event virq_end: pcpuid=0 seqid=7364661 irqid=27 vmid=4 delivered=1
virq_maint_begin / virq_maint_end*#
Logs the beginning and ending of virtual GIC maintenance-interrupt handling within the Hypervisor.
Format:
<timestamp> Event virq_maint_begin: pcpuid=<pcpu-id> seqid=<seq-id> vmid=<vm-id> gich_misr=<misr>
<timestamp> Event virq_maint_end: pcpuid=<pcpu-id> seqid=<seq-id> vmid=<vm-id> gich_misr=<misr>
trap_begin / trap_end*#
Logs the beginning and ending of trap handling within the Hypervisor.
Format:
<timestamp> Event trap_begin: pcpuid=<pcpu-id> seqid=<seq-id> vcpuid=<vcpu-id> ec=<ec>
<timestamp> Event trap_end: pcpuid=<pcpu-id> seqid=<seq-id> vcpuid=<vcpu-id>
ec=<ec> ipa=<ipa> dir=<dir> width=<width>
Example:
[1541234747] Event trap_begin: pcpuid=0 seqid=7364665 vcpuid=0 ec=1
[1541234764] Event trap_end: pcpuid=0 seqid=7364666 vcpuid=0 ec=1 ipa=0 dir=0 width=0
vm_profile#
Logs the program counter value for the running VM.
Format:
<timestamp> Event vm_profile: pcpuid=<pcpu-id> seqid=<seq-id> vmid=<vm-id> pc=<pc> is_sk=<is_sk>
Example:
[1541235923] Event vm_profile: pcpuid=0 seqid=7364667 vmid=65535 pc=0 is_sk=0
Fields#
The following table describes common fields in event traces:
Term |
Definition |
Datatype |
Valid Range |
|---|---|---|---|
|
Specifies the physical CPU ID. |
16-bit unsigned integer |
|
|
Specifies the virtual CPU ID. |
16-bit unsigned integer |
|
|
Specifies the Virtual Machine ID. |
16-bit unsigned integer |
|
|
Helps to identify sequence of events on a physical CPU. Sudden jumps in seq-id indicates loss of events. |
64-bit unsigned integer |
|
|
Specifies the interrupt request ID. |
16-bit unsigned integer |
Note Values |
|
Specifies the exception class. |
6-bit unsigned integer |
Refer to the ARM Architecture Reference Manual for more information. |
|
Specifies the intermediate physical address. |
64-bit unsigned integer |
|
|
Specifies the data abort read/write direction. |
16-bit unsigned integer |
0: Read, 1: Write |
|
Specifies the data abort access width. |
16-bit unsigned integer |
|
|
Specifies the GICH Maintenance Interrupt Status Register. |
32-bit unsigned integer |
|
|
Specifies the reference counter. This field can be ignored. |
||
|
Specifies the delivery status of the virtual interrupt. |
boolean |
Reserved IDs#
The following table lists reserved IDs that may appear in fields such as from, to, or vmid in the preceding event records:
ID |
Description |
|---|---|
65535 |
Hypervisor idle / low-power state |
65534 |
Hypervisor kernel |
65533 |
Hypervisor sidekick |
65525 to 65532 |
Hypervisor sentinel tasks (priority 0-3, secure and non-secure) |
65521 |
TOS secure storage process |
65519, 65520 |
Hypervisor test secure process |
65518 |
TOS testing-service-slave process |
65517 |
TOS testing-service process |