[ESP32] Use esp_log_writev() for logging rather than ESP_LOGx macros (#…

…26348)

* [ESP32] Use esp_log_writev() for logging rather than ESP_LOGx macros

Basically this unreverts the #26282 with additional changes to fixed
the rpc logging problem introduced in #26227.

* Fix the bug when setting the log level

* remove the log level check

* Fix the color codes for pigweed logs

* Added comment explaining the addition of color codes in pigweed logger

config/esp32/components/chip/CMakeLists.txt

@@ -86,10 +86,29 @@ chip_gn_arg_append("esp32_cpu" "\"esp32\"")
 chip_gn_arg_bool("is_debug" ${is_debug})
 
 # Config the chip log level by IDF menuconfig
-chip_gn_arg_bool ("chip_error_logging" CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 1)
-chip_gn_arg_bool ("chip_progress_logging" CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 3)
-chip_gn_arg_bool ("chip_detail_logging" CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 4)
-chip_gn_arg_bool ("chip_automation_logging" CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 5)
+if (CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 1)
+ chip_gn_arg_bool ("chip_error_logging" "true")
+else()
+ chip_gn_arg_bool ("chip_error_logging" "false")
+endif()
+
+if (CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 3)
+ chip_gn_arg_bool ("chip_progress_logging" "true")
+else()
+ chip_gn_arg_bool ("chip_progress_logging" "false")
+endif()
+
+if (CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 4)
+ chip_gn_arg_bool ("chip_detail_logging" "true")
+else()
+ chip_gn_arg_bool ("chip_detail_logging" "false")
+endif()
+
+if (CONFIG_LOG_DEFAULT_LEVEL GREATER_EQUAL 5)
+ chip_gn_arg_bool ("chip_automation_logging" "true")
+else()
+ chip_gn_arg_bool ("chip_automation_logging" "false")
+endif()
 
 if(CONFIG_ENABLE_CHIPOBLE)
 chip_gn_arg_append("chip_config_network_layer_ble" "true")
@@ -373,8 +392,10 @@ target_link_libraries(${COMPONENT_LIB} INTERFACE -Wl,--start-group
 add_dependencies(${COMPONENT_LIB} chip_gn)
 
 if(CONFIG_ENABLE_PW_RPC)
- set(WRAP_FUNCTIONS esp_log_write)
- target_link_libraries(${COMPONENT_LIB} INTERFACE "-Wl,--wrap=${WRAP_FUNCTIONS}")
+ set(WRAP_FUNCTIONS esp_log_write esp_log_writev)
+ foreach(func ${WRAP_FUNCTIONS})
+ target_link_libraries(${COMPONENT_LIB} INTERFACE "-Wl,--wrap=${func}")
+ endforeach()
 endif()
 
 # Build Matter OTA image

examples/platform/esp32/PigweedLogger.cpp

@@ -86,6 +86,28 @@ SemaphoreHandle_t * getSemaphore()
  return &esp_log_mutex;
 }
 
+static const char * getLogColorForLevel(esp_log_level_t level)
+{
+ switch (level)
+ {
+ case ESP_LOG_ERROR:
+ return LOG_COLOR_E "E";
+
+ case ESP_LOG_INFO:
+ return LOG_COLOR_I "I";
+
+ default:
+ // default is kept as ESP_LOG_DEBUG
+ return LOG_COLOR_D "D";
+ }
+}
+
+// ESP_LOGx(...) logs are funneled to esp_log_write() and it has the specific format. It contains color codes,
+// log level character, timestamp, tag, and actual log message. Everything here is part of format and variadic argument.
+//
+// ChipLogx(...) logs are funneled to esp_log_writev() will only have actual log message without color codes, log level
+// character, timestamp, and tag. So, to match up __wrap_esp_log_writev() adds those details when sending log to pigweed
+// logger.
 extern "C" void __wrap_esp_log_write(esp_log_level_t level, const char * tag, const char * format, ...)
 {
  va_list v;
@@ -107,4 +129,30 @@ extern "C" void __wrap_esp_log_write(esp_log_level_t level, const char * tag, co
  va_end(v);
 }
 
+extern "C" void __wrap_esp_log_writev(esp_log_level_t level, const char * tag, const char * format, va_list v)
+{
+#ifndef CONFIG_LOG_DEFAULT_LEVEL_NONE
+ if (uartInitialised && level <= CONFIG_LOG_MAXIMUM_LEVEL)
+ {
+ const char * logColor = getLogColorForLevel(level);
+ PigweedLogger::putString(logColor, strlen(logColor));
+
+ char formattedMsg[CHIP_CONFIG_LOG_MESSAGE_MAX_SIZE];
+ size_t len = snprintf(formattedMsg, sizeof formattedMsg, " (%u) %s: ", esp_log_timestamp(), tag);
+ PigweedLogger::putString(formattedMsg, len);
+
+ memset(formattedMsg, 0, sizeof formattedMsg);
+ len = vsnprintf(formattedMsg, sizeof formattedMsg, format, v);
+ if (len >= sizeof formattedMsg)
+ {
+ len = sizeof formattedMsg - 1;
+ }
+ PigweedLogger::putString(formattedMsg, len);
+
+ const char * logResetColor = LOG_RESET_COLOR "\n";
+ PigweedLogger::putString(logResetColor, strlen(logResetColor));
+ }
+#endif
+}
+
 } // namespace PigweedLogger

src/platform/ESP32/Logging.cpp

@@ -26,21 +26,35 @@ void ENFORCE_FORMAT(3, 0) LogV(const char * module, uint8_t category, const char
  snprintf(tag, sizeof(tag), "chip[%s]", module);
  tag[sizeof(tag) - 1] = 0;
 
- char formattedMsg[CHIP_CONFIG_LOG_MESSAGE_MAX_SIZE];
- vsnprintf(formattedMsg, sizeof(formattedMsg), msg, v);
-
  switch (category)
  {
- case kLogCategory_Error:
- ESP_LOGE(tag, "%s", formattedMsg);
- break;
+ case kLogCategory_Error: {
+ {
+ printf(LOG_COLOR_E "E (%u) %s: ", esp_log_timestamp(), tag);
+ esp_log_writev(ESP_LOG_ERROR, tag, msg, v);
+ printf(LOG_RESET_COLOR "\n");
+ }
+ }
+ break;
+
  case kLogCategory_Progress:
- default:
- ESP_LOGI(tag, "%s", formattedMsg);
- break;
- case kLogCategory_Detail:
- ESP_LOGD(tag, "%s", formattedMsg);
- break;
+ default: {
+ {
+ printf(LOG_COLOR_I "I (%u) %s: ", esp_log_timestamp(), tag);
+ esp_log_writev(ESP_LOG_INFO, tag, msg, v);
+ printf(LOG_RESET_COLOR "\n");
+ }
+ }
+ break;
+
+ case kLogCategory_Detail: {
+ {
+ printf(LOG_COLOR_D "D (%u) %s: ", esp_log_timestamp(), tag);
+ esp_log_writev(ESP_LOG_DEBUG, tag, msg, v);
+ printf(LOG_RESET_COLOR "\n");
+ }
+ }
+ break;
  }
 }