logging: support emitting MIPI Sys-T catalog messages #43784

dcpleung · 2022-03-15T00:27:22Z

MIPI Sys-T catalog messages are similar to dictionary logging where an ID is emitted instead of the format string. This allows the format strings to be removed from the final binary to save a few bytes. This adds the necessary bits to determine to emit catalog messages when appropriate.

See individual commits for details.

github-actions · 2022-03-15T00:28:11Z

The following west manifest projects have been modified in this Pull Request:

Name	Old Revision	New Revision	Diff
mipi-sys-t	zephyrproject-rtos/mipi-sys-t@`d9da086`	zephyrproject-rtos/mipi-sys-t@`2f51407`	zephyrproject-rtos/[email protected]

Note: This message is automatically posted and updated by the Manifest GitHub Action.

dcpleung · 2022-03-18T22:20:25Z

Updated west.yml as zephyrproject-rtos/mipi-sys-t#6 has been merged.

nordic-krch

Started to look into it. Wasn't yet involved much in dictionary/catalog logging.
I have 2 question:

why string from rodata are not cataloged but appended to the log message?
how to parse catalog mipi syst sample? I run the sample and wanted to run log_parser.py with xml file as database but got error.

nordic-krch · 2022-03-23T14:34:04Z

include/logging/log_msg2.h

@@ -195,19 +195,20 @@ enum z_log_msg2_mode {
 #define Z_LOG_MSG2_STACK_CREATE(_cstr_cnt, _domain_id, _source, _level, _data, _dlen, ...) \
 do { \
 	int _plen; \
+	uint32_t flags = CBPRINTF_PACKAGE_FIRST_RO_STR_CNT(_cstr_cnt) | \


maybe you could use similar approach as i did in multi-domain PR and create a define:
https://github.com/zephyrproject-rtos/zephyr/blob/45c528dfde3d38abf9153f1bcb139b2fafb0b0c8/include/logging/log_msg2.h#L138

Updated and replaced it with a macro.

nordic-krch · 2022-03-23T14:35:12Z

include/logging/log_msg2.h

@@ -221,8 +222,7 @@ do { \
 #ifdef CONFIG_LOG_SPEED
 #define Z_LOG_MSG2_SIMPLE_CREATE(_cstr_cnt, _domain_id, _source, _level, ...) do { \
 	int _plen; \
-	CBPRINTF_STATIC_PACKAGE(NULL, 0, _plen, Z_LOG_MSG2_ALIGN_OFFSET, \
-				CBPRINTF_PACKAGE_FIRST_RO_STR_CNT(_cstr_cnt), \
+	CBPRINTF_STATIC_PACKAGE(NULL, 0, _plen, Z_LOG_MSG2_ALIGN_OFFSET, flags, \


will it compile, flags variable is not created here. Use define as suggested above would result in single place of flags definition

weird... ran through twister without any issue...

dcpleung · 2022-03-28T17:41:35Z

why string from rodata are not cataloged but appended to the log message?

Sys-T does not use catalog for string arguments. There is no way to tag whether a string in the argument list is a string in catalog or a full string. Therefore, each string argument needs to be replaced with the full string.

how to parse catalog mipi syst sample? I run the sample and wanted to run log_parser.py with xml file as database but got error.

There is a systprint utility in modules/debug/mipi-sys-t/ that needs to be built. For example, after saving the content of a qemu_x86 run in a text file, you can do systprint -p -c <build_dir>/zephyr/mipi_syst_collateral.xml <qemu output> to get the messages. Note that the utility looks for lines (strictly) beginning with SYS-T RAW DATA: for messages to be parsed. So depending on the QEMU output, the first line may not print.

nordic-krch · 2022-03-29T11:42:35Z

Therefore, each string argument needs to be replaced with the full string.

@dcpleung does it mean that strings are inserted as value into the stream and not appended like in cbprintf package? Is this somehow standardized or would it be possible to somehow send package as is (converted to mipi syst stream)? Current approach requires quite a lot of processing. Also when package is statically created then ro/rw indexes will be appended for char pointers even when they were used for %p. Will it not disrupt the processing?

One more thing. I didn't see source being sent, any plans to support it?

dcpleung · 2022-03-29T16:12:57Z

@nordic-krch In the MIPI Sys-T Spec, section 9.1.4, the example shows the C strings are copied to output. So a format string of %d %s %s %d will have an a payload of <catalog id> <int> <whole null-terminated C string> <whole null-terminated C string> <int>. I can't find a more detailed documentation on the catalog message payload, but the example shows that C strings are actually inserted. The APIs and examples in the MIPI module are also using the same scheme. So sending the packages as-is cannot be done unless the MIPI specification is changed.

As for %p, this is going to be problematic since using catalog messages usually means the format strings are stripped from final binary, and we have no information to figure whether it is a pointer or a C string. The MIPI Sys-T API actually calls for tagged arguments where each argument is preceded by a numeric value depicting its type, but it requires the printf arguments be augmented like this ...("%d %s\n", MIPI_SYST_PARAM_CSTR("testing"), MIPI_SYST_PARAM_INT(1)); where the MIPI_SYST_PARAM_* add the tags. We cannot do this here because this requires changing all LOG_*() in Zephyr.

As for sending the source of the message, the API we are using right now does not take any source locations. But this is something on my mind that will need to be done in the future.

nordic-krch · 2022-03-30T06:07:19Z

right, I only got to mipi STP specification and couldn't find anything there. Seems that i need to get into mipi_syst specification then.

With the new structure of the cbpprintf packages, the Python parser needs to be updated to skip extra bytes before reaching the string table. Signed-off-by: Daniel Leung <[email protected]>

The MIPI Sys-T library can now take a format string with a variable argument list so there is no need for the temporary buffer anymore. This saves some stack space in v1 immediate mode. Signed-off-by: Daniel Leung <[email protected]>

Compilers often combine strings to conserve space, if one string is a perfect substring of another one towards the end. So add another string in the test to make sure dictionary logging is still working correctly under this scenario. Signed-off-by: Daniel Leung <[email protected]>

Fixes some easy pylint warnings. Signed-off-by: Daniel Leung <[email protected]>

This changes the database generation to actually extracting individual strings instead of stuffing the whole binary sections into the database. This allows the generation script to be extended to accommodate more output formats. Note that if CONFIG_LOG2_FMT_SECTION is enabled, the format strings are in log_strings_sections, and also have associated debug symbols in DWARF. So there is no need to manually extract them. Signed-off-by: Daniel Leung <[email protected]>

This changes the script to allow output format to be specified. Currently, only JSON is support. This will allow supporting other formats in the future. Signed-off-by: Daniel Leung <[email protected]>

This adds the ability to the dictionary logging database generation script to output MIPI Sys-T collateral in XML. This will allow usage of catalog logging under Sys-T, which is similar to dictionary logging. Signed-off-by: Daniel Leung <[email protected]>

This updates the mipi-sys-t module to support prepared argument list for catalog messages. Signed-off-by: Daniel Leung <[email protected]>

This adds a new CONFIG_LOG2_MSG_PKG_ALWAYS_ADD_RO_STRING_IDXS kconfig. If enabled, the log message packages will always have the indexes of read-only string arguments appended to the package. This will be selected only by those backends requiring it. Signed-off-by: Daniel Leung <[email protected]>

MIPI Sys-T catalog messages are similar to dictionary logging where an ID is emitted instead of the format string. This allows the format strings to be removed from the final binary to save a few bytes. This adds the necessary bits to determine to emit catalog messages when appropriate. Note that this implementation copies the argument list as-is with string arguments stitched together since the format strings are assumed to have been removed and they cannot be examined to properly convert the argument lists into catalog message payloads. Because of this, various build asserts are there to avoid building for configurations where they are known not to work. Signed-off-by: Daniel Leung <[email protected]>

Compilers often combine strings to conserve space, if one string is a perfect substring of another one towards the end. So add another string in the test to make sure sys-t with catalog messages is still working correctly under this scenario. Signed-off-by: Daniel Leung <[email protected]>

This adds qemu_x86_64 and qemu_cortex_a53 to make sure 64-bit support for Sys-T is not broken in the future. Signed-off-by: Daniel Leung <[email protected]>

This adds to sample.yaml to build for MIPI Sys-T catalog message support. Note that the current implementation of emitting Sys-T catalog messages does not support 64-bit and architectures having additional alignment requirements. So only allow qemu_x86 and mps2_an385 at the moment. Signed-off-by: Daniel Leung <[email protected]>

dcpleung · 2022-03-30T21:37:17Z

Rebased after #43520 was merged.

Add myself to the CODEOWNERS for samples/subsys/logging/syst to make checkpatch happy, and to get notifications of changes in the sample. Signed-off-by: Daniel Leung <[email protected]>

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 <[email protected]>

dcpleung · 2022-03-31T21:19:04Z

Added a README for the syst sample to show how to get back readable log messages.

nordic-krch

One minor comment.

I wonder if it wouldn't be better to just dump log message as is (similar to dictionary backend) or put it into some custom mipi STP stream and then have some python script that converts this stream to mipi syst format. That would be simpler on device side, handle %p and ro strings could also be sent by address and fetched on the host.

nordic-krch · 2022-03-31T07:50:53Z

subsys/logging/log_output_syst.c

+#endif
+
+#ifdef CONFIG_64BIT
+#define MIPI_SYST_CATMSG_ARGS_COPY MIPI_SYST_CATALOG64_ARGS_COPY


is there a point to have it as 64bit is not supported?

Hopefully we can support 64-bit in the near future.

MaureenHelm · 2022-04-01T13:50:32Z

Added a README for the syst sample to show how to get back readable log messages.

Thanks @dcpleung

dcpleung · 2022-04-01T16:47:55Z

I wonder if it wouldn't be better to just dump log message as is (similar to dictionary backend) or put it into some custom mipi STP stream and then have some python script that converts this stream to mipi syst format. That would be simpler on device side, handle %p and ro strings could also be sent by address and fetched on the host.

This is probably going to be problematic as people won't be able to use arbitrary MIPI tool to parse the log messages. Having a standard spec means multiple tools can be used (as drop-in replacement). Requiring an additional parsing steps breaks this model. I don't think people needing log messages through MIPI would want to deviate from standard.

github-actions bot added area: API Changes to public APIs area: Logging area: Modules area: Samples Samples manifest west manifest-mipi-sys-t DNM This PR should not be merged (Do Not Merge) labels Mar 15, 2022

dcpleung marked this pull request as ready for review March 15, 2022 16:06

dcpleung requested review from nordic-krch, jakub-uC, tejlmand and nashif as code owners March 15, 2022 16:06

zephyrbot added the area: Build System label Mar 16, 2022

zephyrbot requested a review from chen-png March 16, 2022 11:57

zephyrbot assigned nordic-krch Mar 16, 2022

dcpleung force-pushed the logging_mipi_syst_catalog_msg branch from b351e6d to 34f3f7e Compare March 18, 2022 22:19

github-actions bot removed the DNM This PR should not be merged (Do Not Merge) label Mar 18, 2022

nordic-krch reviewed Mar 24, 2022

View reviewed changes

dcpleung force-pushed the logging_mipi_syst_catalog_msg branch from 34f3f7e to c58936a Compare March 28, 2022 22:58

MaureenHelm self-requested a review March 30, 2022 01:37

dcpleung added 3 commits March 30, 2022 13:41

logging: dictionary: update package processing

b12ce52

With the new structure of the cbpprintf packages, the Python parser needs to be updated to skip extra bytes before reaching the string table. Signed-off-by: Daniel Leung <[email protected]>

dcpleung added 10 commits March 30, 2022 13:41

scripts: logging/dictionary: fixes pylint warnings

cd31186

Fixes some easy pylint warnings. Signed-off-by: Daniel Leung <[email protected]>

scripts: logging/dictionary: can specify output format

31bfe11

This changes the script to allow output format to be specified. Currently, only JSON is support. This will allow supporting other formats in the future. Signed-off-by: Daniel Leung <[email protected]>

west.yml: update mipi-sys-t for catalog msg support

efd22e2

This updates the mipi-sys-t module to support prepared argument list for catalog messages. Signed-off-by: Daniel Leung <[email protected]>

samples: syst: allow some 64-bit boards

ee39bf2

This adds qemu_x86_64 and qemu_cortex_a53 to make sure 64-bit support for Sys-T is not broken in the future. Signed-off-by: Daniel Leung <[email protected]>

dcpleung force-pushed the logging_mipi_syst_catalog_msg branch from c58936a to 57a8a92 Compare March 30, 2022 21:36

MaureenHelm previously approved these changes Mar 30, 2022

View reviewed changes

dcpleung added 2 commits March 31, 2022 14:17

CODEOWNERS: add myself for samples/subsys/logging/syst

b82a925

Add myself to the CODEOWNERS for samples/subsys/logging/syst to make checkpatch happy, and to get notifications of changes in the sample. Signed-off-by: Daniel Leung <[email protected]>

samples: logging/syst: add README

acfaec0

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 <[email protected]>

dcpleung dismissed MaureenHelm’s stale review via acfaec0 March 31, 2022 21:18

github-actions bot added the area: Documentation label Mar 31, 2022

nashif approved these changes Mar 31, 2022

View reviewed changes

nordic-krch approved these changes Apr 1, 2022

View reviewed changes

carlescufi merged commit 5e9f172 into zephyrproject-rtos:main Apr 1, 2022

dcpleung deleted the logging_mipi_syst_catalog_msg branch April 1, 2022 16:38

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

logging: support emitting MIPI Sys-T catalog messages #43784

logging: support emitting MIPI Sys-T catalog messages #43784

dcpleung commented Mar 15, 2022

github-actions bot commented Mar 15, 2022 •

edited

Loading

dcpleung commented Mar 18, 2022

nordic-krch left a comment

nordic-krch Mar 23, 2022

dcpleung Mar 28, 2022

nordic-krch Mar 23, 2022

dcpleung Mar 28, 2022

dcpleung commented Mar 28, 2022

nordic-krch commented Mar 29, 2022

dcpleung commented Mar 29, 2022

nordic-krch commented Mar 30, 2022

dcpleung commented Mar 30, 2022

dcpleung commented Mar 31, 2022

nordic-krch left a comment

nordic-krch Mar 31, 2022

dcpleung Apr 1, 2022

MaureenHelm commented Apr 1, 2022

dcpleung commented Apr 1, 2022

logging: support emitting MIPI Sys-T catalog messages #43784

logging: support emitting MIPI Sys-T catalog messages #43784

Conversation

dcpleung commented Mar 15, 2022

github-actions bot commented Mar 15, 2022 • edited Loading

dcpleung commented Mar 18, 2022

nordic-krch left a comment

Choose a reason for hiding this comment

nordic-krch Mar 23, 2022

Choose a reason for hiding this comment

dcpleung Mar 28, 2022

Choose a reason for hiding this comment

nordic-krch Mar 23, 2022

Choose a reason for hiding this comment

dcpleung Mar 28, 2022

Choose a reason for hiding this comment

dcpleung commented Mar 28, 2022

nordic-krch commented Mar 29, 2022

dcpleung commented Mar 29, 2022

nordic-krch commented Mar 30, 2022

dcpleung commented Mar 30, 2022

dcpleung commented Mar 31, 2022

nordic-krch left a comment

Choose a reason for hiding this comment

nordic-krch Mar 31, 2022

Choose a reason for hiding this comment

dcpleung Apr 1, 2022

Choose a reason for hiding this comment

MaureenHelm commented Apr 1, 2022

dcpleung commented Apr 1, 2022

github-actions bot commented Mar 15, 2022 •

edited

Loading