ESP_LOGx 消息中日志级别后的数字表示什么?

问题描述 投票:0回答:2

这是在同一核心上运行两个具有不同优先级的任务的示例程序,其中任务函数记录任务名称、coreId 和演示计数器。

#include <freertos/FreeRTOS.h>
#include <freertos/task.h>
#include <esp_log.h>

_Noreturn void taskFunction(void *taskParams);

_Noreturn void app_main(void) {
    const char *task1Name = "Running Task 1";
    const char *task2Name = "Running Task 2";
    xTaskCreatePinnedToCore(taskFunction, "Task1", 2048, (void *) task1Name, 1, NULL, 1);
    xTaskCreatePinnedToCore(taskFunction, "Task2", 2048, (void *) task2Name, 2, NULL, 1);
    for (;;);
}

void taskFunction(void *taskParams) {
    int counter = 0;
    const char *taskName = taskParams;
    for (;;) {
        ESP_LOGI(taskName, "on core %d counter %d\r\n", xPortGetCoreID(), ++counter);
        vTaskDelay(1000 / portTICK_RATE_MS);
    }
}

及其日志

I (305) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (0) Running Task 2: on core 1 counter 1

I (0) Running Task 1: on core 1 counter 1

0x40080fd4: call_start_cpu1 at D:/SDKs/ESPIDF/components/esp_system/port/cpu_start.c:141

I (1010) Running Task 2: on core 1 counter 2

I (1010) Running Task 1: on core 1 counter 2

I (2010) Running Task 2: on core 1 counter 3

I (2010) Running Task 1: on core 1 counter 3

I (3010) Running Task 2: on core 1 counter 4

I (3010) Running Task 1: on core 1 counter 4

I (4010) Running Task 2: on core 1 counter 5

I (4010) Running Task 1: on core 1 counter 5

E (10315) task_wdt: Task watchdog got triggered. The following tasks did not reset the watchdog in time:
E (10315) task_wdt:  - IDLE (CPU 0)
E (10315) task_wdt: Tasks currently running:
E (10315) task_wdt: CPU 0: main
E (10315) task_wdt: CPU 1: IDLE
E (10315) task_wdt: Print CPU 0 (current core) backtrace
...
...
...

I (16375) Running Task 2: on core 1 counter 12

I (16385) Running Task 1: on core 1 counter 12

I (17375) Running Task 2: on core 1 counter 13

I (17385) Running Task 1: on core 1 counter 13

括号中的日志级别后的数字 1010, 2010, ... 表示什么?

对于两个不同的任务,它们在开始时是相同的,而在看门狗定时器被触发后,它们怎么可能会不同?

logging esp32 esp-idf
2个回答
2
投票

当前时间(以毫秒为单位)。

它们可以是相同的,因为你的任务几乎什么都不做; ESP32 可以在一毫秒内切换任务,因此它们在同一毫秒的计时内运行,即使不是在完全相同的时间。

您可以在源代码中亲自查看

#define ESP_LOGI( tag, format, ... ) ESP_LOG_LEVEL_LOCAL(ESP_LOG_INFO,    tag, format, ##__VA_ARGS__)

ESP_LOG_LEVEL_LOCAL

#define ESP_LOG_LEVEL_LOCAL(level, tag, format, ...) do {               \
        if ( LOG_LOCAL_LEVEL >= level ) ESP_LOG_LEVEL(level, tag, format, ##__VA_ARGS__); \
    } while(0)

ESP_LOG_LEVEL

#if CONFIG_LOG_TIMESTAMP_SOURCE_RTOS
#define ESP_LOG_LEVEL(level, tag, format, ...) do {                     \
        if (level==ESP_LOG_ERROR )          { esp_log_write(ESP_LOG_ERROR,      tag, LOG_FORMAT(E, format), esp_log_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else if (level==ESP_LOG_WARN )      { esp_log_write(ESP_LOG_WARN,       tag, LOG_FORMAT(W, format), esp_log_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else if (level==ESP_LOG_DEBUG )     { esp_log_write(ESP_LOG_DEBUG,      tag, LOG_FORMAT(D, format), esp_log_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else if (level==ESP_LOG_VERBOSE )   { esp_log_write(ESP_LOG_VERBOSE,    tag, LOG_FORMAT(V, format), esp_log_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else                                { esp_log_write(ESP_LOG_INFO,       tag, LOG_FORMAT(I, format), esp_log_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
    } while(0)
#elif CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM
#define ESP_LOG_LEVEL(level, tag, format, ...) do {                     \
        if (level==ESP_LOG_ERROR )          { esp_log_write(ESP_LOG_ERROR,      tag, LOG_SYSTEM_TIME_FORMAT(E, format), esp_log_system_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else if (level==ESP_LOG_WARN )      { esp_log_write(ESP_LOG_WARN,       tag, LOG_SYSTEM_TIME_FORMAT(W, format), esp_log_system_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else if (level==ESP_LOG_DEBUG )     { esp_log_write(ESP_LOG_DEBUG,      tag, LOG_SYSTEM_TIME_FORMAT(D, format), esp_log_system_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else if (level==ESP_LOG_VERBOSE )   { esp_log_write(ESP_LOG_VERBOSE,    tag, LOG_SYSTEM_TIME_FORMAT(V, format), esp_log_system_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
        else                                { esp_log_write(ESP_LOG_INFO,       tag, LOG_SYSTEM_TIME_FORMAT(I, format), esp_log_system_timestamp(), tag __VA_OPT__(,) __VA_ARGS__); } \
    } while(0)
#endif //CONFIG_LOG_TIMESTAMP_SOURCE_xxx
#else // !(defined(__cplusplus) && (__cplusplus >  201703L))
#if CONFIG_LOG_TIMESTAMP_SOURCE_RTOS
#define ESP_LOG_LEVEL(level, tag, format, ...) do {                     \
        if (level==ESP_LOG_ERROR )          { esp_log_write(ESP_LOG_ERROR,      tag, LOG_FORMAT(E, format), esp_log_timestamp(), tag, ##__VA_ARGS__); } \
        else if (level==ESP_LOG_WARN )      { esp_log_write(ESP_LOG_WARN,       tag, LOG_FORMAT(W, format), esp_log_timestamp(), tag, ##__VA_ARGS__); } \
        else if (level==ESP_LOG_DEBUG )     { esp_log_write(ESP_LOG_DEBUG,      tag, LOG_FORMAT(D, format), esp_log_timestamp(), tag, ##__VA_ARGS__); } \
        else if (level==ESP_LOG_VERBOSE )   { esp_log_write(ESP_LOG_VERBOSE,    tag, LOG_FORMAT(V, format), esp_log_timestamp(), tag, ##__VA_ARGS__); } \
        else                                { esp_log_write(ESP_LOG_INFO,       tag, LOG_FORMAT(I, format), esp_log_timestamp(), tag, ##__VA_ARGS__); } \
    } while(0)
#elif CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM
#define ESP_LOG_LEVEL(level, tag, format, ...) do {                     \
        if (level==ESP_LOG_ERROR )          { esp_log_write(ESP_LOG_ERROR,      tag, LOG_SYSTEM_TIME_FORMAT(E, format), esp_log_system_timestamp(), tag, ##__VA_ARGS__); } \
        else if (level==ESP_LOG_WARN )      { esp_log_write(ESP_LOG_WARN,       tag, LOG_SYSTEM_TIME_FORMAT(W, format), esp_log_system_timestamp(), tag, ##__VA_ARGS__); } \
        else if (level==ESP_LOG_DEBUG )     { esp_log_write(ESP_LOG_DEBUG,      tag, LOG_SYSTEM_TIME_FORMAT(D, format), esp_log_system_timestamp(), tag, ##__VA_ARGS__); } \
        else if (level==ESP_LOG_VERBOSE )   { esp_log_write(ESP_LOG_VERBOSE,    tag, LOG_SYSTEM_TIME_FORMAT(V, format), esp_log_system_timestamp(), tag, ##__VA_ARGS__); } \
        else                                { esp_log_write(ESP_LOG_INFO,       tag, LOG_SYSTEM_TIME_FORMAT(I, format), esp_log_system_timestamp(), tag, ##__VA_ARGS__); } \
    } while(0)
#endif //CONFIG_LOG_TIMESTAMP_SOURCE_xxx

最后一个是调用实际的 C 日志记录函数的地方。正如您所看到的,它传递了一个时间戳 - 系统可以配置为选择时间戳的来源。

如果您想了解 printf() 黑客是如何工作的,您可以继续追踪到

C 日志记录功能


0
投票

事实上,情况并非如此。 请注意,两个日志时间戳函数 esp_log_timestamp() 和 esp_log_system_timestamp() esp_log_system_timestamp() 输入 10 毫秒时间格式 hh:mm:ss:xxx。这里不做解释。 只需查看 esp_log_timestamp() 代码即可:

uint32_t esp_log_timestamp(void){
if (unlikely(xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED)) {
    return esp_log_early_timestamp();
}
static uint32_t base = 0;
if (base == 0 && xPortGetCoreID() == 0) {
    base = esp_log_early_timestamp();
}
TickType_t tick_count = xPortInIsrContext() ? xTaskGetTickCountFromISR() : xTaskGetTickCount();
return base + tick_count * (1000 / configTICK_RATE_HZ);

}

请注意最后一行。

return base + tick_count * (1000 / configTICK_RATE_HZ);

configTICK_RATE_HZ其实是一个FreeRTOS配置项,默认值为100,tick_count实际需要*10,即10毫秒的数据。 如果需要输出时间单位为毫秒。需要修改MenuConfig中/FreeRTOS的RATE_HZ

© www.soinside.com 2019 - 2024. All rights reserved.