Intel® System Debugger User Guide

ID 648476
Date 06/13/2024
Confidential
Document Table of Contents

TraceCLI Live output commands

This document provides information on how to use the TraceCLI Live commands.

Warning:

This feature is currently in preview mode and is subject to API changes.

Purpose

When using the capture command in TraceCLI, the output messages are sent to a file. However, this file may not consistently reflect the most recent data. Occasionally, there can be a delay of several minutes before the new messages appears in the file.

This features allows to print in real-time the messages captured to standard output.

Note:

The order in which messages arrive is determined by the type of data being captured. For messages to be organized in chronological order, they must come from a single input source (master & channel id). If this single source condition is not met, the chronological arrangement of messages is not guaranteed.

For example, capturing traces from the BIOS, which is a single source, ensures that the time ordering in the live output is maintained. In contrast, when capturing from CSME, the chronological order of messages is not guaranteed, as they may originate from multiple sources.

Commands

Each of the live commands also has a corresponding version that generates non-live output:

TraceCLI live Commands

Non-live Commands equivalent

Non-live Python* API equivalent

$ decode-live-preview

$ decode

> trace.decode(...)

$ capture-live-preview

$ capture

> trace.start_​capture(...)

$ earlyboot-preview

$ earlyboot

> trace.ext.earlyboot.run(...)

$ emergencyboot-preview

$ emergencyboot

> trace.ext.emergencyboot.run(...)

Outputs

The output from all live commands is directed by default to stdout for messages, while the CLI logs are sent to stderr. This allows for independent access and redirection of each stream. For an example of how to redirect these outputs, refer to this.

Same as for the standard commands, the output columns and format can be configured with the settings argument --output-columns and --output-format

Note:

For the live decode and live capture commands only, there’s an option to also send messages directly to a file. This can be achieved using the --to-file or --to-stdout-and-file parameters.

When directing messages to a file, both --output-location and --output-filename arguments are taken into account.

Filtering

The messages output can be refined by applying a filter expression crafted in a Domain Specific Language. It can be set using the following argument: --filter "<expression>"

Below is the railroad diagram illustrating the grammar of the filter expression:

filter_railroad_grammar

Example of filter expressions:

Filter expression

Description

Summary icontains "version"

Case-insensitive search to find “version” in Summary column

PacketType match(BLOB.MIPI_​*)

Find messages with packet types starting with BLOB.MIPI_​

Severity in ["Warning", "Error", "Fatal"]

Find messages that have a Severity in the given list

Summary ~= /Start.*(Halt|Stop)/

Regex search in the Summary column

MasterId == 16 && ChannelId == 21

Find all messages that match both MasterId and ChannelId values

Note:

Column names are case sensitive. For example, source and Source can represent two distinct columns. To only get messages from a specific trace source, please use the capitalized spelling like in the following: --filter="Source == 'BIOS'"

Use cases & Examples

Visualize outputs of captured traces

By default, using any of the live output commands will display both the messages and CLI logs in the terminal. This can be useful to quickly see the state of the target and current capture:

$ intel_systrace capture-live-preview
{...}
[18:52:30] [INFO    ] [TCA     ] Detected Meteor Lake P
{...}
[18:52:34] [INFO    ] [TRACE   ] Streaming session startup succeeded
"Time","Source","Summary"
[18:52:35] [INFO    ] [TRACE   ] Found message handle registered
[18:52:35] [INFO    ] [TRACE   ] CaptureStatus.running
[18:52:35] [INFO    ] [TRACE   ] Press Ctrl+C to complete capture...
"00:00:02.570434190267","CSME","""[HECI1] Power state changed: Entering CM0-PG! pg_override_mask:0x00000000"""
"00:00:02.570436690267","CSME","""[HECI1] heci_read_csr(): Read 0x80020209 from HECI1_CSE_CSR."""
"00:00:02.570439639486","CSME","""[HECI1] heci_set_we(): Read 0x00000000 and wrote 0x00000001 (HECI1_WE)"""
"00:00:02.570458406575","CSME","""pci_cfg_set_pme(): device id HW_DEV_ID_HECI1(0), sel 0x3f, enable 1"""
"00:00:02.571274047038","CSME","""[ED] ReceiveNotifyConsumer: Consumer Call: Cause: (1) Event: (0x20000004)."""
"00:00:02.571679015299","CSME","""[ED] ReceiveNotifyConsumer: Consumer Call: Cause: (1) Event: (0x20000004)."""
"00:00:02.571762940267","CSME","""[IPC_DRV] ipc_drv_evt_cb: event_grp = 2 evt_id 4"""
{...}
[18:53:37] [INFO    ] [TRACE   ] Stopping capture...
[18:53:39] [INFO    ] [TRACE   ] Processing time: 64s - 449 packets/second
[18:53:39] [INFO    ] [TRACE   ] Waiting for the live output session to complete...
[18:53:39] [INFO    ] [TRACE   ] No more incoming messages: 29818 matches found
[18:53:39] [INFO    ] [TRACE   ] Live output session completed
[18:53:39] [INFO    ] [TRACE   ] CaptureStatus.done

Output is shorten with {…} to only show some of the relevant parts.

Redirect outputs of captured traces

Both messages and logs can be independently redirected. This could be use to pipe the messages to another program for analysis while the CLI logs are saved to a file.

Here both outputs are redirected to files:

$ intel_systrace capture-live-preview 1> out.csv 2> log.txt

out.csv

"Time","Source","Summary"
"00:00:02.570434190267","CSME","""[HECI1] Power state changed: Entering CM0-PG! pg_override_mask:0x00000000"""
"00:00:02.570436690267","CSME","""[HECI1] heci_read_csr(): Read 0x80020209 from HECI1_CSE_CSR."""
"00:00:02.570439639486","CSME","""[HECI1] heci_set_we(): Read 0x00000000 and wrote 0x00000001 (HECI1_WE)"""
"00:00:02.570458406575","CSME","""pci_cfg_set_pme(): device id HW_DEV_ID_HECI1(0), sel 0x3f, enable 1"""
"00:00:02.571274047038","CSME","""[ED] ReceiveNotifyConsumer: Consumer Call: Cause: (1) Event: (0x20000004)."""
"00:00:02.571679015299","CSME","""[ED] ReceiveNotifyConsumer: Consumer Call: Cause: (1) Event: (0x20000004)."""
"00:00:02.571762940267","CSME","""[IPC_DRV] ipc_drv_evt_cb: event_grp = 2 evt_id 4"""
{...}

log.txt

{...}
[18:52:30] [INFO    ] [TCA     ] Detected Meteor Lake P
{...}
[18:52:34] [INFO    ] [TRACE   ] Streaming session startup succeeded
{...}
[18:53:37] [INFO    ] [TRACE   ] Stopping capture...
[18:53:39] [INFO    ] [TRACE   ] Processing time: 64s - 449 packets/second
[18:53:39] [INFO    ] [TRACE   ] Waiting for the live output session to complete...
[18:53:39] [INFO    ] [TRACE   ] No more incoming messages: 29818 matches found
[18:53:39] [INFO    ] [TRACE   ] Live output session completed
[18:53:39] [INFO    ] [TRACE   ] CaptureStatus.done

Output is shorten with {…} to only show some of the relevant parts.