Add support and sample backend for dictionary-based logging

CMakeLists.txt

@@ -1392,6 +1392,24 @@ list(APPEND
   ${extra_post_build_byproducts}
   )
 
+if(CONFIG_LOG_DICTIONARY_SUPPORT)
+  set(LOG_DICT_DB_NAME ${PROJECT_BINARY_DIR}/log_dictionary.json)
+
+  list(APPEND
+    post_build_commands
+    COMMAND
+    ${PYTHON_EXECUTABLE}
+    ${ZEPHYR_BASE}/scripts/logging/dictionary/database_gen.py
+    ${KERNEL_ELF_NAME}
+    ${LOG_DICT_DB_NAME}
+    --build ${BUILD_VERSION}
+    )
+  list(APPEND
+    post_build_byproducts
+    ${LOG_DICT_DB_NAME}
+    )
+endif()
+
 # Add post_build_commands to post-process the final .elf file produced by
 # either the ZEPHYR_PREBUILT_EXECUTABLE or the KERNEL_ELF executable
 # targets above.

CODEOWNERS

@@ -534,6 +534,7 @@
 /scripts/coccinelle/                      @himanshujha199640 @JuliaLawall
 /scripts/coredump/                        @dcpleung
 /scripts/kconfig/                         @ulfalizer
+/scripts/logging/dictionary/              @dcpleung
 /scripts/pylib/twister/expr_parser.py     @nashif
 /scripts/schemas/twister/                 @nashif
 /scripts/gen_app_partitions.py            @dcpleung @nashif

doc/guides/index.rst

@@ -35,3 +35,4 @@ User and Developer Guides
    optimizations/index
    zephyr_cmake_package.rst
    thread_local_storage.rst
+   logging/index

doc/guides/logging/dictionary.rst

@@ -0,0 +1,69 @@
+.. _logging_guide_dictionary:
+
+Dictionary-based Logging
+########################
+
+Dictionary-based logging, instead of human readable texts, outputs the log
+messages in binary format. This binary format encodes arguments to formatted
+strings in their native storage formats which can be more compact than their
+text equivalents. For statically defined strings (including the format
+strings and any string arguments), references to the ELF file are encoded
+instead of the whole strings. A dictionary created at build time contains
+the mappings between these references and the actual strings. This allows
+the offline parser to obtain the strings from the dictionary to parse
+the log messages. This binary format allows a more compact representation
+of log messages in certain scenarios. However, this requires the use of
+an offline parser and is not as intuitive to use as text-based log messages.
+
+Note that ``long double`` is not supported by Python's ``struct`` module.
+Therefore, log messages with ``long double`` will not display the correct
+values.
+
+
+Configuration
+*************
+
+Here are kconfig options related to dictionary-based logging:
+
+- :option:`CONFIG_LOG_DICTIONARY_SUPPORT` enables dictionary-based logging
+  support. This should be selected by the backends which require it.
+
+- The UART backend can be used for dictionary-based logging. These are
+  additional config for the UART backend:
+
+  - :option:`CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_HEX` tells
+    the UART backend to output hexadecimal characters for dictionary based
+    logging. This is useful when the log data needs to be captured manually
+    via terminals and consoles.
+
+  - :option:`CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_BIN` tells
+    the UART backend to output binary data.
+
+
+Usage
+*****
+
+When dictionary-based logging is enabled via enabling related logging backends,
+a JSON database file, named :file:`log_dictionary.json`, will be created
+in the build directory. This database file contains information for the parser
+to correctly parse the log data. Note that this database file only works
+with the same build, and cannot be used for any other builds.
+
+To use the log parser:
+
+.. code-block:: console
+
+   ./scripts/logging/dictionary/log_parser.py <build dir>/log_dictionary.json <log data file>
+
+The parser takes two required arguments, where the first one is the full path
+to the JSON database file, and the second part is the file containing log data.
+Add an optional argument ``--hex`` to the end if the log data file contains
+hexadecimal characters
+(e.g. when ``CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_HEX=y``). This tells
+the parser to convert the hexadecimal characters to binary before parsing.
+
+
+Example
+-------
+
+Please refer to :ref:`logging_dictionary_sample` on how to use the log parser.

doc/guides/logging/index.rst

@@ -0,0 +1,9 @@
+.. _logging_guide:
+
+Logging
+#######
+
+.. toctree::
+   :maxdepth: 1
+
+   dictionary.rst

include/arch/nios2/linker.ld

@@ -133,6 +133,8 @@ SECTIONS
         PROVIDE(gp = _gp);
 #endif
 
+    _image_rodata_start = .;
+
 #include <linker/common-rom.ld>
 
     SECTION_PROLOGUE(_RODATA_SECTION_NAME,,)
@@ -153,6 +155,9 @@ SECTIONS
 
 #include <linker/cplusplus-rom.ld>
 
+    _image_rodata_end = .;
+    _image_rodata_size = _image_rodata_end - _image_rodata_start;
+
     _image_rom_end = .;
     __data_rom_start = ALIGN(4);    /* XIP imaged DATA ROM start addr */
 

include/arch/sparc/linker.ld

@@ -40,6 +40,7 @@ SECTIONS
 	} GROUP_LINK_IN(REGION_TEXT)
 
     _image_text_end = .;
+    _image_rodata_start = .;
 
 #include <linker/common-rom.ld>
 #include <linker/thread-local-storage.ld>
@@ -61,7 +62,11 @@ SECTIONS
 
 #include <linker/cplusplus-rom.ld>
 
+    _image_rodata_end = .;
+    _image_rodata_size = _image_rodata_end - _image_rodata_start;
+
     _image_rom_end = .;
+
     __data_rom_start = .;
 
 

include/logging/log_output_dict.h

@@ -0,0 +1,75 @@
+/*
+ * Copyright (c) 2018 Nordic Semiconductor ASA
+ * Copyright (c) 2021 Intel Corporation
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+#ifndef ZEPHYR_INCLUDE_LOGGING_LOG_OUTPUT_DICT_H_
+#define ZEPHYR_INCLUDE_LOGGING_LOG_OUTPUT_DICT_H_
+
+#include <logging/log_output.h>
+#include <logging/log_msg2.h>
+#include <stdarg.h>
+#include <toolchain.h>
+#include <sys/util.h>
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+/**
+ * Log message type
+ */
+enum log_dict_output_msg_type {
+	MSG_NORMAL = 0,
+	MSG_DROPPED_MSG = 1,
+};
+
+/**
+ * Output header for one dictionary based log message.
+ */
+struct log_dict_output_normal_msg_hdr_t {
+	uint8_t type;
+	uint32_t domain:3;
+	uint32_t level:3;
+	uint32_t package_len:10;
+	uint32_t data_len:12;
+	uintptr_t source;
+	log_timestamp_t timestamp;
+} __packed;
+
+/**
+ * Output for one dictionary based log message about
+ * dropped messages.
+ */
+struct log_dict_output_dropped_msg_t {
+	uint8_t type;
+	uint16_t num_dropped_messages;
+} __packed;
+
+/** @brief Process log messages v2 for dictionary-basde logging.
+ *
+ * Function is using provided context with the buffer and output function to
+ * process formatted string and output the data.
+ *
+ * @param log_output Pointer to the log output instance.
+ * @param msg Log message.
+ * @param flags Optional flags.
+ */
+void log_dict_output_msg2_process(const struct log_output *log_output,
+				  struct log_msg2 *msg, uint32_t flags);
+
+/** @brief Process dropped messages indication for dictionary-based logging.
+ *
+ * Function prints error message indicating lost log messages.
+ *
+ * @param output Pointer to the log output instance.
+ * @param cnt        Number of dropped messages.
+ */
+void log_dict_output_dropped_process(const struct log_output *output, uint32_t cnt);
+
+#ifdef __cplusplus
+}
+#endif
+
+#endif /* ZEPHYR_INCLUDE_LOGGING_LOG_OUTPUT_DICT_H_ */

lib/os/cbprintf_packaged.c

@@ -30,16 +30,12 @@ static inline bool ptr_in_rodata(const char *addr)
 #define RO_START 0
 #define RO_END 0
 #elif defined(CONFIG_ARC) || defined(CONFIG_ARM) || defined(CONFIG_X86) \
-	|| defined(CONFIG_RISCV) || defined(CONFIG_ARM64)
+	|| defined(CONFIG_RISCV) || defined(CONFIG_ARM64) \
+	|| defined(CONFIG_NIOS2)
 	extern char _image_rodata_start[];
 	extern char _image_rodata_end[];
 #define RO_START _image_rodata_start
 #define RO_END _image_rodata_end
-#elif defined(CONFIG_NIOS2) || defined(CONFIG_RISCV)
-	extern char _image_rom_start[];
-	extern char _image_rom_end[];
-#define RO_START _image_rom_start
-#define RO_END _image_rom_end
 #elif defined(CONFIG_XTENSA)
 	extern char _rodata_start[];
 	extern char _rodata_end[];

samples/subsys/logging/dictionary/CMakeLists.txt

@@ -0,0 +1,8 @@
+# SPDX-License-Identifier: Apache-2.0
+
+cmake_minimum_required(VERSION 3.13.1)
+
+find_package(Zephyr REQUIRED HINTS $ENV{ZEPHYR_BASE})
+project(logging_dictionary)
+
+target_sources(app PRIVATE src/main.c)

samples/subsys/logging/dictionary/README.rst

@@ -0,0 +1,71 @@
+.. _logging_dictionary_sample:
+
+Dictionary-based Logging Sample
+###############################
+
+This is a sample app which utilizes dictionary based logging and
+the UART backend. This is configured to output binary log data
+in hexadecimal so it could be run in terminal.
+
+
+Building and Running
+********************
+
+This application can be built and executed on QEMU as follows:
+
+.. zephyr-app-commands::
+   :zephyr-app: samples/subsys/logging/dictionary
+   :host-os: unix
+   :board: qemu_x86
+   :goals: run
+   :compact:
+
+To build for another board, change "qemu_x86" above to that board's name.
+
+
+Sample Output
+=============
+
+   .. code-block:: none
+
+      SeaBIOS (version zephyr-v1.0.0-0-g31d4e0e-dirty-20200714_234759-fv-az50-zephyr)
+      Booting from ROM..##ZLOGV1##000004000000000000ecd7000004000000f76a10001e6b10001d6b1000000003000000000000b3e30000030000004d6410004464100000080200000000000093e70000020000005e64100000200300000000000076eb0000030000006b641000dc60100000180200000000000043ef0000020000007c64100000200500000000000066f300000500000088641000dc60100001000000020000000020050000000000008cf7000005000000a2641000dc6010001000000011000000002005000000000000b3fb000005000000be641000dc60100020000000210000000020070000000000000600010007000000da641000dc60100040000000000000004100000000000000002004000000000000491f0100040000000e651000dc60100021000000002004000000000000e02801000400000025651000dc6010001a651000006007000000000000993501000401000032651000dc601000000000000364796e616d6963207374720000201b0000000000000c5701000a04000043651000dc601000000000003f651000000000003f651000000000003f651000000000000364796e616d696320737472000564796e616d6963207374720007616e6f746865722064796e616d6963207374720009616e6f746865722064796e616d6963207374720000600b000000000000736a01000801000066651000dc601000210000001a651000000000001a651000210000000564796e616d696320737472000020040000000000008c6e01000400000083651000dc601000da0310000020041a0000000000967a010004000000ba651000dc601000ad65100048455844554d50212048455844554d50402048455844554d5023
+
+
+Running the Log Parser
+======================
+
+1. Pipe the run output or copy the hexadecimal string into a temporary file ``/tmp/serial.log``:
+
+   .. code-block:: none
+
+      ##ZLOGV1##000004000000000000ecd7000004000000f76a10001e6b10001d6b1000000003000000000000b3e30000030000004d6410004464100000080200000000000093e70000020000005e64100000200300000000000076eb0000030000006b641000dc60100000180200000000000043ef0000020000007c64100000200500000000000066f300000500000088641000dc60100001000000020000000020050000000000008cf7000005000000a2641000dc6010001000000011000000002005000000000000b3fb000005000000be641000dc60100020000000210000000020070000000000000600010007000000da641000dc60100040000000000000004100000000000000002004000000000000491f0100040000000e651000dc60100021000000002004000000000000e02801000400000025651000dc6010001a651000006007000000000000993501000401000032651000dc601000000000000364796e616d6963207374720000201b0000000000000c5701000a04000043651000dc601000000000003f651000000000003f651000000000003f651000000000000364796e616d696320737472000564796e616d6963207374720007616e6f746865722064796e616d6963207374720009616e6f746865722064796e616d6963207374720000600b000000000000736a01000801000066651000dc601000210000001a651000000000001a651000210000000564796e616d696320737472000020040000000000008c6e01000400000083651000dc601000da0310000020041a0000000000967a010004000000ba651000dc601000ad65100048455844554d50212048455844554d50402048455844554d5023
+
+2. Run the log parser to get the text output:
+
+   .. code-block:: console
+
+      ./scripts/logging/dictionary/log_parser.py build/zephyr/log_dictionary.json /tmp/serial.log --hex
+
+   And here is the output:
+
+   .. code-block:: none
+
+      *** Booting Zephyr OS build zephyr-v2.5.0-2471-g09b9eaf333e6  ***
+      Hello World! qemu_x86
+      [     77820] <err> hello_world: error string
+      [     86332] <dbg> hello_world: main: debug string
+      [     96275] <inf> hello_world: info string
+      [    104784] <dbg> hello_world: main: int8_t 1, uint8_t 2
+      [    117609] <dbg> hello_world: main: int16_t 16, uint16_t 17
+      [    130454] <dbg> hello_world: main: int32_t 32, uint32_t 33
+      [    143299] <dbg> hello_world: main: int64_t 64, uint64_t 65
+      [    166374] <dbg> hello_world: main: char !
+      [    179452] <dbg> hello_world: main: s str static str
+      [    193395] <dbg> hello_world: main: d str dynamic str
+      [    217283] <dbg> hello_world: main: mixed str dynamic str --- dynamic str --- another dynamic str --- another dynamic str
+      [    266022] <dbg> hello_world: main: mixed c/s ! static str dynamic str static str !
+      [    287888] <dbg> hello_world: main: pointer 0x10651a
+      [    301600] <dbg> hello_world: main: For HeXdUmP!
+                                    48 45 58 44 55 4d 50 21  20 48 45 58 44 55 4d 50 |HEXDUMP!  HEXDUMP
+                                    40 20 48 45 58 44 55 4d  50 23                   |@ HEXDUM P#

samples/subsys/logging/dictionary/prj.conf

@@ -0,0 +1,5 @@
+CONFIG_LOG=y
+CONFIG_LOG_PRINTK=y
+CONFIG_LOG_BACKEND_UART_OUTPUT_DICTIONARY_HEX=y
+CONFIG_LOG_BACKEND_UART=y
+CONFIG_LOG2_MODE_DEFERRED=y

samples/subsys/logging/dictionary/sample.yaml

@@ -0,0 +1,7 @@
+sample:
+  description: Dictionary-based Logging Sample Application
+  name: logging_dictionary
+tests:
+  sample.logger.basic.dictionary:
+    build_only: true
+    tags: logging