zephyr/samples/subsys/logging/syst
Anas Nashif b835b02136 tests: cleanup metadata and filtering
- Add integration_platforms to avoid excessive filtering
- Make sure integration platforms are actually part of the filter
- Fix some tags and test meta data

Signed-off-by: Anas Nashif <anas.nashif@intel.com>
2023-06-13 09:38:27 -04:00
..
boards sample: syst: Add intel_adsp_cavs support 2022-04-20 10:25:16 -04:00
src includes: prefer <zephyr/kernel.h> over <zephyr/zephyr.h> 2022-09-05 16:31:47 +02:00
CMakeLists.txt treewide: Use CONFIG_CPP instead of CONFIG_CPLUSPLUS 2023-01-13 17:42:55 -05:00
overlay_deferred.conf logging: Remove logging v1 from the logging 2022-06-16 10:51:15 -04:00
overlay_immediate.conf sample: syst: Add intel_adsp_cavs support 2022-04-20 10:25:16 -04:00
prj.conf sample: syst: Add intel_adsp_cavs support 2022-04-20 10:25:16 -04:00
README.rst samples: logging/syst: add README 2022-04-01 13:29:45 +02:00
sample.yaml tests: cleanup metadata and filtering 2023-06-13 09:38:27 -04:00

.. _samples_subsys_logging_syst:

MIPI Sys-T Logging Sample
#########################

.. contents:: Table of Contents
   :depth: 4
   :local:
   :backlinks: none

Building and Running
********************

This project outputs a few sample log messages in MIPI Sys-T format.
These Sys-T messages can be interpreted by a utility in
:file:`<workspace>/modules/debug/mipi-sys-t/printer/`.

Build the Sys-T Message Parser
==============================

.. code-block:: console

   cd <workspace>/modules/debug/mipi-sys-t/printer/
   mkdir build
   cd build
   cmake ../
   make

An newly built executable ``systprint`` can be found under
:file:`<workspace>/modules/debug/mipi-sys-t/printer/build`.

MIPI Sys-T Text Messages
========================

The Sys-T text messages are self contained strings that do not
require additional artifacts to process.

To build the sample printing text messages under ``qemu_x86``:

.. zephyr-app-commands::
   :zephyr-app: samples/subsys/logging/syst
   :host-os: unix
   :board: qemu_x86
   :goals: build
   :gen-args: -DCONFIG_LOG_BACKEND_SHOW_COLOR=n
   :compact:

Run the sample and capture the output in a text file:

.. code-block:: console

   west build -t run > /tmp/syst

Since the output is being directed to a text file, there will not be
any output printed on the terminal. So exit QEMU by pressing
:kbd:`CTRL+A` :kbd:`x`.

Sample Text Messages Output
---------------------------

The :file:`/tmp/syst` should contain something like this:

.. code-block:: text

   SeaBIOS (version zephyr-v1.0.0-0-g31d4e0e-dirty-20200714_234759-fv-az50-zephyr)
   Booting from ROM..SYS-T RAW DATA: 020A000B490000000000000000002A2A2A20426F6F74696E67205A6570687972204F53206275696C64202573202573202A2A2A0A007A65706879722D76332E302E302D323036372D673166623436343433333731650000
   SYS-T RAW DATA: 220A000B170001000000000000004572726F72206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 320A000B190001000000000000005761726E696E67206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 420A000B16000100000000000000496E666F206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 720A000B170001000000000000004465627567206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 720A000B1E0001000000000000004465627567206D657373616765206578616D706C652C2025640001000000
   SYS-T RAW DATA: 720A000B260001000000000000004465627567206D657373616765206578616D706C652C2025642C202564000100000002000000
   SYS-T RAW DATA: 720A000B2E0001000000000000004465627567206D657373616765206578616D706C652C2025642C2025642C20256400010000000200000003000000
   SYS-T RAW DATA: 720A000B380001000000000000004465627567206D657373616765206578616D706C652C2025642C2025642C2025642C20307825780001000000020000000300000004000000
   SYS-T RAW DATA: 720A000B0C000100000000000000636861722025630021000000
   SYS-T RAW DATA: 720A000B1D0001000000000000007320737472202573202573007374617469632073747200632073747200
   SYS-T RAW DATA: 720A000B1500010000000000000064207374722025730064796E616D69632073747200
   SYS-T RAW DATA: 720A000B6B0001000000000000006D69786564207374722025732025732025732025732025732025732025730064796E616D696320737472002D2D2D0064796E616D696320737472002D2D2D00616E6F746865722064796E616D696320737472002D2D2D00616E6F746865722064796E616D69632073747200
   SYS-T RAW DATA: 720A000B430001000000000000006D6978656420632F732025632025732025732025732025630021000000737461746963207374720064796E616D69632073747200737461746963207374720021000000
   SYS-T RAW DATA: 720A000B220001000000000000004465627567206D657373616765206578616D706C652C20256600EA2E4454FB210940
   SYS-T RAW DATA: 220A000B090001000000000000002573006672616D6500
   SYS-T RAW DATA: 220A000B47000200000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 320A000B090002000000000000002573006672616D6500
   SYS-T RAW DATA: 320A000B47000200000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 420A000B090002000000000000002573006672616D6500
   SYS-T RAW DATA: 420A000B47000200000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 720A000B090002000000000000002573006672616D6500
   SYS-T RAW DATA: 720A000B47000200000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 020A000B2200020000000000000068656C6C6F207379732D74206F6E20626F6172642025730A0071656D755F78383600
   [    0.020000] <err> syst: Error message example.
   [    0.020000] <wrn> syst: Warning message example.
   [    0.020000] <inf> syst: Info message example.
   [    0.020000] <dbg> syst: Debug message example.
   [    0.020000] <dbg> syst: Debug message example, 1
   [    0.020000] <dbg> syst: Debug message example, 1, 2
   [    0.020000] <dbg> syst: Debug message example, 1, 2, 3
   [    0.020000] <dbg> syst: Debug message example, 1, 2, 3, 0x4
   [    0.020000] <dbg> syst: char !
   [    0.020000] <dbg> syst: s str static str c str
   [    0.020000] <dbg> syst: d str dynamic str
   [    0.020000] <dbg> syst: mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
   [    0.020000] <dbg> syst: mixed c/s ! static str dynamic str static str !
   [    0.030000] <dbg> syst: Debug message example, %f
   [    0.030000] <err> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   [    0.030000] <wrn> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   [    0.030000] <inf> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   [    0.030000] <dbg> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   hello sys-t on board qemu_x86
   SYS-T RAW DATA: 220A000B170003000000000000004572726F72206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 320A000B190003000000000000005761726E696E67206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 420A000B16000300000000000000496E666F206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 720A000B170003000000000000004465627567206D657373616765206578616D706C652E00
   SYS-T RAW DATA: 720A000B1E0003000000000000004465627567206D657373616765206578616D706C652C2025640001000000
   SYS-T RAW DATA: 720A000B260003000000000000004465627567206D657373616765206578616D706C652C2025642C202564000100000002000000
   SYS-T RAW DATA: 720A000B2E0003000000000000004465627567206D657373616765206578616D706C652C2025642C2025642C20256400010000000200000003000000
   SYS-T RAW DATA: 720A000B380003000000000000004465627567206D657373616765206578616D706C652C2025642C2025642C2025642C20307825780001000000020000000300000004000000
   SYS-T RAW DATA: 720A000B0C000300000000000000636861722025630021000000
   SYS-T RAW DATA: 720A000B1D0003000000000000007320737472202573202573007374617469632073747200632073747200
   SYS-T RAW DATA: 720A000B1500030000000000000064207374722025730064796E616D69632073747200
   SYS-T RAW DATA: 720A000B6B0003000000000000006D69786564207374722025732025732025732025732025732025732025730064796E616D696320737472002D2D2D0064796E616D696320737472002D2D2D00616E6F746865722064796E616D696320737472002D2D2D00616E6F746865722064796E616D69632073747200
   SYS-T RAW DATA: 720A000B430004000000000000006D6978656420632F732025632025732025732025732025630021000000737461746963207374720064796E616D69632073747200737461746963207374720021000000
   SYS-T RAW DATA: 720A000B220004000000000000004465627567206D657373616765206578616D706C652C20256600EA2E4454FB210940
   SYS-T RAW DATA: 220A000B090004000000000000002573006672616D6500
   SYS-T RAW DATA: 220A000B47000400000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 320A000B090004000000000000002573006672616D6500
   SYS-T RAW DATA: 320A000B47000400000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 420A000B090004000000000000002573006672616D6500
   SYS-T RAW DATA: 420A000B47000400000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 720A000B090004000000000000002573006672616D6500
   SYS-T RAW DATA: 720A000B47000400000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 020A000B2200040000000000000068656C6C6F207379732D74206F6E20626F6172642025730A0071656D755F78383600
   QEMU: Terminated

Parsing Text Messages
^^^^^^^^^^^^^^^^^^^^^

Use ``systprint`` to parse the output:

.. code-block:: console

   <workspace>/modules/debug/mipi-sys-t/printer/build/systprint -p /tmp/syst

And the parsed messages:

.. code-block:: text

   Error message example.
   Warning message example.
   Info message example.
   Debug message example.
   Debug message example, 1
   Debug message example, 1, 2
   Debug message example, 1, 2, 3
   Debug message example, 1, 2, 3, 0x4
   char !
   s str static str c str
   d str dynamic str
   mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
   mixed c/s ! static str dynamic str static str !
   Debug message example, 3.141593
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   hello sys-t on board qemu_x86

   Warning message example.
   Info message example.
   Debug message example.
   Debug message example, 1
   Debug message example, 1, 2
   Debug message example, 1, 2, 3
   Debug message example, 1, 2, 3, 0x4
   char !
   s str static str c str
   d str dynamic str
   mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
   mixed c/s ! static str dynamic str static str !
   Debug message example, 3.141593
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   hello sys-t on board qemu_x86


MIPI Sys-T Catalog Messages
===========================

Catalog messages are similar to dictionary logging where the format strings
are being referenced by identification hashes, and the string arguments
are encoded in the Sys-T message payload. The hashes and the encoded
arguments can be combined offline with the collateral file (which contains
the mapping between hashes and their corresponding format strings) to
form the actual messages.

To build the sample printing catalog messages under ``qemu_x86``:

.. zephyr-app-commands::
   :zephyr-app: samples/subsys/logging/syst
   :host-os: unix
   :board: qemu_x86
   :goals: build
   :gen-args: -DCONFIG_LOG_BACKEND_SHOW_COLOR=n -DCONFIG_LOG_MIPI_SYST_USE_CATALOG=y
   :compact:

Run the sample and capture the output in a text file:

.. code-block:: console

   west build -t run > /tmp/syst

Since the output is being directed to a text file, there will not be
any output printed on the terminal. So exit QEMU by pressing
:kbd:`CTRL+A` :kbd:`x`.

Sample Catalog Messages Output
------------------------------

The :file:`/tmp/syst` should contain something like this:

.. code-block:: text

   SeaBIOS (version zephyr-v1.0.0-0-g31d4e0e-dirty-20200714_234759-fv-az50-zephyr)
   Booting from ROM..SYS-T RAW DATA: 020A000B490000000000000000002A2A2A20426F6F74696E67205A6570687972204F53206275696C64202573202573202A2A2A0A007A65706879722D76332E302E302D323036372D673166623436343433333731650000
   SYS-T RAW DATA: 230A0001040001000000000000004C221100
   SYS-T RAW DATA: 330A00010400010000000000000030221100
   SYS-T RAW DATA: 430A00010400010000000000000018221100
   SYS-T RAW DATA: 730A00010400010000000000000000221100
   SYS-T RAW DATA: 730A000108000100000000000000E421110001000000
   SYS-T RAW DATA: 730A00010C000100000000000000C42111000100000002000000
   SYS-T RAW DATA: 730A000110000100000000000000A0211100010000000200000003000000
   SYS-T RAW DATA: 730A0001140001000000000000006021110001000000020000000300000004000000
   SYS-T RAW DATA: 730A0001080001000000000000003C21110021000000
   SYS-T RAW DATA: 730A000115000100000000000000302111007374617469632073747200632073747200
   SYS-T RAW DATA: 730A0001100001000000000000002421110064796E616D69632073747200
   SYS-T RAW DATA: 730A0001500001000000000000000421110064796E616D696320737472002D2D2D0064796E616D696320737472002D2D2D00616E6F746865722064796E616D696320737472002D2D2D00616E6F746865722064796E616D69632073747200
   SYS-T RAW DATA: 730A00013E000100000000000000E820110021000000737461746963207374720064796E616D696320737472007374617469632073747200210000000103050464796E616D69632073747200
   SYS-T RAW DATA: 730A00010C000100000000000000CC201100EA2E4454FB210940
   SYS-T RAW DATA: 230A00010A000100000000000000C92011006672616D6500
   SYS-T RAW DATA: 220A000B47000100000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 330A00010A000100000000000000C62011006672616D6500
   SYS-T RAW DATA: 320A000B47000100000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 430A00010A000200000000000000C32011006672616D6500
   SYS-T RAW DATA: 420A000B47000200000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 730A00010A000200000000000000C02011006672616D6500
   SYS-T RAW DATA: 720A000B47000200000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 020A000B2200020000000000000068656C6C6F207379732D74206F6E20626F6172642025730A0071656D755F78383600
   [    0.020000] <err> syst: Error message example.
   [    0.020000] <wrn> syst: Warning message example.
   [    0.020000] <inf> syst: Info message example.
   [    0.020000] <dbg> syst: Debug message example.
   [    0.020000] <dbg> syst: Debug message example, 1
   [    0.020000] <dbg> syst: Debug message example, 1, 2
   [    0.020000] <dbg> syst: Debug message example, 1, 2, 3
   [    0.020000] <dbg> syst: Debug message example, 1, 2, 3, 0x4
   [    0.020000] <dbg> syst: char !
   [    0.020000] <dbg> syst: s str static str c str
   [    0.020000] <dbg> syst: d str dynamic str
   [    0.020000] <dbg> syst: mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
   [    0.020000] <dbg> syst: mixed c/s ! static str dynamic str static str !
   [    0.020000] <dbg> syst: Debug message example, %f
   [    0.020000] <err> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   [    0.020000] <wrn> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   [    0.020000] <inf> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   [    0.030000] <dbg> syst: frame
                              03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   hello sys-t on board qemu_x86
   SYS-T RAW DATA: 230A0001040003000000000000004C221100
   SYS-T RAW DATA: 330A00010400030000000000000030221100
   SYS-T RAW DATA: 430A00010400030000000000000018221100
   SYS-T RAW DATA: 730A00010400030000000000000000221100
   SYS-T RAW DATA: 730A000108000300000000000000E421110001000000
   SYS-T RAW DATA: 730A00010C000300000000000000C42111000100000002000000
   SYS-T RAW DATA: 730A000110000300000000000000A0211100010000000200000003000000
   SYS-T RAW DATA: 730A0001140003000000000000006021110001000000020000000300000004000000
   SYS-T RAW DATA: 730A0001080003000000000000003C21110021000000
   SYS-T RAW DATA: 730A000115000300000000000000302111007374617469632073747200632073747200
   SYS-T RAW DATA: 730A0001100003000000000000002421110064796E616D69632073747200
   SYS-T RAW DATA: 730A0001500003000000000000000421110064796E616D696320737472002D2D2D0064796E616D696320737472002D2D2D00616E6F746865722064796E616D696320737472002D2D2D00616E6F746865722064796E616D69632073747200
   SYS-T RAW DATA: 730A00013E000300000000000000E820110021000000737461746963207374720064796E616D696320737472007374617469632073747200210000000103050464796E616D69632073747200
   SYS-T RAW DATA: 730A00010C000300000000000000CC201100EA2E4454FB210940
   SYS-T RAW DATA: 230A00010A000300000000000000C92011006672616D6500
   SYS-T RAW DATA: 220A000B47000300000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 330A00010A000300000000000000C62011006672616D6500
   SYS-T RAW DATA: 320A000B47000300000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 430A00010A000400000000000000C32011006672616D6500
   SYS-T RAW DATA: 420A000B47000400000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 730A00010A000400000000000000C02011006672616D6500
   SYS-T RAW DATA: 720A000B47000400000000000000257300303320643220303420303020303020303820303120303220203033203034203035203036203037203038202020202020207C2E2E2E2E2E2E2E2E202E2E2E2E2E2E202000
   SYS-T RAW DATA: 020A000B2200040000000000000068656C6C6F207379732D74206F6E20626F6172642025730A0071656D755F78383600
   QEMU: Terminated

Notice the shorter payload of catalog messages compared to text messages.

Parsing Catalog Messages
^^^^^^^^^^^^^^^^^^^^^^^^

Use ``systprint`` to parse the output:

.. code-block:: console

   <workspace>/modules/debug/mipi-sys-t/printer/build/systprint -c <build_dir>/zephyr/mipi_syst_collateral.xml -p /tmp/syst

And the parsed messages:

.. code-block:: text

   Error message example.
   Warning message example.
   Info message example.
   Debug message example.
   Debug message example, 1
   Debug message example, 1, 2
   Debug message example, 1, 2, 3
   Debug message example, 1, 2, 3, 0x4
   char !
   s str static str c str
   d str dynamic str
   mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
   mixed c/s ! static str dynamic str static str !
   Debug message example, 3.141593
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   hello sys-t on board qemu_x86

   Error message example.
   Warning message example.
   Info message example.
   Debug message example.
   Debug message example, 1
   Debug message example, 1, 2
   Debug message example, 1, 2, 3
   Debug message example, 1, 2, 3, 0x4
   char !
   s str static str c str
   d str dynamic str
   mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
   mixed c/s ! static str dynamic str static str !
   Debug message example, 3.141593
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   frame
   03 d2 04 00 00 08 01 02  03 04 05 06 07 08       |........ ......
   hello sys-t on board qemu_x86