Merge pull request #12044 from gschorcht/cpu/esp32/log_module_fix

cpu/esp32: improvements and cleanup of log_module

cpu/esp32/Makefile.dep

@@ -84,6 +84,10 @@ ifneq (,$(filter shell,$(USEMODULE)))
     USEMODULE += ps
 endif
 
+ifneq (,$(filter log_color,$(USEMODULE)))
+    USEMODULE += esp_log_colored
+endif
+
 # if SPI RAM is enabled, ESP-IDF heap and quot flash mode have to be used
 ifneq (,$(filter esp_spi_ram,$(USEMODULE)))
     USEMODULE += esp_idf_heap

cpu/esp32/Makefile.include

@@ -67,6 +67,8 @@ PSEUDOMODULES += esp_hw_counter
 PSEUDOMODULES += esp_i2c_sw
 PSEUDOMODULES += esp_i2c_hw
 PSEUDOMODULES += esp_idf_newlib
+PSEUDOMODULES += esp_log_colored
+PSEUDOMODULES += esp_log_tagged
 PSEUDOMODULES += esp_spi_ram
 PSEUDOMODULES += esp_spiffs
 PSEUDOMODULES += esp_wifi_any
@@ -145,6 +147,12 @@ ifeq ($(QEMU), 1)
     CFLAGS += -DQEMU
 endif
 
+ifneq (,$(filter esp_log_colored,$(USEMODULE)))
+    BOOTLOADER_BIN = bootloader_with_colors.bin
+else
+    BOOTLOADER_BIN = bootloader_without_colors.bin
+endif
+
 # LINKFLAGS += -Wl,--verbose
 
 LINKFLAGS += -L$(ESP32_SDK_DIR)/components/esp32
@@ -198,7 +206,7 @@ ifeq ($(QEMU), 1)
     FLASHER = dd
     FFLAGS += if=/dev/zero bs=1M count=4  | tr "\\000" "\\377" > tmp.bin && cat tmp.bin |
     FFLAGS += head -c $$((0x1000)) |
-    FFLAGS += cat - $(RIOTCPU)/$(CPU)/bin/bootloader.bin tmp.bin |
+    FFLAGS += cat - $(RIOTCPU)/$(CPU)/bin/$(BOOTLOADER_BIN) tmp.bin |
     FFLAGS += head -c $$((0x8000)) |
     FFLAGS += cat - $(BINDIR)/partitions.bin tmp.bin |
     FFLAGS += head -c $$((0x10000)) |
@@ -212,7 +220,7 @@ else
     FFLAGS += --chip esp32 -p $(PROG_DEV) -b $(PROGRAMMER_SPEED)
     FFLAGS += --before default_reset --after hard_reset write_flash
     FFLAGS += -z -fm $(FLASH_MODE) -fs detect -ff $(FLASH_FREQ)
-    FFLAGS += 0x1000 $(RIOTCPU)/$(CPU)/bin/bootloader.bin
+    FFLAGS += 0x1000 $(RIOTCPU)/$(CPU)/bin/$(BOOTLOADER_BIN)
     FFLAGS += 0x8000 $(BINDIR)/partitions.bin
     FFLAGS += 0x10000 $(FLASHFILE).bin
 endif

cpu/esp32/doc.txt

@@ -114,6 +114,8 @@ Module    | Default  | Short description
 [esp_hw_counter](#esp32_timers) | not used | use hardware counters for RIOT timers
 [esp_i2c_hw](#esp32_i2c_interfaces) | not used  | use the i2C hardware implementation
 [esp_idf_heap](#esp32_esp_idf_heap_implementation) | not used | enable ESP-IDF heap implementation
+[esp_log_colored](#esp32_esp_log_module) | not used | enable colored log output
+[esp_log_tagged](#esp32_esp_log_module) | not used | add additional information to the log output
 [esp_now](#esp32_esp_now_network_interface) | not used  | enable the ESP-NOW network device
 [esp_spi_ram](#esp32_spi_ram) | not used |  enable SPI RAM
 [esp_spiffs](#esp32_spiffs_device) | not used  |  enable SPIFFS for on-board flash memory
@@ -409,6 +411,8 @@ esp_eth | Enable the Ethernet MAC (EMAC) interface as `netdev` network device, s
 esp_gdb | Enable the compilation with debug information for debugging with [QEMU and GDB](#esp32_qemu_mode_and_gdb) (```QEMU=1```) or via [JTAG interface with OpenOCD](#esp32_jtag_debugging).
 esp_i2c_hw | Use the hardware I2C implementation, see section [I2C Interfaces](#esp32_i2c_interfaces).
 esp_idf_heap | Use the ESP-IDF heap implementation, see section [ESP-IDF Heap Implementation](#esp32_esp_idf_heap_implementation).
+esp_log_colored | Enable colored log output, see section [Log output](#esp32_esp_log_module).
+esp_log_tagged | Add additional information to the log output, see section [Log output](#esp32_esp_log_module).
 esp_now | Enable the built-in WiFi module with the ESP-NOW protocol as `netdev` network device, see section [ESP-NOW Network Interface](#esp32_esp_now_network_interface).
 esp_spiffs  | Enable the optional SPIFFS drive in on-board flash memory, see section [SPIFFS Device](#esp32_spiffs_device).
 esp_spi_ram | Enable the optional SPI RAM, see section [SPI RAM Modules](#esp32_spi_ram).
@@ -435,6 +439,41 @@ The flash mode determines whether 2 data lines (```dio``` and ```dout```) or 4 d
 
 For more information about these flash modes, refer the documentation of [esptool.py](https://github.com/espressif/esptool/wiki/SPI-Flash-Modes).
 
+## <a name="esp32_esp_log_module"> Log output </a> &nbsp;[[TOC](#esp32_toc)]
+
+The RIOT port for ESP32 implements a log module with a bunch of macros
+to generate log output according to the interface as defined in
+[system logging header](http://doc.riot-os.org/log_8h.html). These macros
+support colored and tagged log output.
+
+The colored log output is enabled by module `esp_log_colored`. If colored log
+output is enabled, log messages are displayed in color according to their type:
+Error messages are displayed in red, warnings in yellow, information
+messages in green and all other message types in standard color.
+
+When the `esp_log_tagged` module is used, all log messages are tagged with
+additional information: the type of message, the system time in ms, and the
+module or function in which the log message is generated. For example:
+
+```
+I (663) [main_trampoline] main(): This is RIOT! (Version: 2019.10-devel-437-gf506a)
+```
+
+Either the `LOG_*` macros as defined in
+[system logging header](http://doc.riot-os.org/log_8h.html) or the tagged
+version `LOG_TAG_*` of these macros can be used to produce tagged log output.
+If the `LOG_*` macros are used, the function which generates the log message
+is used in the tag while a `tag` parameter is used for the `LOG_TAG_*` macros.
+For example,
+```
+LOG_ERROR("error message");
+```
+generates a log message in which the name of the calling function is used as
+tag. With
+```
+LOG_TAG_ERROR("mod", "error message");
+```
+a log message with string `mod` in the tag is generated.
 
 ## <a name="esp32_esp_idf_heap_implementation"> ESP-IDF Heap Implementation </a> &nbsp;[[TOC](#esp32_toc)]
 

cpu/esp32/include/esp_common_log.h

@@ -26,48 +26,111 @@
 extern "C" {
 #endif
 
+#include <stdio.h>
+#include <stdint.h>
+
 #include "log.h"
 
-#define LOG_TAG(level, tag, ...) do { \
+extern uint32_t system_get_time_ms (void);
-    if ((level) <= LOG_LEVEL) log_write_tagged(level, tag, __VA_ARGS__); } while (0U)
+extern int ets_printf(const char *fmt, ...);
+
+#if MODULE_ESP_LOG_COLORED
+
+#define LOG_RESET_COLOR   "\033[0m"
+#define LOG_COLOR_E       "\033[1;31m"
+#define LOG_COLOR_W       "\033[1;33m"
+#define LOG_COLOR_I       "\033[1m"
+#define LOG_COLOR_D       "\033[0;32m"
+#define LOG_COLOR_V
+
+#else /* MODULE_ESP_LOG_COLORED */
+
+#define LOG_COLOR_E
+#define LOG_COLOR_W
+#define LOG_COLOR_I
+#define LOG_COLOR_D
+#define LOG_COLOR_V
+#define LOG_RESET_COLOR
+
+#endif /* MODULE_ESP_LOG_COLORED */
+
+#if MODULE_ESP_LOG_TAGGED
+
+#define LOG_FORMAT(letter, format)  LOG_COLOR_ ## letter #letter " (%d) [%s] " format LOG_RESET_COLOR
+
+#define LOG_TAG(level, letter, tag, format, ...) \
+                 do { \
+                    if ((unsigned)level <= (unsigned)LOG_LEVEL) { \
+                        printf(LOG_FORMAT(letter, format), system_get_time_ms(), tag, ##__VA_ARGS__); \
+                        fflush(stdout); \
+                    } \
+                } while(0)
+
+#define LOG_TAG_EARLY(level, letter, tag, format, ...) \
+                do { \
+                    if (LOG_LEVEL >= level) { \
+                        ets_printf(LOG_FORMAT(letter, format), system_get_time_ms(), tag, ##__VA_ARGS__); \
+                    } \
+                } while(0)
+
+#else /* MODULE_ESP_LOG_TAGGED */
+
+#define LOG_FORMAT(letter, format)  LOG_COLOR_ ## letter format LOG_RESET_COLOR
+
+#define LOG_TAG(level, letter, tag, format, ...) \
+                do { \
+                    (void)tag; \
+                    if ((unsigned)level <= (unsigned)LOG_LEVEL) { \
+                        printf(LOG_FORMAT(letter, format), ##__VA_ARGS__); \
+                        fflush(stdout); \
+                    } \
+                } while (0U)
+
+#define LOG_TAG_EARLY(level, letter, tag, format, ...) \
+                do { \
+                    (void)tag; \
+                    if ((unsigned)level <= (unsigned)LOG_LEVEL) { \
+                        ets_printf(LOG_FORMAT(letter, format), ##__VA_ARGS__); \
+                    } \
+                } while (0U)
+
+#endif /* MODULE_ESP_LOG_TAGGED */
 
 /**
  * Override LOG_* definitions with a tagged version. By default the function
- * name is used tag.
+ * name is used as tag.
  */
+#ifndef MODULE_LOG_PRINTFNOFORMAT
 #undef LOG_ERROR
 #undef LOG_INFO
 #undef LOG_WARNING
 #undef LOG_DEBUG
-#define LOG_ERROR(fmt, ...)   LOG_TAG(LOG_ERROR  , __func__, fmt, ##__VA_ARGS__)
+#define LOG_ERROR(format, ...)   LOG_TAG(LOG_ERROR  , E, __func__, format, ##__VA_ARGS__)
-#define LOG_WARNING(fmt, ...) LOG_TAG(LOG_WARNING, __func__, fmt, ##__VA_ARGS__)
+#define LOG_WARNING(format, ...) LOG_TAG(LOG_WARNING, W, __func__, format, ##__VA_ARGS__)
-#define LOG_INFO(fmt, ...)    LOG_TAG(LOG_INFO   , __func__, fmt, ##__VA_ARGS__)
+#define LOG_INFO(format, ...)    LOG_TAG(LOG_INFO   , I, __func__, format, ##__VA_ARGS__)
-#define LOG_DEBUG(fmt, ...)   LOG_TAG(LOG_DEBUG  , __func__, fmt, ##__VA_ARGS__)
+#define LOG_DEBUG(format, ...)   LOG_TAG(LOG_DEBUG  , D, __func__, format, ##__VA_ARGS__)
+#endif
 
 /** Tagged LOG_* definitions */
-#define LOG_TAG_ERROR(tag, fmt, ...)   LOG_TAG(LOG_ERROR  , tag, fmt, ##__VA_ARGS__)
+#define LOG_TAG_ERROR(tag, format, ...)   LOG_TAG(LOG_ERROR  , E, tag, format, ##__VA_ARGS__)
-#define LOG_TAG_WARNING(tag, fmt, ...) LOG_TAG(LOG_WARNING, tag, fmt, ##__VA_ARGS__)
+#define LOG_TAG_WARNING(tag, format, ...) LOG_TAG(LOG_WARNING, W, tag, format, ##__VA_ARGS__)
-#define LOG_TAG_INFO(tag, fmt, ...)    LOG_TAG(LOG_INFO   , tag, fmt, ##__VA_ARGS__)
+#define LOG_TAG_INFO(tag, format, ...)    LOG_TAG(LOG_INFO   , I, tag, format, ##__VA_ARGS__)
-#define LOG_TAG_DEBUG(tag, fmt, ...)   LOG_TAG(LOG_DEBUG  , tag, fmt, ##__VA_ARGS__)
+#define LOG_TAG_DEBUG(tag, format, ...)   LOG_TAG(LOG_DEBUG  , D, tag, format, ##__VA_ARGS__)
 
 /** definitions for source code compatibility with ESP-IDF */
-#define ESP_EARLY_LOGE(tag, fmt, ...) LOG_TAG(LOG_ERROR  , tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_EARLY_LOGE(tag, format, ...) LOG_TAG_EARLY(LOG_ERROR  , E, tag, format "\n", ##__VA_ARGS__)
-#define ESP_EARLY_LOGW(tag, fmt, ...) LOG_TAG(LOG_WARNING, tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_EARLY_LOGW(tag, format, ...) LOG_TAG_EARLY(LOG_WARNING, W, tag, format "\n", ##__VA_ARGS__)
-#define ESP_EARLY_LOGI(tag, fmt, ...) LOG_TAG(LOG_INFO   , tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_EARLY_LOGI(tag, format, ...) LOG_TAG_EARLY(LOG_INFO   , I, tag, format "\n", ##__VA_ARGS__)
-/*
+#define ESP_LOGE(tag, format, ...) LOG_TAG(LOG_ERROR  , E, tag, format "\n", ##__VA_ARGS__)
-#define ESP_EARLY_LOGI(tag, fmt, ...) ets_printf("I (%u) %s: " fmt "\n", \
+#define ESP_LOGW(tag, format, ...) LOG_TAG(LOG_WARNING, W, tag, format "\n", ##__VA_ARGS__)
-                                                 system_get_time_ms(), tag, ##__VA_ARGS__)
+#define ESP_LOGI(tag, format, ...) LOG_TAG(LOG_INFO   , I, tag, format "\n", ##__VA_ARGS__)
-*/
-#define ESP_LOGE(tag, fmt, ...) LOG_TAG(LOG_ERROR  , tag, fmt "\n", ##__VA_ARGS__)
-#define ESP_LOGW(tag, fmt, ...) LOG_TAG(LOG_WARNING, tag, fmt "\n", ##__VA_ARGS__)
-#define ESP_LOGI(tag, fmt, ...) LOG_TAG(LOG_INFO   , tag, fmt "\n", ##__VA_ARGS__)
 
 #if ENABLE_DEBUG
 
-#define ESP_EARLY_LOGD(tag, fmt, ...) LOG_TAG(LOG_DEBUG, tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_EARLY_LOGD(tag, format, ...) LOG_TAG_EARLY(LOG_DEBUG, D, tag, format "\n", ##__VA_ARGS__)
-#define ESP_EARLY_LOGV(tag, fmt, ...) LOG_TAG(LOG_ALL  , tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_EARLY_LOGV(tag, format, ...) LOG_TAG_EARLY(LOG_ALL  , V, tag, format "\n", ##__VA_ARGS__)
-#define ESP_LOGD(tag, fmt, ...) LOG_TAG(LOG_DEBUG, tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_LOGD(tag, format, ...) LOG_TAG(LOG_DEBUG, D, tag, format "\n", ##__VA_ARGS__)
-#define ESP_LOGV(tag, fmt, ...) LOG_TAG(LOG_ALL  , tag, fmt "\n", ##__VA_ARGS__)
+#define ESP_LOGV(tag, format, ...) LOG_TAG(LOG_ALL  , V, tag, format "\n", ##__VA_ARGS__)
 
 #else /* ENABLE_DEBUG */
 

cpu/esp32/include/log_module.h

@@ -23,22 +23,35 @@
 extern "C" {
 #endif
 
-/**
+#include <stdio.h>
- * @brief log_write overridden function
+#include "esp_common_log.h"
- *
- * @param[in] level (unused)
- * @param[in] format String that the function will print
- */
-void log_write(unsigned level, const char *format, ...);
 
-/**
+#ifdef MODULE_LOG_PRINTFNOFORMAT
- * @brief log_write overridden function, tagged version
+
- *
+static inline void log_write(unsigned level, const char *format, ...) {
- * @param[in] level     Level of the message
+    (void)level;
- * @param[in] tag       Additional information like function or module
+    puts(format);
- * @param[in] format    String that the function will print
+}
- */
+
-void log_write_tagged(unsigned level, const char *tag, const char *format, ...);
+#else /* MODULE_LOG_PRINTFNOFORMAT */
+
+#define log_write(level, ...) \
+                do { \
+                    if (level == LOG_ERROR) { \
+                        LOG_TAG(LOG_ERROR, E, __func__, ##__VA_ARGS__); \
+                    } \
+                    else if (level == LOG_WARNING) { \
+                        LOG_TAG(LOG_WARNING, W, __func__, ##__VA_ARGS__); \
+                    } \
+                    else if (level == LOG_INFO) { \
+                        LOG_TAG(LOG_INFO, D, __func__, ##__VA_ARGS__); \
+                    } \
+                    else if (level == LOG_DEBUG) { \
+                        LOG_TAG(LOG_DEBUG, E, __func__, ##__VA_ARGS__); \
+                    } \
+                } while (0U);
+
+#endif /* MODULE_LOG_PRINTFNOFORMAT */
 
 #ifdef __cplusplus
 }

cpu/esp32/log_module.c

@@ -1,99 +0,0 @@
-/*
- * Copyright (C) 2018 Gunar Schorcht
- *
- * This file is subject to the terms and conditions of the GNU Lesser
- * General Public License v2.1. See the file LICENSE in the top level
- * directory for more details.
- */
-
-/**
- * @ingroup     cpu_esp32
- * @{
- *
- * @file
- * @brief       Log module to realize consistent log messages
- *
- * @author      Gunar Schorcht <gunar@schorcht.net>
- */
-
-#include <stdio.h>
-#include <string.h>
-
-#include "rom/ets_sys.h"
-
-#include "cpu_conf.h"
-#include "log.h"
-#include "syscalls.h"
-
-char _printf_buf[PRINTF_BUFSIZ];
-bool _new_line = true;
-
-void log_write(unsigned level, const char *format, ...)
-{
-    if (level == LOG_NONE) {
-        return;
-    }
-
-    if (_new_line) {
-        /* if we are in new line, we print the prefix */
-        char lc = 'U';
-        switch (level) {
-            case LOG_ERROR  : lc = 'E'; break;
-            case LOG_WARNING: lc = 'W'; break;
-            case LOG_INFO   : lc = 'I'; break;
-            case LOG_DEBUG  : lc = 'D'; break;
-            case LOG_ALL    : lc = 'V'; break;
-        }
-        ets_printf("%c (%u) ", lc, system_get_time_ms());
-    }
-
-    va_list arglist;
-    va_start(arglist, format);
-
-    int ret = vsnprintf(_printf_buf, PRINTF_BUFSIZ, format, arglist);
-
-    if (ret > 0) {
-        ets_printf (_printf_buf);
-    }
-
-    va_end(arglist);
-
-    _new_line = (strrchr(format, '\n') != NULL);
-}
-
-void log_write_tagged(unsigned level, const char *tag, const char *format, ...)
-{
-    if (level == LOG_NONE) {
-        return;
-    }
-
-    if (_new_line) {
-        /* if we are in new line, we print the prefix */
-        char lc = 'U';
-        switch (level) {
-            case LOG_ERROR  : lc = 'E'; break;
-            case LOG_WARNING: lc = 'W'; break;
-            case LOG_INFO   : lc = 'I'; break;
-            case LOG_DEBUG  : lc = 'D'; break;
-            case LOG_ALL    : lc = 'V'; break;
-        }
-        #if LOG_TAG_IN_BRACKETS
-        ets_printf("%c (%u) [%10s]: ", lc, system_get_time_ms(), tag);
-        #else
-        ets_printf("%c (%u) %10s: ", lc, system_get_time_ms(), tag);
-        #endif
-    }
-
-    va_list arglist;
-    va_start(arglist, format);
-
-    int ret = vsnprintf(_printf_buf, PRINTF_BUFSIZ, format, arglist);
-
-    if (ret > 0) {
-        ets_printf (_printf_buf);
-    }
-
-    va_end(arglist);
-
-    _new_line = (strrchr(format, '\n') != NULL);
-}

cpu/esp32/periph/adc.c

@@ -26,7 +26,6 @@
 #include "adc_ctrl.h"
 #include "esp_common.h"
 #include "gpio_arch.h"
-#include "rom/ets_sys.h"
 #include "soc/rtc_io_struct.h"
 #include "soc/rtc_cntl_struct.h"
 #include "soc/sens_reg.h"
@@ -271,11 +270,11 @@ static void _adc_module_init(void)
 
 void adc_print_config(void)
 {
-    ets_printf("\tADC\t\tpins=[ ");
+    printf("\tADC\t\tpins=[ ");
 #if defined(ADC_GPIOS)
     for (unsigned i = 0; i < ADC_NUMOF; i++) {
-        ets_printf("%d ", adc_channels[i]);
+        printf("%d ", adc_channels[i]);
     }
 #endif /* defined(ADC_GPIOS) */
-    ets_printf("]\n");
+    printf("]\n");
 }

cpu/esp32/periph/dac.c

@@ -26,7 +26,6 @@
 #include "adc_ctrl.h"
 #include "esp_common.h"
 #include "gpio_arch.h"
-#include "rom/ets_sys.h"
 #include "soc/rtc_io_struct.h"
 #include "soc/rtc_cntl_struct.h"
 #include "soc/sens_reg.h"
@@ -136,11 +135,11 @@ static bool _dac_conf_check(void)
 
 void dac_print_config(void)
 {
-    ets_printf("\tDAC\t\tpins=[ ");
+    printf("\tDAC\t\tpins=[ ");
 #if defined(DAC_GPIOS)
     for (unsigned i = 0; i < DAC_NUMOF; i++) {
-        ets_printf("%d ", dac_channels[i]);
+        printf("%d ", dac_channels[i]);
     }
 #endif /* defined(DAC_GPIOS) */
-    ets_printf("]\n");
+    printf("]\n");
 }

cpu/esp32/periph/i2c_hw.c

@@ -869,8 +869,8 @@ static void _i2c_reset_hw (i2c_t dev)
 void i2c_print_config(void)
 {
     for (unsigned dev = 0; dev < I2C_NUMOF; dev++) {
-        ets_printf("\tI2C_DEV(%d)\tscl=%d sda=%d\n",
+        printf("\tI2C_DEV(%u)\tscl=%d sda=%d\n",
-                   dev, i2c_config[dev].scl, i2c_config[dev].sda);
+               dev, i2c_config[dev].scl, i2c_config[dev].sda);
     }
 }
 

cpu/esp32/periph/i2c_sw.c

@@ -700,8 +700,8 @@ static /* IRAM */ int _i2c_read_byte(_i2c_bus_t* bus, uint8_t *byte, bool ack)
 void i2c_print_config(void)
 {
     for (unsigned dev = 0; dev < I2C_NUMOF; dev++) {
-        ets_printf("\tI2C_DEV(%d)\tscl=%d sda=%d\n",
+        printf("\tI2C_DEV(%u)\tscl=%d sda=%d\n",
-                   dev, i2c_config[dev].scl, i2c_config[dev].sda);
+               dev, i2c_config[dev].scl, i2c_config[dev].sda);
     }
 }
 

cpu/esp32/periph/pwm.c

@@ -32,7 +32,6 @@
 #include "gpio_arch.h"
 
 #include "driver/periph_ctrl.h"
-#include "rom/ets_sys.h"
 #include "soc/gpio_struct.h"
 #include "soc/gpio_sig_map.h"
 #include "soc/mcpwm_reg.h"
@@ -437,11 +436,11 @@ static bool _pwm_configuration(void)
 void pwm_print_config(void)
 {
     for (unsigned pwm = 0; pwm < PWM_NUMOF; pwm++) {
-        ets_printf("\tPWM_DEV(%d)\tchannels=[ ", pwm);
+        printf("\tPWM_DEV(%d)\tchannels=[ ", pwm);
         for (int i = 0; i < _pwm_hw[pwm].gpio_num; i++) {
-            ets_printf("%d ", _pwm_hw[pwm].gpios[i]);
+            printf("%d ", _pwm_hw[pwm].gpios[i]);
         }
-        ets_printf("]\n");
+        printf("]\n");
     }
 }
 

cpu/esp32/periph/spi.c

@@ -125,7 +125,7 @@ void IRAM_ATTR spi_init (spi_t bus)
                     _spi[bus].signal_miso = VSPIQ_IN_IDX;
                     break;
         default:    LOG_TAG_ERROR("spi", "invalid SPI interface controller "
-                                         "used for SPI_DEV(%d)\n");
+                                         "used for SPI_DEV(%d)\n", bus);
                     break;
     }
     return;
@@ -361,11 +361,11 @@ static const char* _spi_names[] = { "CSPI", "FSPI", "HSPI", "VSPI"  };
 void spi_print_config(void)
 {
     for (unsigned bus = 0; bus < SPI_NUMOF; bus++) {
-        ets_printf("\tSPI_DEV(%d)\t%s ", bus, _spi_names[spi_config[bus].ctrl]);
+        printf("\tSPI_DEV(%u)\t%s ", bus, _spi_names[spi_config[bus].ctrl]);
-        ets_printf("sck=%d " , spi_config[bus].sck);
+        printf("sck=%d " , spi_config[bus].sck);
-        ets_printf("miso=%d ", spi_config[bus].miso);
+        printf("miso=%d ", spi_config[bus].miso);
-        ets_printf("mosi=%d ", spi_config[bus].mosi);
+        printf("mosi=%d ", spi_config[bus].mosi);
-        ets_printf("cs=%d\n" , spi_config[bus].cs);
+        printf("cs=%d\n" , spi_config[bus].cs);
     }
 }
 

cpu/esp32/periph/uart.c

@@ -205,8 +205,8 @@ void uart_system_init (void)
 void uart_print_config(void)
 {
     for (unsigned uart = 0; uart < UART_NUMOF; uart++) {
-        ets_printf("\tUART_DEV(%d)\ttxd=%d rxd=%d\n", uart,
+        printf("\tUART_DEV(%u)\ttxd=%d rxd=%d\n", uart,
-                   uart_config[uart].txd, uart_config[uart].rxd);
+               uart_config[uart].txd, uart_config[uart].rxd);
     }
 }
 

cpu/esp32/tools.c

@@ -43,18 +43,18 @@ void esp_hexdump (const void* addr, uint32_t num, char width, uint8_t per_line)
 
     while (count < num) {
         if (count % per_line == 0) {
-            ets_printf ("%08" PRIx32 ": ", (uint32_t)((uint8_t*)addr+count*size));
+            printf ("%08" PRIx32 ": ", (uint32_t)((uint8_t*)addr+count*size));
         }
         switch (width) {
-            case 'b': ets_printf("%02" PRIx8 " ", addr8[count++]); break;
+            case 'b': printf("%02" PRIx8 " ", addr8[count++]); break;
-            case 'h': ets_printf("%04" PRIx16 " ", addr16[count++]); break;
+            case 'h': printf("%04" PRIx16 " ", addr16[count++]); break;
-            case 'w': ets_printf("%08" PRIx32 " ", addr32[count++]); break;
+            case 'w': printf("%08" PRIx32 " ", addr32[count++]); break;
-            case 'g': ets_printf("%016" PRIx64 " ", addr64[count++]); break;
+            case 'g': printf("%016" PRIx64 " ", addr64[count++]); break;
-            default : ets_printf("."); count++; break;
+            default : printf("."); count++; break;
         }
         if (count % per_line == 0) {
-            ets_printf ("\n");
+            printf ("\n");
         }
     }
-    ets_printf ("\n");
+    printf ("\n");
 }

cpu/esp32/vendor/esp-idf/esp_funcs.c

@@ -86,6 +86,22 @@ uint32_t IRAM_ATTR esp_log_timestamp(void)
     return system_get_time() / USEC_PER_MSEC;
 }
 
+
+#if MODULE_ESP_LOG_TAGGED
+#define ESP_LOG_PREFIX(letter, tag)  \
+                        printf(LOG_COLOR_ ## letter #letter " (%d) [%s] ", \
+                               system_get_time_ms(), tag)
+#else
+#define ESP_LOG_PREFIX(letter, tag)  \
+                        printf(LOG_COLOR_ ## letter "[%s] ", tag)
+#endif
+
+#if MODULE_ESP_LOG_COLORED
+#define ESP_LOG_SUFFIX()  printf(LOG_RESET_COLOR)
+#else
+#define ESP_LOG_SUFFIX()
+#endif
+
 /*
  * provided by: /path/to/esp-idf/component/log/log.c
  */
@@ -97,23 +113,16 @@ void IRAM_ATTR esp_log_write(esp_log_level_t level,
     }
 
     char _printf_buf[PRINTF_BUFSIZ];
-
     const char* prefix = (strchr (format, ':') + 2);
 
-    char lc = 'U';
     switch (level) {
         case LOG_NONE   : return;
-        case LOG_ERROR  : lc = 'E'; break;
+        case LOG_ERROR  : ESP_LOG_PREFIX(E, tag); break;
-        case LOG_WARNING: lc = 'W'; break;
+        case LOG_WARNING: ESP_LOG_PREFIX(W, tag); break;
-        case LOG_INFO   : lc = 'I'; break;
+        case LOG_INFO   : ESP_LOG_PREFIX(I, tag); break;
-        case LOG_DEBUG  : lc = 'D'; break;
+        case LOG_DEBUG  : ESP_LOG_PREFIX(D, tag); break;
-        case LOG_ALL    : lc = 'V'; break;
+        case LOG_ALL    : ESP_LOG_PREFIX(V, tag); break;
     }
-    #ifdef LOG_TAG_IN_BRACKETS
-    ets_printf("%c (%u) [%10s]: ", lc, system_get_time_ms(), tag);
-    #else
-    ets_printf("%c (%u) %10s: ", lc, system_get_time_ms(), tag);
-    #endif
 
     va_list arglist;
     va_start(arglist, format);
@@ -124,11 +133,13 @@ void IRAM_ATTR esp_log_write(esp_log_level_t level,
 
     int ret = vsnprintf(_printf_buf, PRINTF_BUFSIZ, prefix, arglist);
 
+    va_end(arglist);
+
     if (ret > 0) {
-        ets_printf (_printf_buf);
+        printf ("%s", _printf_buf);
     }
 
-    va_end(arglist);
+    ESP_LOG_SUFFIX();
 }
 
 /*
@@ -154,11 +165,11 @@ void spi_ram_init(void)
         _spi_ram_initialized = true;
     }
     else {
-        ets_printf("Failed to init external SPI RAM\n");
+        ESP_EARLY_LOGE("spi_ram", "Failed to init external SPI RAM\n");
         _spi_ram_initialized = false;
     }
     #else
-    ets_printf("External SPI RAM functions not enabled\n");
+    ESP_EARLY_LOGI("spi_ram", "External SPI RAM functions not enabled\n");
     #endif
 }
 
@@ -178,14 +189,14 @@ void spi_ram_heap_init(void)
     #if CONFIG_SPIRAM_USE_CAPS_ALLOC || CONFIG_SPIRAM_USE_MALLOC
     esp_err_t r=esp_spiram_add_to_heapalloc();
     if (r != ESP_OK) {
-        ets_printf("External SPI RAM could not be added to heap!\n");
+        ESP_EARLY_LOGE("spi_ram", "External SPI RAM could not be added to heap!\n");
         abort();
     }
 
     #if CONFIG_SPIRAM_MALLOC_RESERVE_INTERNAL
     r=esp_spiram_reserve_dma_pool(CONFIG_SPIRAM_MALLOC_RESERVE_INTERNAL);
     if (r != ESP_OK) {
-        ets_printf("Could not reserve internal/DMA pool!\n");
+        ESP_EARLY_LOGE("spi_ram", "Could not reserve internal/DMA pool!\n");
         abort();
     }
     #endif /* CONFIG_SPIRAM_MALLOC_RESERVE_INTERNAL */
@@ -197,7 +208,7 @@ void spi_ram_heap_init(void)
     #endif /* CONFIG_SPIRAM_USE_CAPS_ALLOC || CONFIG_SPIRAM_USE_MALLOC */
 
     #else  /* CONFIG_SPIRAM_SUPPORT */
-    ets_printf("External SPI RAM functions not enabled\n");
+    ESP_EARLY_LOGI("spi_ram", "External SPI RAM functions not enabled\n");
     #endif /* CONFIG_SPIRAM_SUPPORT */
 }
 

cpu/esp32/vendor/esp-idf/include/log/esp_log.h

@@ -318,41 +318,36 @@ void esp_log_write(esp_log_level_t level, const char* tag, const char* format, .
 
 #include "esp_common.h"
 
-#if 0 /* TODO */
+#ifndef LOG_LOCAL_LEVEL
-
+#define LOG_LOCAL_LEVEL (esp_log_level_t)LOG_LEVEL
-#define LOG_FORMAT(letter, format)  #letter " (%d) %s: " format "\n"
-
-#define ESP_LOG_LEVEL(level, tag, format, ...) do { \
-        if ((esp_log_level_t)level==ESP_LOG_ERROR ) { \
-            esp_log_write(ESP_LOG_ERROR, tag, LOG_FORMAT(E, format), \
-                          esp_log_timestamp(), tag, ##__VA_ARGS__);  \
-        } \
-        else if ((esp_log_level_t)level==ESP_LOG_WARN ) { \
-            esp_log_write(ESP_LOG_WARN,  tag, LOG_FORMAT(W, format), \
-                          esp_log_timestamp(), tag, ##__VA_ARGS__); \
-        } \
-        else if ((esp_log_level_t)level==ESP_LOG_DEBUG ) { \
-            esp_log_write(ESP_LOG_DEBUG, tag, LOG_FORMAT(D, format), \
-                          esp_log_timestamp(), tag, ##__VA_ARGS__); \
-        } \
-        else if ((esp_log_level_t)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)
-
-#define ESP_LOG_LEVEL_LOCAL(level, tag, format, ...) do {               \
-        if ( LOG_LOCAL_LEVEL >= level ) ESP_LOG_LEVEL(level, tag, format, ##__VA_ARGS__); \
-    } while(0)
-
-#else
-#define ESP_LOG_LEVEL_LOCAL(level, tag, format, ...)
 #endif
 
+#define ESP_LOG_LEVEL(level, tag, format, ...) \
+            do { \
+                if ((esp_log_level_t)level==ESP_LOG_ERROR ) { \
+                    LOG_TAG(level, E, tag, format, ##__VA_ARGS__);  \
+                } \
+                else if ((esp_log_level_t)level==ESP_LOG_WARN ) { \
+                    LOG_TAG(level, W, tag, format, ##__VA_ARGS__);  \
+                } \
+                else if ((esp_log_level_t)level==ESP_LOG_INFO ) { \
+                    LOG_TAG(level, I, tag, format, ##__VA_ARGS__);  \
+                } \
+                else if ((esp_log_level_t)level==ESP_LOG_DEBUG ) { \
+                    LOG_TAG(level, D, tag, format, ##__VA_ARGS__);  \
+                } \
+                else if ((esp_log_level_t)level==ESP_LOG_VERBOSE ) { \
+                    LOG_TAG(level, V, tag, format, ##__VA_ARGS__);  \
+                } \
+            } while(0)
+
+#define ESP_LOG_LEVEL_LOCAL(level, tag, format, ...) \
+            do {               \
+                if ( LOG_LOCAL_LEVEL >= level ) { \
+                    ESP_LOG_LEVEL(level, tag, format, ##__VA_ARGS__); \
+                } \
+            } while(0)
+
 #endif /* RIOT_VERSION */
 
 #ifdef __cplusplus