feat(log): Refactoring timestamp APIs (move only)

components/log/CMakeLists.txt

@@ -1,6 +1,16 @@
 idf_build_get_property(target IDF_TARGET)
 
-set(srcs "")
+if(BOOTLOADER_BUILD)
+    set(system_target "noos")
+else()
+    if(${target} STREQUAL "linux")
+        set(system_target "linux")
+    else()
+        set(system_target "os")
+    endif()
+endif()
+
+set(srcs "src/${system_target}/log_timestamp.c")
 set(priv_requires "")
 
 if(BOOTLOADER_BUILD)

components/log/include/esp_log.h

@@ -14,6 +14,7 @@
 #include "esp_rom_sys.h"
 #include "esp_log_level.h"
 #include "esp_log_buffer.h"
+#include "esp_log_timestamp.h"
 
 #ifdef __cplusplus
 extern "C" {
@@ -37,45 +38,6 @@ typedef int (*vprintf_like_t)(const char *, va_list);
  */
 vprintf_like_t esp_log_set_vprintf(vprintf_like_t func);
 
-/**
- * @brief Function which returns timestamp to be used in log output
- *
- * This function is used in expansion of ESP_LOGx macros.
- * In the 2nd stage bootloader, and at early application startup stage
- * this function uses CPU cycle counter as time source. Later when
- * FreeRTOS scheduler start running, it switches to FreeRTOS tick count.
- *
- * For now, we ignore millisecond counter overflow.
- *
- * @return timestamp, in milliseconds
- */
-uint32_t esp_log_timestamp(void);
-
-/**
- * @brief Function which returns system timestamp to be used in log output
- *
- * This function is used in expansion of ESP_LOGx macros to print
- * the system time as "HH:MM:SS.sss". The system time is initialized to
- * 0 on startup, this can be set to the correct time with an SNTP sync,
- * or manually with standard POSIX time functions.
- *
- * Currently, this will not get used in logging from binary blobs
- * (i.e. Wi-Fi & Bluetooth libraries), these will still print the RTOS tick time.
- *
- * @return timestamp, in "HH:MM:SS.sss"
- */
-char* esp_log_system_timestamp(void);
-
-/**
- * @brief Function which returns timestamp to be used in log output
- *
- * This function uses HW cycle counter and does not depend on OS,
- * so it can be safely used after application crash.
- *
- * @return timestamp, in milliseconds
- */
-uint32_t esp_log_early_timestamp(void);
-
 /**
  * @brief Write message into the log
  *

components/log/include/esp_log_timestamp.h

@@ -0,0 +1,56 @@
+/*
+ * SPDX-FileCopyrightText: 2015-2024 Espressif Systems (Shanghai) CO LTD
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+#pragma once
+
+#include <stdint.h>
+
+#ifdef __cplusplus
+extern "C" {
+#endif
+
+/**
+ * @brief Function which returns timestamp to be used in log output
+ *
+ * This function is used in expansion of ESP_LOGx macros.
+ * In the 2nd stage bootloader, and at early application startup stage
+ * this function uses CPU cycle counter as time source. Later when
+ * FreeRTOS scheduler start running, it switches to FreeRTOS tick count.
+ *
+ * For now, we ignore millisecond counter overflow.
+ *
+ * @return timestamp, in milliseconds
+ */
+uint32_t esp_log_timestamp(void);
+
+/**
+ * @brief Function which returns system timestamp to be used in log output
+ *
+ * This function is used in expansion of ESP_LOGx macros to print
+ * the system time as "HH:MM:SS.sss". The system time is initialized to
+ * 0 on startup, this can be set to the correct time with an SNTP sync,
+ * or manually with standard POSIX time functions.
+ *
+ * Currently, this will not get used in logging from binary blobs
+ * (i.e. Wi-Fi & Bluetooth libraries), these will still print the RTOS tick time.
+ *
+ * @return timestamp, in "HH:MM:SS.sss"
+ */
+char* esp_log_system_timestamp(void);
+
+/**
+ * @brief Function which returns timestamp to be used in log output
+ *
+ * This function uses HW cycle counter and does not depend on OS,
+ * so it can be safely used after application crash.
+ *
+ * @return timestamp, in milliseconds
+ */
+uint32_t esp_log_early_timestamp(void);
+
+#ifdef __cplusplus
+}
+#endif

components/log/linker.lf

@@ -2,8 +2,5 @@
 archive: liblog.a
 entries:
     log_write:esp_log_write (noflash)
-    log_freertos:esp_log_timestamp (noflash)
-    log_freertos:esp_log_early_timestamp (noflash)
-    log_freertos:esp_log_impl_lock (noflash)
-    log_freertos:esp_log_impl_lock_timeout (noflash)
-    log_freertos:esp_log_impl_unlock (noflash)
+    log_timestamp:esp_log_timestamp (noflash)
+    log_timestamp:esp_log_early_timestamp (noflash)

components/log/log_freertos.c

@@ -1,18 +1,13 @@
 /*
- * SPDX-FileCopyrightText: 2015-2021 Espressif Systems (Shanghai) CO LTD
+ * SPDX-FileCopyrightText: 2015-2024 Espressif Systems (Shanghai) CO LTD
  *
  * SPDX-License-Identifier: Apache-2.0
  */
 
-#include <stdint.h>
-#include <time.h>
-#include <sys/time.h>
 #include "freertos/FreeRTOS.h"
 #include "freertos/task.h"
 #include "freertos/semphr.h"
-#include "esp_cpu.h" // for esp_cpu_get_cycle_count()
 #include "esp_compiler.h"
-#include "esp_log.h"
 #include "esp_private/log_lock.h"
 
 // Maximum time to wait for the mutex in a logging statement.
@@ -54,68 +49,3 @@ void esp_log_impl_unlock(void)
     }
     xSemaphoreGive(s_log_mutex);
 }
-
-char *esp_log_system_timestamp(void)
-{
-    static char buffer[18] = {0};
-    static _lock_t bufferLock = 0;
-
-    if (xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED) {
-        uint32_t timestamp = esp_log_early_timestamp();
-        for (uint8_t i = 0; i < sizeof(buffer); i++) {
-            if ((timestamp > 0) || (i == 0)) {
-                for (uint8_t j = sizeof(buffer) - 1; j > 0; j--) {
-                    buffer[j] = buffer[j - 1];
-                }
-                buffer[0] = (char)(timestamp % 10) + '0';
-                timestamp /= 10;
-            } else {
-                buffer[i] = 0;
-                break;
-            }
-        }
-        return buffer;
-    } else {
-        struct timeval tv;
-        struct tm timeinfo;
-
-        gettimeofday(&tv, NULL);
-        localtime_r(&tv.tv_sec, &timeinfo);
-
-        _lock_acquire(&bufferLock);
-        snprintf(buffer, sizeof(buffer),
-                 "%02d:%02d:%02d.%03ld",
-                 timeinfo.tm_hour,
-                 timeinfo.tm_min,
-                 timeinfo.tm_sec,
-                 tv.tv_usec / 1000);
-        _lock_release(&bufferLock);
-
-        return buffer;
-    }
-}
-
-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);
-}
-
-/* FIXME: define an API for getting the timestamp in soc/hal IDF-2351 */
-uint32_t esp_log_early_timestamp(void)
-{
-#if CONFIG_IDF_TARGET_ESP32
-    /* ESP32 ROM stores separate clock rate values for each CPU, but we want the PRO CPU value always */
-    extern uint32_t g_ticks_per_us_pro;
-    return esp_cpu_get_cycle_count() / (g_ticks_per_us_pro * 1000);
-#else
-    return esp_cpu_get_cycle_count() / (esp_rom_get_cpu_ticks_per_us() * 1000);
-#endif
-}

components/log/log_linux.c

@@ -5,9 +5,7 @@
  */
 
 #include <pthread.h>
-#include <time.h>
 #include <assert.h>
-#include <stdint.h>
 #include "esp_private/log_lock.h"
 
 static pthread_mutex_t mutex1 = PTHREAD_MUTEX_INITIALIZER;
@@ -27,12 +25,3 @@ void esp_log_impl_unlock(void)
 {
     assert(pthread_mutex_unlock(&mutex1) == 0);
 }
-
-uint32_t esp_log_timestamp(void)
-{
-    struct timespec current_time;
-    int result = clock_gettime(CLOCK_MONOTONIC, &current_time);
-    assert(result == 0);
-    uint32_t milliseconds = current_time.tv_sec * 1000 + current_time.tv_nsec / 1000000;
-    return milliseconds;
-}

components/log/log_noos.c

@@ -1,13 +1,11 @@
 /*
- * SPDX-FileCopyrightText: 2019-2021 Espressif Systems (Shanghai) CO LTD
+ * SPDX-FileCopyrightText: 2019-2024 Espressif Systems (Shanghai) CO LTD
  *
  * SPDX-License-Identifier: Apache-2.0
  */
 
 #include <assert.h>
 #include "esp_private/log_lock.h"
-#include "esp_rom_sys.h"
-#include "esp_cpu.h"
 
 static int s_lock = 0;
 
@@ -28,11 +26,3 @@ void esp_log_impl_unlock(void)
     assert(s_lock == 1);
     s_lock = 0;
 }
-
-/* FIXME: define an API for getting the timestamp in soc/hal IDF-2351 */
-uint32_t esp_log_early_timestamp(void)
-{
-    return esp_cpu_get_cycle_count() / (esp_rom_get_cpu_ticks_per_us() * 1000);
-}
-
-uint32_t esp_log_timestamp(void) __attribute__((alias("esp_log_early_timestamp")));

components/log/src/linux/log_timestamp.c

@@ -0,0 +1,18 @@
+/*
+ * SPDX-FileCopyrightText: 2010-2024 Espressif Systems (Shanghai) CO LTD
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+#include <assert.h>
+#include <time.h>
+#include "esp_log_timestamp.h"
+
+uint32_t esp_log_timestamp(void)
+{
+    struct timespec current_time;
+    int result = clock_gettime(CLOCK_MONOTONIC, &current_time);
+    assert(result == 0);
+    uint32_t milliseconds = current_time.tv_sec * 1000 + current_time.tv_nsec / 1000000;
+    return milliseconds;
+}

components/log/src/noos/log_timestamp.c

@@ -0,0 +1,17 @@
+/*
+ * SPDX-FileCopyrightText: 2019-2024 Espressif Systems (Shanghai) CO LTD
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+#include "esp_rom_sys.h"
+#include "esp_cpu.h"
+#include "esp_log_timestamp.h"
+
+/* FIXME: define an API for getting the timestamp in soc/hal IDF-2351 */
+uint32_t esp_log_early_timestamp(void)
+{
+    return esp_cpu_get_cycle_count() / (esp_rom_get_cpu_ticks_per_us() * 1000);
+}
+
+uint32_t esp_log_timestamp(void) __attribute__((alias("esp_log_early_timestamp")));

components/log/src/os/log_timestamp.c

@@ -0,0 +1,85 @@
+/*
+ * SPDX-FileCopyrightText: 2015-2024 Espressif Systems (Shanghai) CO LTD
+ *
+ * SPDX-License-Identifier: Apache-2.0
+ */
+
+#include <time.h>
+#include <sys/time.h>
+#include "freertos/FreeRTOS.h"
+#include "freertos/task.h"
+#include "esp_cpu.h" // for esp_cpu_get_cycle_count()
+#include "esp_compiler.h"
+#include "esp_private/log_util.h"
+#include "esp_private/log_lock.h"
+#include "esp_log_timestamp.h"
+
+static inline bool is_early_log(void)
+{
+    return xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED;
+}
+
+char *esp_log_system_timestamp(void)
+{
+    static char buffer[18] = {0};
+    static _lock_t bufferLock = 0;
+
+    if (is_early_log()) {
+        uint32_t timestamp = esp_log_early_timestamp();
+        for (uint8_t i = 0; i < sizeof(buffer); i++) {
+            if ((timestamp > 0) || (i == 0)) {
+                for (uint8_t j = sizeof(buffer) - 1; j > 0; j--) {
+                    buffer[j] = buffer[j - 1];
+                }
+                buffer[0] = (char)(timestamp % 10) + '0';
+                timestamp /= 10;
+            } else {
+                buffer[i] = 0;
+                break;
+            }
+        }
+        return buffer;
+    } else {
+        struct timeval tv;
+        struct tm timeinfo;
+
+        gettimeofday(&tv, NULL);
+        localtime_r(&tv.tv_sec, &timeinfo);
+
+        _lock_acquire(&bufferLock);
+        snprintf(buffer, sizeof(buffer),
+                 "%02d:%02d:%02d.%03ld",
+                 timeinfo.tm_hour,
+                 timeinfo.tm_min,
+                 timeinfo.tm_sec,
+                 tv.tv_usec / 1000);
+        _lock_release(&bufferLock);
+
+        return buffer;
+    }
+}
+
+uint32_t esp_log_timestamp(void)
+{
+    if (unlikely(is_early_log())) {
+        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);
+}
+
+/* FIXME: define an API for getting the timestamp in soc/hal IDF-2351 */
+uint32_t esp_log_early_timestamp(void)
+{
+#if CONFIG_IDF_TARGET_ESP32
+    /* ESP32 ROM stores separate clock rate values for each CPU, but we want the PRO CPU value always */
+    extern uint32_t g_ticks_per_us_pro;
+    return esp_cpu_get_cycle_count() / (g_ticks_per_us_pro * 1000);
+#else
+    return esp_cpu_get_cycle_count() / (esp_rom_get_cpu_ticks_per_us() * 1000);
+#endif
+}

docs/doxygen/Doxyfile

@@ -271,6 +271,7 @@ INPUT = \
     $(PROJECT_PATH)/components/log/include/esp_log.h \
     $(PROJECT_PATH)/components/log/include/esp_log_level.h \
     $(PROJECT_PATH)/components/log/include/esp_log_buffer.h \
+    $(PROJECT_PATH)/components/log/include/esp_log_timestamp.h \
     $(PROJECT_PATH)/components/lwip/include/apps/esp_sntp.h \
     $(PROJECT_PATH)/components/lwip/include/apps/ping/ping_sock.h \
     $(PROJECT_PATH)/components/mbedtls/esp_crt_bundle/include/esp_crt_bundle.h \

docs/en/api-reference/system/log.rst

@@ -153,3 +153,4 @@ API Reference
 .. include-build-file:: inc/esp_log.inc
 .. include-build-file:: inc/esp_log_level.inc
 .. include-build-file:: inc/esp_log_buffer.inc
+.. include-build-file:: inc/esp_log_timestamp.inc

docs/zh_CN/api-reference/system/log.rst

@@ -135,3 +135,6 @@ API 参考
 -------------
 
 .. include-build-file:: inc/esp_log.inc
+.. include-build-file:: inc/esp_log_level.inc
+.. include-build-file:: inc/esp_log_buffer.inc
+.. include-build-file:: inc/esp_log_timestamp.inc