From 49ce733a30d29c819e2ab57dbe758f272e09da7a Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Sebastian=20G=C5=82=C4=85b?= Date: Tue, 14 Jan 2025 13:40:39 +0100 Subject: [PATCH] Revert "[nrf fromtree] samples: boards: nordic: coresight_stm: Test STM dictionary mode" This reverts commit fa58e795d190daf173dbda0f61d195a49bd26a3a. --- .../boards/nordic/coresight_stm/README.rst | 102 ------- .../nordic/coresight_stm/pytest/test_stm.py | 258 ------------------ .../boards/nordic/coresight_stm/sample.yaml | 44 +-- 3 files changed, 24 insertions(+), 380 deletions(-) delete mode 100644 samples/boards/nordic/coresight_stm/README.rst delete mode 100644 samples/boards/nordic/coresight_stm/pytest/test_stm.py diff --git a/samples/boards/nordic/coresight_stm/README.rst b/samples/boards/nordic/coresight_stm/README.rst deleted file mode 100644 index 370253cf41c..00000000000 --- a/samples/boards/nordic/coresight_stm/README.rst +++ /dev/null @@ -1,102 +0,0 @@ -.. zephyr:code-sample:: coresight_stm_sample - :name: Coresight STM benchmark - :relevant-api: log_api - -Overview -******** - -This sample presents how to enable STM logging on nRF54H20 platform. - -Also, it prints timing for different log messages. -Thus, performance of different loggers can be compared. - -There are three sample configurations in the :file:`sample.yaml`. - -* **sample.boards.nrf.coresight_stm.local_uart** - - This configuration doesn't use STM. - Logs are printed on local console. - -* **sample.boards.nrf.coresight_stm** - - This configuration use STM. - Application, Radio, PPR and FLPR cores send logs to an ETR buffer. - Proxy (Application core) gets logs from the ETR buffer, decodes STPv2 data - and prints human readable logs on UART. - -* **sample.boards.nrf.coresight_stm.dict** - - This sample uses STM logging in dictionary mode. - Application, Radio, PPR and FLPR cores send logs to the ETR buffer. - Proxy (Application core) forwards data from the ETR to the host using UART. - Host tool is needed to decode the logs. - -Requirements -************ - -This application uses nRF54H20 DK board for the demo. - -**sample.boards.nrf.coresight_stm.dict** requires host tool like ``nrfutil trace`` -to decode the traces. - -Building and running -******************** - -To build the sample, use configuration setups from the :file:`sample.yaml` using the ``-T`` option. -See the example: - -nRF54H20 DK - - .. code-block:: console - - west build -p -b nrf54h20dk/nrf54h20/cpuapp -T sample.boards.nrf.coresight_stm . - -Sample Output -============= - -.. code-block:: console - - *** Using Zephyr OS v3.6.99-5bb7bb0af17c *** - (...) - [00:00:00.227,264] app/app: test with one argument 100 - [00:00:00.227,265] app/app: test with one argument 100 - (...) - [00:00:00.585,558] rad/app: test with one argument 100 - [00:00:00.585,569] rad/app: test with one argument 100 - (...) - [00:00:00.624,408] ppr/app: test with one argument 100 - [00:00:00.624,433] ppr/app: test with one argument 100 - (...) - [00:00:00.625,249] flpr/app: test with one argument 100 - [00:00:00.625,251] flpr/app: test with one argument 100 - (...) - rad: Timing for log message with 0 arguments: 5.10us - rad: Timing for log message with 1 argument: 6.10us - rad: Timing for log message with 2 arguments: 6.0us - rad: Timing for log message with 3 arguments: 6.40us - rad: Timing for log_message with string: 7.10us - rad: Timing for tracepoint: 0.5us - rad: Timing for tracepoint_d32: 0.5us - flpr: Timing for log message with 0 arguments: 1.20us - flpr: Timing for log message with 1 argument: 1.20us - flpr: Timing for log message with 2 arguments: 1.20us - flpr: Timing for log message with 3 arguments: 1.30us - flpr: Timing for log_message with string: 3.0us - flpr: Timing for tracepoint: 0.0us - flpr: Timing for tracepoint_d32: 0.0us - app: Timing for log message with 0 arguments: 1.80us - app: Timing for log message with 1 argument: 2.0us - app: Timing for log message with 2 arguments: 2.0us - app: Timing for log message with 3 arguments: 2.10us - app: Timing for log_message with string: 4.40us - app: Timing for tracepoint: 0.10us - app: Timing for tracepoint_d32: 0.10us - ppr: Timing for log message with 0 arguments: 25.20us - ppr: Timing for log message with 1 argument: 26.20us - ppr: Timing for log message with 2 arguments: 26.90us - ppr: Timing for log message with 3 arguments: 27.40us - ppr: Timing for log_message with string: 64.80us - ppr: Timing for tracepoint: 0.30us - ppr: Timing for tracepoint_d32: 0.25us - -For logging on NRF54H20 using ARM Coresight STM see :ref:`logging_cs_stm`. diff --git a/samples/boards/nordic/coresight_stm/pytest/test_stm.py b/samples/boards/nordic/coresight_stm/pytest/test_stm.py deleted file mode 100644 index 2187805f15f..00000000000 --- a/samples/boards/nordic/coresight_stm/pytest/test_stm.py +++ /dev/null @@ -1,258 +0,0 @@ -# -# Copyright (c) 2024 Nordic Semiconductor ASA -# -# SPDX-License-Identifier: Apache-2.0 -# - -import logging -import re -import subprocess -from pathlib import Path -from time import sleep - -import psutil -from twister_harness import DeviceAdapter - -logger = logging.getLogger(__name__) - -SB_CONFIG_APP_CPUPPR_RUN = None -SB_CONFIG_APP_CPUFLPR_RUN = None - -# https://github.com/zephyrproject-rtos/zephyr/blob/main/drivers/misc/coresight/nrf_etr.c#L102 -STM_M_ID = { - "sec": 33, - "app": 34, - "rad": 35, - "mod": 36, - "sys": 44, - "flpr": 45, - "ppr": 46, - "hw": 128, -} - - -def _analyse_autoconf(filepath: str) -> None: - global SB_CONFIG_APP_CPUPPR_RUN - global SB_CONFIG_APP_CPUFLPR_RUN - - SB_CONFIG_APP_CPUPPR_RUN = False - SB_CONFIG_APP_CPUFLPR_RUN = False - - # Parse contents of {BUILD_DIR}/_sysbuild/autoconf.h - with open(f"{filepath}", errors="ignore") as autoconf: - for line in autoconf: - if "SB_CONFIG_APP_CPUPPR_RUN 1" in line: - SB_CONFIG_APP_CPUPPR_RUN = True - continue - if "SB_CONFIG_APP_CPUFLPR_RUN 1" in line: - SB_CONFIG_APP_CPUFLPR_RUN = True - logger.debug(f"{SB_CONFIG_APP_CPUPPR_RUN=}") - logger.debug(f"{SB_CONFIG_APP_CPUFLPR_RUN=}") - - -def _check_benchmark_results(output: str, core: str) -> None: - """ - Use regular expressions to parse 'output' string. - Search for benchmark results related to 'core' coprocessor. - """ - - latency_msg_0_str = re.search( - rf"{core}: Timing for log message with 0 arguments: (.+)us", output - ).group(1) - assert latency_msg_0_str is not None, "Timing for log message with 0 arguments NOT found" - - latency_msg_1_str = re.search( - rf"{core}: Timing for log message with 1 argument: (.+)us", output - ).group(1) - assert latency_msg_1_str is not None, "Timing for log message with 1 argument NOT found" - - latency_msg_2_str = re.search( - rf"{core}: Timing for log message with 2 arguments: (.+)us", output - ).group(1) - assert latency_msg_2_str is not None, "Timing for log message with 2 arguments NOT found" - - latency_msg_3_str = re.search( - rf"{core}: Timing for log message with 3 arguments: (.+)us", output - ).group(1) - assert latency_msg_3_str is not None, "Timing for log message with 3 arguments NOT found" - - latency_msg_string_str = re.search( - rf"{core}: Timing for log_message with string: (.+)us", output - ).group(1) - assert latency_msg_string_str is not None, "Timing for log_message with string NOT found" - - latency_tracepoint_str = re.search( - rf"{core}: Timing for tracepoint: (.+)us", output - ).group(1) - assert latency_tracepoint_str is not None, "Timing for tracepoint NOT found" - - latency_tracepoint_d32_str = re.search( - rf"{core}: Timing for tracepoint_d32: (.+)us", output - ).group(1) - assert latency_tracepoint_d32_str is not None, "Timing for tracepoint_d32 NOT found" - - -# nrfutil starts children processes -# when subprocess.terminate(nrfutil_process) is executed, only the parent terminates -# this blocks serial port for other uses -def _kill(proc): - try: - for child in psutil.Process(proc.pid).children(recursive=True): - child.kill() - proc.kill() - except Exception as e: - logger.exception(f'Could not kill nrfutil - {e}') - - -def _nrfutil_dictionary_from_serial( - dut: DeviceAdapter, - decoded_file_name: str = "output.txt", - collect_time: float = 60.0, -) -> None: - UART_PATH = dut.device_config.serial - UART_BAUDRATE = dut.device_config.baud - dut.close() - - logger.debug(f"Using serial: {UART_PATH}") - - if Path(f"{decoded_file_name}").exists(): - logger.warning("Output file already exists!") - - # prepare database config string - BUILD_DIR = str(dut.device_config.build_dir) - logger.debug(f"{BUILD_DIR=}") - config_str = f"{STM_M_ID['app']}:{BUILD_DIR}/coresight_stm/zephyr/log_dictionary.json" - config_str = config_str + f",{STM_M_ID['rad']}:{BUILD_DIR}/remote_rad/zephyr/log_dictionary.json" - if SB_CONFIG_APP_CPUPPR_RUN: - config_str = config_str + f",{STM_M_ID['ppr']}:{BUILD_DIR}/remote_ppr/zephyr/log_dictionary.json" - if SB_CONFIG_APP_CPUFLPR_RUN: - config_str = config_str + f",{STM_M_ID['flpr']}:{BUILD_DIR}/remote_flpr/zephyr/log_dictionary.json" - logger.debug(f"{config_str=}") - - cmd = ( - "nrfutil trace stm --database-config " - f"{config_str} " - f"--input-serialport {UART_PATH} --baudrate {UART_BAUDRATE} " - f"--output-ascii {decoded_file_name}" - ) - try: - # run nrfutil trace in background non-blocking - logger.info(f"Executing:\n{cmd}") - proc = subprocess.Popen(cmd.split(), stdout=subprocess.DEVNULL) - except OSError as exc: - logger.error(f"Unable to start nrfutil trace:\n{cmd}\n{exc}") - try: - proc.wait(collect_time) - except subprocess.TimeoutExpired: - pass - finally: - _kill(proc) - - -def test_STM_decoded(dut: DeviceAdapter): - """ - Run sample.boards.nrf.coresight_stm from samples/boards/nrf/coresight_stm sample. - Both Application and Radio cores use STM for logging. - STM proxy (Application core) decodes logs from all domains. - After reset, coprocessors execute code in expected way and Application core - outputs STM traces on UART port. - """ - BUILD_DIR = str(dut.device_config.build_dir) - autoconf_file = f"{BUILD_DIR}/_sysbuild/autoconf.h" - - # nrf54h20 prints immediately after it is flashed. - # Wait a bit to skipp logs from previous test. - sleep(4) - - # Get output from serial port - output = "\n".join(dut.readlines()) - - # set SB_CONFIG_APP_CPUPPR_RUN, SB_CONFIG_APP_CPUFLPR_RUN - _analyse_autoconf(autoconf_file) - - # check that LOGs from Application core are present - _check_benchmark_results( - output=output, - core='app', - ) - - # check that LOGs from Radio core are present - _check_benchmark_results( - output=output, - core='rad', - ) - - if SB_CONFIG_APP_CPUPPR_RUN: - # check that LOGs from PPR core are present - _check_benchmark_results( - output=output, - core='ppr', - ) - - if SB_CONFIG_APP_CPUFLPR_RUN: - # check that LOGs from FLPR core are present - _check_benchmark_results( - output=output, - core='flpr', - ) - - -def test_STM_dictionary_mode(dut: DeviceAdapter): - """ - Run sample.boards.nrf.coresight_stm.dict from samples/boards/nrf/coresight_stm sample. - Both Application and Radio cores use STM for logging. - STM proxy (Application core) prints on serial port raw logs from all domains. - Nrfutil trace is used to decode STM logs. - After reset, coprocessors execute code in expected way and Application core - outputs STM traces on UART port. - """ - BUILD_DIR = str(dut.device_config.build_dir) - test_filename = f"{BUILD_DIR}/coresight_stm_dictionary.txt" - autoconf_file = f"{BUILD_DIR}/_sysbuild/autoconf.h" - COLLECT_TIMEOUT = 10.0 - - # set SB_CONFIG_APP_CPUPPR_RUN, SB_CONFIG_APP_CPUFLPR_RUN - # this information is needed to build nrfutil database-config - _analyse_autoconf(autoconf_file) - - # use nrfutil trace to decode logs - _nrfutil_dictionary_from_serial( - dut=dut, - decoded_file_name=f"{test_filename}", - collect_time=COLLECT_TIMEOUT, - ) - - # read decoded logs - with open(f"{test_filename}", errors="ignore") as decoded_file: - decoded_file_content = decoded_file.read() - - # if nothing in decoded_file, stop test - assert( - len(decoded_file_content) > 0 - ), f"File {test_filename} is empty" - - # check that LOGs from Application core are present - _check_benchmark_results( - output=decoded_file_content, - core='app', - ) - - # check that LOGs from Radio core are present - _check_benchmark_results( - output=decoded_file_content, - core='rad', - ) - - if SB_CONFIG_APP_CPUPPR_RUN: - # check that LOGs from PPR core are present - _check_benchmark_results( - output=decoded_file_content, - core='ppr', - ) - - if SB_CONFIG_APP_CPUFLPR_RUN: - # check that LOGs from FLPR core are present - _check_benchmark_results( - output=decoded_file_content, - core='flpr', - ) diff --git a/samples/boards/nordic/coresight_stm/sample.yaml b/samples/boards/nordic/coresight_stm/sample.yaml index 4251c5d6df8..eb3971a2f4e 100644 --- a/samples/boards/nordic/coresight_stm/sample.yaml +++ b/samples/boards/nordic/coresight_stm/sample.yaml @@ -1,40 +1,44 @@ sample: name: Logging using Coresight STM on nrf54h20 - common: - tags: stm sysbuild: true - platform_allow: - - nrf54h20dk/nrf54h20/cpuapp - integration_platforms: - - nrf54h20dk/nrf54h20/cpuapp - tests: sample.boards.nrf.coresight_stm.dict: - harness: pytest - harness_config: - pytest_dut_scope: session - pytest_root: - - "pytest/test_stm.py::test_STM_dictionary_mode" + platform_allow: + - nrf54h20dk/nrf54h20/cpuapp + integration_platforms: + - nrf54h20dk/nrf54h20/cpuapp + build_only: true required_snippets: - nordic-log-stm-dict extra_args: - SB_CONFIG_APP_CPUPPR_RUN=y - SB_CONFIG_APP_CPUFLPR_RUN=y - sample.boards.nrf.coresight_stm: - harness: pytest + platform_allow: + - nrf54h20dk/nrf54h20/cpuapp + integration_platforms: + - nrf54h20dk/nrf54h20/cpuapp + harness: console harness_config: - pytest_dut_scope: session - pytest_root: - - "pytest/test_stm.py::test_STM_decoded" - required_snippets: - - nordic-log-stm + type: multi_line + ordered: true + regex: + - "Timing for log message with 0 arguments:" + - "Timing for log message with 1 argument:" + - "Timing for log message with 2 arguments:" + - "Timing for log message with 3 arguments:" + - "Timing for log_message with string:" extra_args: - SB_CONFIG_APP_CPUPPR_RUN=y - SB_CONFIG_APP_CPUFLPR_RUN=y - + required_snippets: + - nordic-log-stm sample.boards.nrf.coresight_stm.local_uart: + platform_allow: + - nrf54h20dk/nrf54h20/cpuapp + integration_platforms: + - nrf54h20dk/nrf54h20/cpuapp harness: console harness_config: type: multi_line