Crash_Override/OVMS3-idf
1
0
Fork 0
Code Issues Pull requests Projects Releases Wiki Activity

Merge branch 'feature/log_system_time' into 'master'

Browse source 
log: Add menuconfig option to log system time rather than RTOS time

See merge request espressif/esp-idf!6103
This commit is contained in:
Angus Gratton 2019-10-16 14:56:14 +08:00
commit 65940cc0da
3 changed files with 93 additions and 0 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

25
components/log/Kconfig
View file

@ -44,5 +44,30 @@ menu "Log output"
In order to view these, your terminal program must support ANSI color codes.
choice LOG_TIMESTAMP_SOURCE
prompt "Log Timestamps"
default LOG_TIMESTAMP_SOURCE_RTOS
help
Choose what sort of timestamp is displayed in the log output:
- Milliseconds since boot is calulated from the RTOS tick count multiplied
by the tick period. This time will reset after a software reboot.
e.g. (90000)
- System time is taken from POSIX time functions which use the ESP32's
RTC and FRC1 timers to maintain an accurate time. The system time is
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)
- NOTE: Currently this 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"
endchoice
endmenu

26
components/log/include/esp_log.h
View file

@ -86,6 +86,21 @@ vprintf_like_t esp_log_set_vprintf(vprintf_like_t func);
*/
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 WiFi & 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
*
@ -242,6 +257,7 @@ void esp_log_write(esp_log_level_t level, const char* tag, const char* format, .
#endif //CONFIG_LOG_COLORS
#define LOG_FORMAT(letter, format) LOG_COLOR_ ## letter #letter " (%d) %s: " format LOG_RESET_COLOR "\n"
#define LOG_SYSTEM_TIME_FORMAT(letter, format) LOG_COLOR_ ## letter #letter " (%s) %s: " format LOG_RESET_COLOR "\n"
/** @endcond */
@ -295,6 +311,7 @@ void esp_log_write(esp_log_level_t level, const char* tag, const char* format, .
*
* @see ``printf``
*/
#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__); } \
@ -302,6 +319,15 @@ void esp_log_write(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_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
/** runtime macro to output logs at a specified level. Also check the level with ``LOG_LOCAL_LEVEL``.
*

42
components/log/log.c
View file

@ -53,6 +53,8 @@
#include <stdio.h>
#include <assert.h>
#include <ctype.h>
#include <time.h>
#include <sys/time.h>
#include "esp_log.h"
@ -332,6 +334,46 @@ uint32_t ATTR esp_log_early_timestamp(void)
#ifndef BOOTLOADER_BUILD
char* IRAM_ATTR 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 IRAM_ATTR esp_log_timestamp(void)
{
if (xTaskGetSchedulerState() == taskSCHEDULER_NOT_STARTED) {