From 6bd95801374da49eb4076a99af5356807a91e79c Mon Sep 17 00:00:00 2001 From: Angus Gratton Date: Thu, 11 Mar 2021 20:17:21 +1100 Subject: [PATCH] log: Allow setting maximum log level higher than default Main change is possibility the log cache locking functions will be called before the scheduler has started. This change doesn't change the behaviour of ESP_EARLY_LOGx, this is done in the following commit. Closes https://github.com/espressif/esp-idf/issues/5542 --- components/log/Kconfig | 54 ++++++++++++++++++++++++++++++-- components/log/include/esp_log.h | 4 +-- components/log/log_freertos.c | 20 ++++++++++-- 3 files changed, 70 insertions(+), 8 deletions(-) diff --git a/components/log/Kconfig b/components/log/Kconfig index 1c624a216b..e6b135c3d4 100644 --- a/components/log/Kconfig +++ b/components/log/Kconfig @@ -8,10 +8,11 @@ menu "Log output" You can set lower verbosity level at runtime using esp_log_level_set function. - Note that this setting limits which log statements - are compiled into the program. So setting this to, say, + By default, this setting limits which log statements + are compiled into the program. For example, selecting "Warning" would mean that changing log level to "Debug" - at runtime will not be possible. + at runtime will not be possible. To allow increasing log + level above the default at runtime, see the next option. config LOG_DEFAULT_LEVEL_NONE bool "No output" @@ -36,6 +37,53 @@ menu "Log output" default 4 if LOG_DEFAULT_LEVEL_DEBUG default 5 if LOG_DEFAULT_LEVEL_VERBOSE + choice LOG_MAXIMUM_LEVEL + bool "Maximum log verbosity" + default LOG_MAXIMUM_EQUALS_DEFAULT + help + This config option sets the highest log verbosity that it's possible to select + at runtime by calling esp_log_level_set(). This level may be higher than + the default verbosity level which is set when the app starts up. + + This can be used enable debugging output only at a critical point, for a particular + tag, or to minimize startup time but then enable more logs once the firmware has + loaded. + + Note that increasing the maximum available log level will increase the firmware + binary size. + + This option only applies to logging from the app, the bootloader log level is + fixed at compile time to the separate "Bootloader log verbosity" setting. + + config LOG_MAXIMUM_EQUALS_DEFAULT + bool "Same as default" + config LOG_MAXIMUM_LEVEL_ERROR + bool "Error" + depends on LOG_DEFAULT_LEVEL < 1 + config LOG_MAXIMUM_LEVEL_WARN + bool "Warning" + depends on LOG_DEFAULT_LEVEL < 2 + config LOG_MAXIMUM_LEVEL_INFO + bool "Info" + depends on LOG_DEFAULT_LEVEL < 3 + config LOG_MAXIMUM_LEVEL_DEBUG + bool "Debug" + depends on LOG_DEFAULT_LEVEL < 4 + config LOG_MAXIMUM_LEVEL_VERBOSE + bool "Verbose" + depends on LOG_DEFAULT_LEVEL < 5 + endchoice + + config LOG_MAXIMUM_LEVEL + int + default LOG_DEFAULT_LEVEL if LOG_MAXIMUM_EQUALS_DEFAULT + default 0 if LOG_MAXIMUM_LEVEL_NONE + default 1 if LOG_MAXIMUM_LEVEL_ERROR + default 2 if LOG_MAXIMUM_LEVEL_WARN + default 3 if LOG_MAXIMUM_LEVEL_INFO + default 4 if LOG_MAXIMUM_LEVEL_DEBUG + default 5 if LOG_MAXIMUM_LEVEL_VERBOSE + config LOG_COLORS bool "Use ANSI terminal colors in log output" default "y" diff --git a/components/log/include/esp_log.h b/components/log/include/esp_log.h index 1f3c17139c..131e093e9f 100644 --- a/components/log/include/esp_log.h +++ b/components/log/include/esp_log.h @@ -46,7 +46,7 @@ typedef int (*vprintf_like_t)(const char *, va_list); * If logging for given component has already been enabled, changes previous setting. * * Note that this function can not raise log level above the level set using - * CONFIG_LOG_DEFAULT_LEVEL setting in menuconfig. + * CONFIG_LOG_MAXIMUM_LEVEL setting in menuconfig. * * To raise log level above the default one for a given file, define * LOG_LOCAL_LEVEL to one of the ESP_LOG_* values, before including @@ -137,7 +137,7 @@ void esp_log_writev(esp_log_level_t level, const char* tag, const char* format, #ifndef LOG_LOCAL_LEVEL #ifndef BOOTLOADER_BUILD -#define LOG_LOCAL_LEVEL CONFIG_LOG_DEFAULT_LEVEL +#define LOG_LOCAL_LEVEL CONFIG_LOG_MAXIMUM_LEVEL #else #define LOG_LOCAL_LEVEL CONFIG_BOOTLOADER_LOG_LEVEL #endif diff --git a/components/log/log_freertos.c b/components/log/log_freertos.c index 25308761c3..6caf8b4e31 100644 --- a/components/log/log_freertos.c +++ b/components/log/log_freertos.c @@ -11,11 +11,16 @@ #include "freertos/task.h" #include "freertos/semphr.h" #include "hal/cpu_hal.h" // for cpu_hal_get_cycle_count() +#include "esp_compiler.h" #include "esp_log.h" #include "esp_log_private.h" // Maximum time to wait for the mutex in a logging statement. +// +// We don't expect this to happen in most cases, as contention is low. The most likely case is if a +// log function is called from an ISR (technically caller should use the ISR-friendly logging macros but +// possible they use the normal one instead and disable the log type by tag). #define MAX_MUTEX_WAIT_MS 10 #define MAX_MUTEX_WAIT_TICKS ((MAX_MUTEX_WAIT_MS + portTICK_PERIOD_MS - 1) / portTICK_PERIOD_MS) @@ -23,22 +28,31 @@ static SemaphoreHandle_t s_log_mutex = NULL; void esp_log_impl_lock(void) { - if (!s_log_mutex) { + if (unlikely(!s_log_mutex)) { s_log_mutex = xSemaphoreCreateMutex(); } + if (unlikely(xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED)) { + return; + } xSemaphoreTake(s_log_mutex, portMAX_DELAY); } bool esp_log_impl_lock_timeout(void) { - if (!s_log_mutex) { + if (unlikely(!s_log_mutex)) { s_log_mutex = xSemaphoreCreateMutex(); } + if (unlikely(xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED)) { + return true; + } return xSemaphoreTake(s_log_mutex, MAX_MUTEX_WAIT_TICKS) == pdTRUE; } void esp_log_impl_unlock(void) { + if (unlikely(xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED)) { + return; + } xSemaphoreGive(s_log_mutex); } @@ -84,7 +98,7 @@ char *esp_log_system_timestamp(void) uint32_t esp_log_timestamp(void) { - if (xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED) { + if (unlikely(xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED)) { return esp_log_early_timestamp(); } static uint32_t base = 0;