From baf651f4bd82725d948e42790197ec0a63d7fcc8 Mon Sep 17 00:00:00 2001 From: Kai Vehmanen Date: Mon, 28 Sep 2026 12:39:45 +0300 Subject: [PATCH 1/4] docs: developer_guides: update traces guide to use mtrace-reader.py Replace references to the sof-logger and smex tools with documentation for mtrace-reader.py. Highlight that SOF uses the Zephyr logging subsystem and that any Zephyr backend can be used to transport logs; mtrace-reader.py is the Intel ADSP-specific backend, while other hardware platforms use their own logging mechanisms. Document how to acquire mtrace-reader.py from the SOF main repository (tools/mtrace/mtrace-reader.py), how to run it locally and on a remote DUT over SSH, and how to enable the mtrace backend via the snd_sof kernel module parameter sof_debug=SOF_DBG_ENABLE_TRACE (0x1). Signed-off-by: Kai Vehmanen --- .../debugability/traces/index.rst | 169 ++++++++++++------ 1 file changed, 110 insertions(+), 59 deletions(-) diff --git a/developer_guides/debugability/traces/index.rst b/developer_guides/debugability/traces/index.rst index 207b035f..e3476137 100644 --- a/developer_guides/debugability/traces/index.rst +++ b/developer_guides/debugability/traces/index.rst @@ -3,7 +3,7 @@ DSP Telemetry, Logging & Traces ############################### -Sound Open Firmware (SOF) features a high-performance, asynchronous logging and telemetry infrastructure designed specifically for hard real-time embedded audio DSPs. Because audio signal processing operates on strict sub-millisecond scheduling deadlines (e.g. 1 ms or 200 µs periods), DSP firmware cannot block on slow UART serial writes or synchronous host communications. Instead, SOF combines compile-time string dictionary extraction (**smex**), hardware DMA circular buffers, native Zephyr RTOS structured logging, and network-accessible telemetry servers. +Sound Open Firmware (SOF) uses the **Zephyr RTOS logging subsystem** as its firmware logging infrastructure. Because audio signal processing operates on strict sub-millisecond scheduling deadlines (e.g. 1 ms or 200 µs periods), DSP firmware cannot block on slow UART serial writes or synchronous host communications. Instead, SOF firmware emits log entries through Zephyr's logging API, and the active **Zephyr logging backend** determines how those entries are transported to the host. Different hardware platforms use different backends: on Intel ADSPs, the ``mtrace-reader.py`` tool reads logs from the hardware ``mtrace`` buffer; on other platforms, different host-side utilities or transport mechanisms apply. .. figure:: images/dsp_telemetry_architecture.svg :alt: Sound Open Firmware DSP Telemetry, Logging and Trace Architecture @@ -21,7 +21,7 @@ The SOF logging infrastructure is split into three decoupled operational stages: 1. **Build-Time Dictionary Extraction**: C source strings and format specifications are stripped from the target executable and saved into an external Log Dictionary Catalog (``.ldc``), embedding only 32-bit metadata IDs into the firmware binary. 2. **Runtime Execution & Autonomous DMA**: The DSP core writes fixed-size binary trace packets into an internal SRAM circular ring buffer. A dedicated background hardware DMA channel transfers trace chunks to a shared host memory window without stalling audio pipeline processing loops. -3. **Host-Side Ingestion & Real-Time Decoding**: The host Linux kernel exposes binary trace buffers via ``debugfs``, and user-space utilities (``sof-logger``, ``sof_probe_server``) decode entry IDs against the ``.ldc`` dictionary in real time. +3. **Host-Side Ingestion & Real-Time Decoding**: A Zephyr logging backend transports log entries from the DSP to the host. The backend is hardware-specific: on Intel ADSPs the ``mtrace-reader.py`` utility reads from the hardware ``mtrace`` buffer; other platforms rely on their own transport mechanisms. --- @@ -78,23 +78,6 @@ SOF utilizes four standard log levels mapped directly to Zephyr severity ratings --- -Compile-Time String Extraction with smex -**************************************** - -To minimize the DSP memory footprint and avoid transmitting bulky ASCII text across memory buses, SOF employs the **smex** (String Metadata Extractor) build tool: - -1. **Linker Placement**: String literals, filenames, line numbers, and printf format arguments in ``LOG_*`` invocations are placed in a dedicated read-only section (``.static_log_entries``) of the ELF binary. -2. **Metadata Harvesting**: During the firmware build, ``smex`` parses the ``.static_log_entries`` section of ``zephyr.elf``: - - .. code-block:: bash - - smex -l build/sof-tgl.ldc -e build/zephyr/zephyr.elf - -3. **Dictionary Catalog (``.ldc``)**: ``smex`` extracts format strings and argument typing into the ``.ldc`` catalog file. In the binary firmware image (``.ri`` / ``.bin``), the compiler and linker emit compact 32-bit integer entry IDs. -4. **Footprint Reduction**: This reduces firmware binary size by 40–70% and reduces DSP trace logging execution to approximately 10–20 clock cycles per event. - ---- - Runtime DSP Trace DMA Engine **************************** @@ -116,34 +99,11 @@ At runtime, logging operations must never interrupt audio pipelines executing on | [ DMA Position IPC ] -> Host Driver Interrupt -> [ Linux debugfs trace]| +-------------------------------------------------------------------------+ -Trace Packet Structure -====================== - -Each binary trace entry emitted into the internal SRAM circular buffer contains a packed binary header: - -.. code-block:: c - - struct sof_log_entry { - uint64_t timestamp; /**< Hardware DSP timer tick count */ - uint32_t log_entry_id; /**< 32-bit metadata ID resolved via .ldc catalog */ - uint32_t params[4]; /**< Up to 4 runtime 32-bit format arguments */ - } __attribute__((packed)); - -Autonomous Background Transfer -============================== - -* **Lockless Ring Buffer**: The internal trace buffer (typically 8 KB or 16 KB) operates locklessly. Audio processing threads append trace packets using atomic pointer operations without acquiring mutexes or disabling interrupts. -* **Trace DMA Controller**: A background hardware DMA channel transfers accumulated trace chunks to host shared memory (SRAM Window 3 on Intel cAVS/ACE architectures). -* **Watermark Triggering**: When the buffer reaches its configured watermark threshold or a periodic timer fires, the DMA burst executes autonomously without DSP CPU polling. -* **Trace Position IPC**: The DSP notifies the host kernel of newly available trace data by posting an asynchronous ``SOF_IPC_TRACE_DMA_POSITION`` message containing the write pointer offset. - ---- - Host-Side Ingestion & Decoding ****************************** -Linux Kernel debugfs Trace Node -=============================== +Linux Kernel debugfs Trace Node (IPC3) +====================================== On Linux hosts with the mainline SOF driver loaded, the raw binary trace buffer is exposed via ``debugfs``: @@ -171,10 +131,103 @@ When enabled, the driver automatically allocates extraction DMA channels during --- -Using sof-logger -**************** +Intel ADSP: Using mtrace-reader.py +********************************** + +On Intel ADSP hardware, the Zephyr logging backend forwards log entries through the +hardware ``mtrace`` buffer. The ``mtrace-reader.py`` script reads from that buffer on the +host and prints decoded messages to standard output. On non-Intel platforms, consult the +platform-specific documentation for the applicable logging backend and host-side tooling. + +``mtrace-reader.py`` is available in the SOF main repository at +`tools/mtrace/mtrace-reader.py `_. + +Enabling mtrace in the Linux SOF Driver +======================================== -The ``sof-logger`` host utility reads the binary trace stream, resolves metadata entry IDs using the ``.ldc`` catalog, and prints formatted messages with microsecond-accurate timestamps: +Before ``mtrace-reader.py`` can receive logs, the Linux SOF driver must be instructed to +program the firmware to emit logs via the ``mtrace`` backend. The ``sof_debug`` ``snd_sof`` kernel module parameter is a bitmask; setting +``SOF_DBG_ENABLE_TRACE`` (``0x1``) instructs the driver to program the firmware to enable +log output through the ``mtrace`` buffer. + +.. code-block:: bash + + sudo modprobe snd_sof sof_debug=1 + +Acquiring mtrace-reader.py +=========================== + +The recommended way to obtain the script is from the SOF main repository: + +.. code-block:: bash + + # Clone the SOF repository and locate the script + git clone https://github.com/thesofproject/sof.git + ls sof/tools/mtrace/mtrace-reader.py + + # Or download the script directly + wget https://raw.githubusercontent.com/thesofproject/sof/main/tools/mtrace/mtrace-reader.py + +Live Continuous Streaming +========================= + +Run ``mtrace-reader.py`` on the target system to stream firmware log output continuously: + +.. code-block:: bash + + # Stream live firmware traces from the mtrace buffer + python3 mtrace-reader.py + +Saving Trace Output to a File +============================== + +Redirect standard output to capture a trace log for offline analysis: + +.. code-block:: bash + + # Capture trace output to a file + python3 mtrace-reader.py > /tmp/fw_mtrace.log + +Running on a Remote DUT +======================== + +On remote hardware test stations accessed over SSH, launch ``mtrace-reader.py`` in the +background before starting the audio test: + +.. code-block:: bash + + # Copy script to DUT (if not already present) + scp sof/tools/mtrace/mtrace-reader.py root@:/tmp/ + + # Start mtrace reader on DUT prior to test execution + timeout 15 ssh -o ConnectTimeout=5 root@ \ + 'nohup python3 /tmp/mtrace-reader.py > /tmp/fw_mtrace.log 2>&1 &' + + # Execute test audio pipeline + timeout 30 ssh -o ConnectTimeout=5 root@ \ + 'aplay -D hw:0 -r 48000 -c 2 -f S16_LE /dev/zero -d 5' + + # Retrieve formatted trace log from DUT + scp root@:/tmp/fw_mtrace.log ./fw_mtrace.log + + # Terminate reader + timeout 15 ssh -o ConnectTimeout=5 root@ 'pkill -f mtrace-reader' + +--- + +Legacy: Using sof-logger (non-Zephyr SOF firmware only) +******************************************************** + +.. note:: + + ``sof-logger`` is only applicable to older SOF firmware versions that do **not** use the + Zephyr RTOS. On Intel ADSPs, **Meteor Lake and all newer platforms are exclusively + supported by Zephyr-based SOF firmware**; ``sof-logger`` cannot be used on those + platforms. For current platforms, use ``mtrace-reader.py`` as documented above. + +The ``sof-logger`` host utility reads the binary trace stream from ``debugfs``, resolves +metadata entry IDs using the ``.ldc`` catalog, and prints formatted messages with +microsecond-accurate timestamps: Live Continuous Streaming ========================= @@ -185,7 +238,7 @@ Live Continuous Streaming sof-logger -t -l /lib/firmware/intel/sof-ipc4/tgl/community/sof-tgl.ldc Offline Binary Trace Decoding -============================= +============================== If a binary trace dump was captured during an automated test run or hardware crash: @@ -224,7 +277,7 @@ Command-Line Options Network Probe Server Streaming (Port 9999) ****************************************** -On remote development and automated validation setups (DUTs), running ``sof-logger`` over SSH introduces significant network latency and terminal process overhead. SOF provides a high-throughput C streaming daemon—**``sof_probe_server``**—listening on TCP port **9999**: +On remote development and automated validation setups (DUTs), reading traces over SSH introduces significant network latency and terminal process overhead. SOF provides a high-throughput C streaming daemon—**``sof_probe_server``**—listening on TCP port **9999**: .. code-block:: text @@ -275,23 +328,21 @@ Troubleshooting & Diagnostics Trace Buffer Wraparound & Missing Entries ========================================= -* **Symptom**: ``sof-logger`` prints ``[DROPPED X ENTRIES]`` or non-sequential timestamps. +* **Symptom**: Non-sequential timestamps or apparent gaps in the decoded log output. * **Root Cause**: Host reader cannot consume trace DMA packets quickly enough during bursts of ``LOG_DBG`` calls, overflowing the internal SRAM buffer. * **Resolution**: 1. Filter out high-frequency debug logs by raising ``CONFIG_SOF_LOG_LEVEL`` to ``CONFIG_LOG_DEFAULT_LEVEL=3`` (INFO). 2. Increase internal trace buffer size in Kconfig: ``CONFIG_SOF_TRACE_BUF_SIZE=16384``. 3. Stream via ``sof_probe_server`` using its 1 MB host-side circular queue rather than reading directly through debugfs over SSH. -Dictionary Mismatch (Unresolved IDs) -==================================== - -* **Symptom**: ``sof-logger`` outputs ````. -* **Root Cause**: The ``.ldc`` dictionary supplied to ``sof-logger`` does not match the exact binary running on the DSP. -* **Resolution**: Ensure the ``.ldc`` file corresponds to the identical Git commit and build configuration: - - .. code-block:: bash +No Output from mtrace-reader.py +================================ - sof-logger -l build-sof-staging/sof/sof-tgl.ldc -t +* **Symptom**: ``mtrace-reader.py`` produces no output or exits immediately. +* **Root Cause**: The ``mtrace`` buffer is not active, or the DSP core is suspended in D0ix sleep. +* **Resolution**: + 1. Start an audio playback stream to bring the DSP into active D0 state: ``aplay -D hw:0 -r 48000 -c 2 -f S16_LE /dev/zero &``. + 2. Verify logging is enabled in kernel module: ``modprobe snd-sof sof_debug=1``. Zero Data from debugfs Node =========================== From befe0eea826632c644529e207aee7c71903f23a6 Mon Sep 17 00:00:00 2001 From: Kai Vehmanen Date: Mon, 28 Sep 2026 12:41:56 +0300 Subject: [PATCH 2/4] docs: developer_guides: update telemetry arch, remove sof-logger/smex Remove references to sof-logger and smex from the DSP telemetry architecture diagram. These are only used in older SOF releases. Update the subtitle and section titles to reflect the Zephyr logging subsystem and mtrace backend, which are the most common tools used with new SOF releases. Replace the smex card with a generic build-time metadata extraction description, and replace the sof-logger decoder card with mtrace-reader.py for Intel ADSP, including the sof_debug=1 modprobe enable step. Signed-off-by: Kai Vehmanen --- .../images/dsp_telemetry_architecture.svg | 20 +++++++++---------- 1 file changed, 10 insertions(+), 10 deletions(-) diff --git a/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg b/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg index 2fb8a1d7..1f5acda7 100644 --- a/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg +++ b/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg @@ -68,7 +68,7 @@ Figure 329: Sound Open Firmware (SOF) DSP Telemetry, Logging & Trace Streaming Architecture - Asynchronous Zero-Overhead Logging: Build-Time smex Extraction, Trace DMA Ring Buffers & TCP Probe Server (Port 9999) + Asynchronous Zero-Overhead Logging: Zephyr Logging Subsystem, Trace DMA Ring Buffers & mtrace Backend (Intel ADSP) @@ -78,7 +78,7 @@ - 1. Build-Time String Extraction & Metadata Catalog Pipeline (smex) + 1. Build-Time String Extraction & Metadata Catalog Pipeline @@ -94,9 +94,9 @@ - smex Metadata Extraction Tool - smex -l sof-tgl.ldc -e build/zephyr.elf - Extracts catalog (.ldc); embeds 32-bit entry IDs in FW + Build-Time Metadata Extraction + Generates Log Dictionary Catalog (.ldc) + Strips format strings from FW binary; embeds 32-bit entry IDs @@ -161,7 +161,7 @@ - 2B. Linux Driver Ingestion & sof-logger Decoding + 2B. Linux Driver Ingestion & Host-Side Log Decoding @@ -178,10 +178,10 @@ - sof-logger Binary Trace Decoder - sof-logger -t -d /path/to/sof-tgl.ldc -l /sys/.../trace - Resolves entry ID -> source file, line, function, printf format - Live streaming (-t), file dump (-i/-o), timestamp sync + mtrace-reader.py (Intel ADSP) + python3 mtrace-reader.py > /tmp/fw_mtrace.log + Reads firmware logs from hardware mtrace buffer + Enable with: modprobe snd_sof sof_debug=1 From 54bacca25e88a548d3d794c3a67384e97bc4473d Mon Sep 17 00:00:00 2001 From: Kai Vehmanen Date: Mon, 28 Sep 2026 12:57:29 +0300 Subject: [PATCH 3/4] docs: developer_guides: replace .ldc dictionary with Zephyr log dict Replace the build-time Log Dictionary Catalog (.ldc) description with a reference to the Zephyr logging dictionary (log_dictionary.json). Clarify that the dictionary is optional and is not required for basic log streaming with mtrace-reader.py. Point to the Zephyr documentation for details on dictionary-based logging. Update the architecture SVG accordingly. Signed-off-by: Kai Vehmanen --- developer_guides/debugability/index.rst | 6 +++--- .../traces/images/dsp_telemetry_architecture.svg | 4 ++-- developer_guides/debugability/traces/index.rst | 7 ++++++- 3 files changed, 11 insertions(+), 6 deletions(-) diff --git a/developer_guides/debugability/index.rst b/developer_guides/debugability/index.rst index bb1a1ff7..3c5d3e6b 100644 --- a/developer_guides/debugability/index.rst +++ b/developer_guides/debugability/index.rst @@ -8,7 +8,7 @@ Sound Open Firmware (SOF) provides an asynchronous, zero-overhead diagnostic and To provide continuous visibility into the firmware runtime without compromising acoustic deadlines, SOF decouples event generation from data transmission through a multi-tier observability stack: -* **Compile-Time String Metadata Extraction (:ref:`dbg-traces`)**: Format strings and filenames are stripped from the firmware binary by the ``smex`` tool into an external dictionary file (``.ldc``), leaving compact 32-bit entry IDs and packed arguments in firmware text. +* **Compile-Time String Metadata Extraction (:ref:`dbg-traces`)**: SOF uses the Zephyr logging dictionary * **Autonomous Hardware Trace DMA**: Log entries and performance metrics are written to high-speed internal SRAM circular buffers and transferred to host memory windows by background DMA engines without CPU intervention. * **Network-Accessible Telemetry Server (:ref:`dbg-probes`)**: High-throughput daemon (``sof_probe_server``) streaming live trace DMA packets over TCP port ``9999`` to remote development clients and the multi-pane ``dut-monitor`` dashboard. * **Zero-Allocation Fatal Crash Preservation (:ref:`dbg-coredump-reader`)**: Dedicated hardware memory window backends preserve CPU register windows, call stacks, and exception causes upon fatal CPU traps for GDB post-mortem backtrace analysis. @@ -23,7 +23,7 @@ To provide continuous visibility into the firmware runtime without compromising - Host Ingestion Interface - Primary Use Case & Capabilities * - **DSP Traces & Telemetry** - - Compile-time ``smex`` extraction, Zephyr logging, internal SRAM ring buffers, background trace DMA. + - Compile-time dictionary extraction, Zephyr logging, internal SRAM ring buffers, background trace DMA. - Linux kernel debugfs (``/sys/kernel/debug/sof/trace``) & ``sof-logger``. - Real-time event tracing, state transition verification, microsecond timing benchmarks, module logging. * - **Crash Diagnostics & Coredump** @@ -90,7 +90,7 @@ Select the appropriate diagnostic tool based on the observed system behavior: For dedicated specifications, architectural deep-dives, and step-by-step developer runbooks for each observability subsystem, refer to the individual guides in the :ref:`telemetry_diagnostics_pillar`: - * :ref:`dbg-traces`: Compile-time dictionary extraction, lockless trace DMA buffers, and live ``sof-logger`` decoding. + * :ref:`dbg-traces`: Compile-time dictionary extraction, lockless trace DMA buffers, and log decoding. * :ref:`dbg-coredump-reader`: Native Zephyr RTOS coredump, memory window register preservation, and interactive GDB backtrace analysis. * :ref:`dbg-probes`: Dynamic audio buffer probe points, ALSA Compress Offload (``crecord``), and high-throughput TCP probe server (port 9999). * :ref:`dbg-zephyr-shell`: Zero-IPC interactive Zephyr memory window shell, ``cavstool.py`` terminal bridge, and thread/stack monitoring. diff --git a/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg b/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg index 1f5acda7..9dc972b0 100644 --- a/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg +++ b/developer_guides/debugability/traces/images/dsp_telemetry_architecture.svg @@ -95,8 +95,8 @@ Build-Time Metadata Extraction - Generates Log Dictionary Catalog (.ldc) - Strips format strings from FW binary; embeds 32-bit entry IDs + Generates log_dictionary.json (optional) + Zephyr log dictionary; maps entry IDs to source strings diff --git a/developer_guides/debugability/traces/index.rst b/developer_guides/debugability/traces/index.rst index e3476137..33bd5c65 100644 --- a/developer_guides/debugability/traces/index.rst +++ b/developer_guides/debugability/traces/index.rst @@ -19,7 +19,12 @@ Architecture Overview The SOF logging infrastructure is split into three decoupled operational stages: -1. **Build-Time Dictionary Extraction**: C source strings and format specifications are stripped from the target executable and saved into an external Log Dictionary Catalog (``.ldc``), embedding only 32-bit metadata IDs into the firmware binary. +1. **Build-Time Log Dictionary (Optional)**: SOF uses the `Zephyr logging dictionary + `_ + (``log_dictionary.json``) produced during the firmware build. The dictionary maps compact + binary log entry IDs back to their source strings, enabling offline decoding of captured + log data. Generating the dictionary is optional; it is not required for basic log + streaming with ``mtrace-reader.py``. 2. **Runtime Execution & Autonomous DMA**: The DSP core writes fixed-size binary trace packets into an internal SRAM circular ring buffer. A dedicated background hardware DMA channel transfers trace chunks to a shared host memory window without stalling audio pipeline processing loops. 3. **Host-Side Ingestion & Real-Time Decoding**: A Zephyr logging backend transports log entries from the DSP to the host. The backend is hardware-specific: on Intel ADSPs the ``mtrace-reader.py`` utility reads from the hardware ``mtrace`` buffer; other platforms rely on their own transport mechanisms. From 9976e7f0f16b2e07ea4f0a8d25b311fada0d7304 Mon Sep 17 00:00:00 2001 From: Kai Vehmanen Date: Mon, 28 Sep 2026 13:22:36 +0300 Subject: [PATCH 4/4] sof_bin_releases: update sof_bin_releases.json to 2026.09.1 Update sof_bin_releases.json to match latest release. Signed-off-by: Kai Vehmanen --- data/sof_bin_releases.json | 22 +++++++++++----------- 1 file changed, 11 insertions(+), 11 deletions(-) diff --git a/data/sof_bin_releases.json b/data/sof_bin_releases.json index e0f223c7..232937dc 100644 --- a/data/sof_bin_releases.json +++ b/data/sof_bin_releases.json @@ -1,4 +1,15 @@ [ + { + "tag_name": "v2026.09.1", + "name": "v2026.09.1", + "fw_version": "v2.15", + "published_at": "2026-09-23", + "html_url": "https://github.com/thesofproject/sof-bin/releases/tag/v2026.09.1", + "asset_name": "sof-bin-2026.09.1.tar.gz", + "asset_url": "https://github.com/thesofproject/sof-bin/releases/download/v2026.09.1/sof-bin-2026.09.1.tar.gz", + "asset_size_mb": 16.7, + "prerelease": false + }, { "tag_name": "v2026.09", "name": "v2026.09", @@ -119,16 +130,5 @@ "asset_url": "https://github.com/thesofproject/sof-bin/releases/download/v2024.09/sof-bin-2024.09.tar.gz", "asset_size_mb": 9.7, "prerelease": false - }, - { - "tag_name": "v2024.06", - "name": "v2024.06", - "fw_version": "v2.10", - "published_at": "2024-07-18", - "html_url": "https://github.com/thesofproject/sof-bin/releases/tag/v2024.06", - "asset_name": "sof-bin-2024.06.tar.gz", - "asset_url": "https://github.com/thesofproject/sof-bin/releases/download/v2024.06/sof-bin-2024.06.tar.gz", - "asset_size_mb": 9.4, - "prerelease": false } ] \ No newline at end of file