Added option to use datetime stamp during logging. (IDFGH-3855)

components/log/Kconfig

@@ -59,15 +59,21 @@ menu "Log output"
               initialized to 0 on startup, it can be set with an SNTP sync, or with
               POSIX time functions. This time will not reset after a software reboot.
               e.g. (00:01:30.000)
+
+            - System date and time is the same as the system time, but also includes
+              year, month, and day. It is initialized to 1970-01-01 00:00:00.000 on startup.
+              e.g. (2020-01-31 00:01:30.000)
 
-            - NOTE: Currently this will not get used in logging from binary blobs
+            - NOTE: Currently system timestamps will not get used in logging from binary blobs
               (i.e WiFi & Bluetooth libraries), these will always print
               milliseconds since boot.
 
         config LOG_TIMESTAMP_SOURCE_RTOS
             bool "Milliseconds Since Boot"
         config LOG_TIMESTAMP_SOURCE_SYSTEM
             bool "System Time"
+        config LOG_TIMESTAMP_SOURCE_SYSTEM_DATETIME
+            bool "System Date and Time"
     endchoice
 
 endmenu

components/log/include/esp_log.h

@@ -106,6 +106,22 @@ uint32_t esp_log_timestamp(void);
  */
 char* esp_log_system_timestamp(void);
 
+/**
+ * @brief Function which returns system datetimestamp to be used in log output
+ *
+ * This function is used in expansion of ESP_LOGx macros to print
+ * the system date and time as "YYYY-mm-DD HH:MM:SS.sss". 
+ * The system date is initialized to 1970-01-01 00:00:00.000 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 WiFi & Bluetooth libraries), these will still print the RTOS tick time.
+ *
+ * @return datetimestamp, in "YYYY-mm-DD HH:MM:SS.sss"
+ */
+char* esp_log_system_datetimestamp(void);
+
 /**
  * @brief Function which returns timestamp to be used in log output
  *
@@ -341,6 +357,14 @@ void esp_log_writev(esp_log_level_t level, const char* tag, const char* format,
         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)
+#elif CONFIG_LOG_TIMESTAMP_SOURCE_SYSTEM_DATETIME
+#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_datetimestamp(), 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_datetimestamp(), 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_datetimestamp(), 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_datetimestamp(), tag, ##__VA_ARGS__); } \
+        else                                { esp_log_write(ESP_LOG_INFO,       tag, LOG_SYSTEM_TIME_FORMAT(I, format), esp_log_system_datetimestamp(), tag, ##__VA_ARGS__); } \
+    } while(0)    
 #endif //CONFIG_LOG_TIMESTAMP_SOURCE_xxx
 
 /** runtime macro to output logs at a specified level. Also check the level with ``LOG_LOCAL_LEVEL``.

components/log/log_freertos.c

@@ -50,11 +50,8 @@ void esp_log_impl_unlock(void)
     xSemaphoreGive(s_log_mutex);
 }
 
-char *esp_log_system_timestamp(void)
+static bool esp_log_system_early_timestamp(char *buffer)
 {
-    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++) {
@@ -69,6 +66,44 @@ char *esp_log_system_timestamp(void)
                 break;
             }
         }
+        return ESP_OK;
+    }
+    return ESP_FAIL;
+}
+
+char *esp_log_system_timestamp(void)
+{
+    static char buffer[13] = {0};
+    static _lock_t bufferLock = 0;
+
+    if (esp_log_system_early_timestamp(buffer) == ESP_OK) {
+        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),
+                 "%02u:%02u:%02u.%03lu",
+                 timeinfo.tm_hour,
+                 timeinfo.tm_min,
+                 timeinfo.tm_sec,
+                 tv.tv_usec / 1000);
+        _lock_release(&bufferLock);
+
+        return buffer;
+    }
+}
+
+char *esp_log_system_datetimestamp(void)
+{
+    static char buffer[24] = {0};
+    static _lock_t bufferLock = 0;
+
+    if (esp_log_system_early_timestamp(buffer) == ESP_OK) {
         return buffer;
     } else {
         struct timeval tv;
@@ -79,7 +114,10 @@ char *esp_log_system_timestamp(void)
 
         _lock_acquire(&bufferLock);
         snprintf(buffer, sizeof(buffer),
-                 "%02d:%02d:%02d.%03ld",
+                 "%04u-%02u-%02u %02u:%02u:%02u.%03lu",
+                 timeinfo.tm_year+1900,
+                 timeinfo.tm_mon+1,
+                 timeinfo.tm_mday,
                  timeinfo.tm_hour,
                  timeinfo.tm_min,
                  timeinfo.tm_sec,