From 21af14f6ed6cc38dceeac98c9a5c36c0f43220a0 Mon Sep 17 00:00:00 2001 From: Jerzy Kasenberg Date: Wed, 3 Apr 2024 11:17:55 +0200 Subject: [PATCH 1/5] sys/log: Use autogenerated function to get mod log name Current code had switch in function log_module_get_name() that returned module name based on some syscfg value first then it search modules registered by log_module_register(). Some of the syscfg values used in this code were referring to be values that are not any syscfg.yml file. Now code calls first auto-genereated function logcfg_log_module_name() to get those names. Signed-off-by: Jerzy Kasenberg --- sys/log/full/src/log.c | 44 ++++++++---------------------------------- 1 file changed, 8 insertions(+), 36 deletions(-) diff --git a/sys/log/full/src/log.c b/sys/log/full/src/log.c index a1a2f1a57d..68c04d6f00 100644 --- a/sys/log/full/src/log.c +++ b/sys/log/full/src/log.c @@ -230,48 +230,20 @@ const char * log_module_get_name(uint8_t module) { int idx; + const char *name; - switch (module) { -#ifdef MYNEWT_VAL_DFLT_LOG_MOD - case MYNEWT_VAL(DFLT_LOG_MOD): - return "DEFAULT"; -#endif -#ifdef MYNEWT_VAL_OS_LOG_MOD - case MYNEWT_VAL(OS_LOG_MOD): - return "OS"; -#endif -#ifdef MYNEWT_VAL_BLE_LL_LOG_MOD - case MYNEWT_VAL(BLE_LL_LOG_MOD): - return "NIMBLE_CTLR"; -#endif -#ifdef MYNEWT_VAL_BLE_HS_LOG_MOD - case MYNEWT_VAL(BLE_HS_LOG_MOD): - return "NIMBLE_HOST"; -#endif -#ifdef MYNEWT_VAL_NFFS_LOG_MOD - case MYNEWT_VAL(NFFS_LOG_MOD): - return "NFFS"; -#endif -#ifdef MYNEWT_VAL_REBOOT_LOG_MOD - case MYNEWT_VAL(REBOOT_LOG_MOD): - return "REBOOT"; -#endif -#ifdef MYNEWT_VAL_OC_LOG_MOD - case MYNEWT_VAL(OC_LOG_MOD): - return "IOTIVITY"; -#endif -#ifdef MYNEWT_VAL_TEST_LOG_MOD - case MYNEWT_VAL(TEST_LOG_MOD): - return "TEST"; -#endif - default: + /* Find module defined in syscfg.logcfg sections */ + name = logcfg_log_module_name(module); + + if (name == NULL) { + /* not in syscfg.logcfg, find module registered with log_module_register() */ idx = log_module_find_idx(module); if (idx != -1) { - return g_log_module_list[idx].name; + name = g_log_module_list[idx].name; } } - return NULL; + return name; } /** From 77ae598d9c1a72ae4500e005b4a776ee771753e8 Mon Sep 17 00:00:00 2001 From: Jerzy Kasenberg Date: Wed, 3 Apr 2024 11:20:01 +0200 Subject: [PATCH 2/5] sys/log: Set name for DFLT_LOG DFLT_LOG has now log name specified in syscfg to keep "DEFAULT" as default module log name. Without this change name would be "DLFT" Signed-off-by: Jerzy Kasenberg --- sys/log/common/syscfg.yml | 1 + 1 file changed, 1 insertion(+) diff --git a/sys/log/common/syscfg.yml b/sys/log/common/syscfg.yml index 27f4860070..0eb143954d 100644 --- a/sys/log/common/syscfg.yml +++ b/sys/log/common/syscfg.yml @@ -34,4 +34,5 @@ syscfg.logs: DFLT_LOG: module: MYNEWT_VAL(DFLT_LOG_MOD) level: MYNEWT_VAL(DFLT_LOG_LVL) + name: '"DEFAULT"' From 6b55c7788a5b1d3582080933d01018a4b8ccc891 Mon Sep 17 00:00:00 2001 From: Jerzy Kasenberg Date: Wed, 3 Apr 2024 11:27:51 +0200 Subject: [PATCH 3/5] sys/log: Update modlog name for msc_fat_view and dfu This sets module name for logging to nicer values Signed-off-by: Jerzy Kasenberg --- hw/usb/tinyusb/dfu/syscfg.yml | 1 + hw/usb/tinyusb/msc_fat_view/syscfg.yml | 1 + 2 files changed, 2 insertions(+) diff --git a/hw/usb/tinyusb/dfu/syscfg.yml b/hw/usb/tinyusb/dfu/syscfg.yml index f5d5ce7903..c50eb3cbd2 100644 --- a/hw/usb/tinyusb/dfu/syscfg.yml +++ b/hw/usb/tinyusb/dfu/syscfg.yml @@ -111,6 +111,7 @@ syscfg.logs: USBD_DFU_LOG: module: MYNEWT_VAL(USBD_DFU_LOG_MODULE) level: MYNEWT_VAL(USBD_DFU_LOG_LVL) + name: '"DFU"' syscfg.vals.BOOT_LOADER: diff --git a/hw/usb/tinyusb/msc_fat_view/syscfg.yml b/hw/usb/tinyusb/msc_fat_view/syscfg.yml index 34f0cb6653..b1d0700ba9 100644 --- a/hw/usb/tinyusb/msc_fat_view/syscfg.yml +++ b/hw/usb/tinyusb/msc_fat_view/syscfg.yml @@ -141,3 +141,4 @@ syscfg.logs: MSC_FAT_VIEW_LOG: module: MYNEWT_VAL(MSC_FAT_VIEW_LOG_MOD) level: MYNEWT_VAL(MSC_FAT_VIEW_LOG_LVL) + name: '"FATVIEW"' From a8fe8a326a1bcd7f3091273ec89097be0522d1c5 Mon Sep 17 00:00:00 2001 From: Jerzy Kasenberg Date: Wed, 3 Apr 2024 11:33:27 +0200 Subject: [PATCH 4/5] log_console: Fix image header log print console print was using series of hexadecimal formatting without specifying filed size it could result in misleading printout where leading zeros for each byte are missing. Now format makes sure that all digits are present. Signed-off-by: Jerzy Kasenberg --- sys/log/full/src/log_console.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/sys/log/full/src/log_console.c b/sys/log/full/src/log_console.c index 69017f0d1d..5905f8d1f4 100644 --- a/sys/log/full/src/log_console.c +++ b/sys/log/full/src/log_console.c @@ -57,7 +57,7 @@ log_console_print_hdr(const struct log_entry_hdr *hdr) hdr->ue_ts, hdr->ue_module, hdr->ue_level); if (hdr->ue_flags & LOG_FLAGS_IMG_HASH) { - console_printf("ih=0x%x%x%x%x", hdr->ue_imghash[0], hdr->ue_imghash[1], + console_printf("ih=0x%02x%02x%02x%02x", hdr->ue_imghash[0], hdr->ue_imghash[1], hdr->ue_imghash[2], hdr->ue_imghash[3]); } console_printf("]"); From 12383a187027439fa809f1099c4829e097ed9294 Mon Sep 17 00:00:00 2001 From: Jerzy Kasenberg Date: Wed, 3 Apr 2024 11:49:13 +0200 Subject: [PATCH 5/5] log_console: Add pretty print This introduces alternative output of mod log header. Log mod module was printed: mod=0 now it is displayed this way: [DEFAULT] Log level used to be: level=2 Now it is: [WRN] of nothing if color are requested Time stamp is not displayed by default if CONSOLE_TICKS is 1 Severity level can be printed in color. Additional syscfg values that can be used: LOG_CONSOLE_PRETTY enable alternative display LOG_CONSOLE_PRETTY_WITH_COLORS enables colors for severity level LOG_CONSOLE_PRETTY_WITH_TIMESTAMP enables/disables time stamp printing Signed-off-by: Jerzy Kasenberg --- sys/log/full/src/log_console.c | 85 ++++++++++++++++++++++++++++++++++ sys/log/full/syscfg.yml | 19 ++++++++ 2 files changed, 104 insertions(+) diff --git a/sys/log/full/src/log_console.c b/sys/log/full/src/log_console.c index 5905f8d1f4..9a31666230 100644 --- a/sys/log/full/src/log_console.c +++ b/sys/log/full/src/log_console.c @@ -50,6 +50,90 @@ log_console_get(void) return &log_console; } +#if MYNEWT_VAL(LOG_CONSOLE_PRETTY) +#define CSI "\x1b[" +#define COLOR_BLUE "36m" +#define COLOR_YELLOW "33m" +#define COLOR_RED "31m" +#define COLOR_RED_BG "41m" + +#if MYNEWT_VAL(LOG_CONSOLE_PRETTY_WITH_COLORS) +#define COLOR_DBG CSI COLOR_BLUE +#define COLOR_INF "" +#define COLOR_WRN CSI COLOR_YELLOW +#define COLOR_ERR CSI COLOR_RED +#define COLOR_CRI CSI COLOR_RED_BG +#define COLOR_RESET CSI "0m" +#else +#define COLOR_DBG "" +#define COLOR_INF "" +#define COLOR_WRN "" +#define COLOR_ERR "" +#define COLOR_CRI "" +#define COLOR_RESET "" +#endif + +static const char * const log_level_color[] = { + COLOR_DBG, + COLOR_INF, + COLOR_WRN, + COLOR_ERR, + COLOR_CRI, +}; + +static const char * const log_level_str[] = { + "[DBG]", + "[INF]", + "[WRN]", + "[ERR]", + "[CRI]", +}; + +static void +log_console_print_hdr(const struct log_entry_hdr *hdr) +{ + char module_num[10]; + char image_hash_str[17]; + char level_str_buf[13]; + const char *level_str = ""; + const char *module_name = NULL; + const char *color = ""; + const char *color_off = ""; + + /* Find module defined in syscfg.logcfg sections */ + module_name = log_module_get_name(hdr->ue_module); + + if (module_name == NULL) { + module_name = module_num; + sprintf(module_num, "mod=%u", hdr->ue_module); + } + if (hdr->ue_flags & LOG_FLAGS_IMG_HASH) { + sprintf(image_hash_str, "[ih=0x%02x%02x%02x%02x]", hdr->ue_imghash[0], hdr->ue_imghash[1], + hdr->ue_imghash[2], hdr->ue_imghash[3]); + } else { + image_hash_str[0] = 0; + } + if (hdr->ue_level <= LOG_LEVEL_CRITICAL) { + if (MYNEWT_VAL(LOG_CONSOLE_PRETTY_WITH_COLORS)) { + color = log_level_color[hdr->ue_level]; + color_off = COLOR_RESET; + } else { + level_str = log_level_str[hdr->ue_level]; + } + } else { + sprintf(level_str_buf, "[level=%u]", hdr->ue_level); + } + + if (MYNEWT_VAL(LOG_CONSOLE_PRETTY_WITH_TIMESTAMP)) { + unsigned int us = (unsigned int)hdr->ue_ts % 1000000; + unsigned int s = (unsigned int)(hdr->ue_ts / 1000000); + console_printf("[%u.%06u][%s%7s%s]%s%s ", s, us, color, module_name, color_off, level_str, image_hash_str); + } else { + console_printf("[%s%7s%s]%s%s ", color, module_name, color_off, level_str, image_hash_str); + } +} + +#else static void log_console_print_hdr(const struct log_entry_hdr *hdr) { @@ -62,6 +146,7 @@ log_console_print_hdr(const struct log_entry_hdr *hdr) } console_printf("]"); } +#endif static int log_console_append_body(struct log *log, const struct log_entry_hdr *hdr, diff --git a/sys/log/full/syscfg.yml b/sys/log/full/syscfg.yml index 356753eaa9..91709976f1 100644 --- a/sys/log/full/syscfg.yml +++ b/sys/log/full/syscfg.yml @@ -32,6 +32,22 @@ syscfg.defs: description: 'Limits what level log messages are compiled in.' value: 0 + LOG_CONSOLE_PRETTY: + description: > + Use alternative formatting of mod log prints. + value: 0 + + LOG_CONSOLE_PRETTY_WITH_COLORS: + description: > + Use color for mod log levels. + value: 0 + + LOG_CONSOLE_PRETTY_WITH_TIMESTAMP: + description: > + Print timestamp in us. + Turned off by default when CONSOLE_TICKS is on. + value: 1 + LOG_FLAGS_IMAGE_HASH: description: > Enable logging of the first 4 bytes of the image hash. 0 - disable; @@ -155,5 +171,8 @@ syscfg.defs: the global index to be sequentially increasing for persisted logs. value: 0 +syscfg.vals.CONSOLE_TICKS: + LOG_CONSOLE_PRETTY_WITH_TIMESTAMP: 0 + syscfg.vals.LOG_NEWTMGR: LOG_MGMT: MYNEWT_VAL(LOG_MGMT)