From 5e9f1722a9db91445bf056e0fd06a94895ad4500 Mon Sep 17 00:00:00 2001 From: Daniel Leung Date: Thu, 31 Mar 2022 12:55:37 -0700 Subject: [PATCH] samples: logging/syst: add README Add a README.rst on how to build the MIPI Sys-T logging sample and how to parse the output. Signed-off-by: Daniel Leung --- samples/subsys/logging/syst/README.rst | 370 +++++++++++++++++++++++++ 1 file changed, 370 insertions(+) create mode 100644 samples/subsys/logging/syst/README.rst diff --git a/samples/subsys/logging/syst/README.rst b/samples/subsys/logging/syst/README.rst new file mode 100644 index 000000000000..ffad8a3e7e94 --- /dev/null +++ b/samples/subsys/logging/syst/README.rst @@ -0,0 +1,370 @@ +.. _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:`/modules/debug/mipi-sys-t/printer/`. + +Build the Sys-T Message Parser +============================== + +.. code-block:: console + + cd /modules/debug/mipi-sys-t/printer/ + mkdir build + cd build + cmake ../ + make + +An newly built executable ``systprint`` can be found under +:file:`/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] syst: Error message example. + [ 0.020000] syst: Warning message example. + [ 0.020000] syst: Info message example. + [ 0.020000] syst: Debug message example. + [ 0.020000] syst: Debug message example, 1 + [ 0.020000] syst: Debug message example, 1, 2 + [ 0.020000] syst: Debug message example, 1, 2, 3 + [ 0.020000] syst: Debug message example, 1, 2, 3, 0x4 + [ 0.020000] syst: char ! + [ 0.020000] syst: s str static str c str + [ 0.020000] syst: d str dynamic str + [ 0.020000] syst: mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str + [ 0.020000] syst: mixed c/s ! static str dynamic str static str ! + [ 0.030000] syst: Debug message example, %f + [ 0.030000] syst: frame + 03 d2 04 00 00 08 01 02 03 04 05 06 07 08 |........ ...... + [ 0.030000] syst: frame + 03 d2 04 00 00 08 01 02 03 04 05 06 07 08 |........ ...... + [ 0.030000] syst: frame + 03 d2 04 00 00 08 01 02 03 04 05 06 07 08 |........ ...... + [ 0.030000] 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 + + /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] syst: Error message example. + [ 0.020000] syst: Warning message example. + [ 0.020000] syst: Info message example. + [ 0.020000] syst: Debug message example. + [ 0.020000] syst: Debug message example, 1 + [ 0.020000] syst: Debug message example, 1, 2 + [ 0.020000] syst: Debug message example, 1, 2, 3 + [ 0.020000] syst: Debug message example, 1, 2, 3, 0x4 + [ 0.020000] syst: char ! + [ 0.020000] syst: s str static str c str + [ 0.020000] syst: d str dynamic str + [ 0.020000] syst: mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str + [ 0.020000] syst: mixed c/s ! static str dynamic str static str ! + [ 0.020000] syst: Debug message example, %f + [ 0.020000] syst: frame + 03 d2 04 00 00 08 01 02 03 04 05 06 07 08 |........ ...... + [ 0.020000] syst: frame + 03 d2 04 00 00 08 01 02 03 04 05 06 07 08 |........ ...... + [ 0.020000] syst: frame + 03 d2 04 00 00 08 01 02 03 04 05 06 07 08 |........ ...... + [ 0.030000] 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 + + /modules/debug/mipi-sys-t/printer/build/systprint -c /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