Onw on ESP-IDF 5.1/Arduino 3.0 Huge Logs?

1

I moved to ESP-IDF 5.1 with Arduino 3.0 just a few days ago and now I’m getting crazy amounts of log output to the serial port. I have tried a few things to reduce this but nothing seems to help.

my platformio.ini

[env:esp32-s3-devkitc-1]
platform = espressif32
board = esp32-s3-devkitc-1
framework = espidf, arduino
board_build.filesystem = littlefs
board_build.partitions = default_partitions.csv
board_build.arduino.memory_type = dio_opi
monitor_speed = 115200
;monitor_filters = direct, esp32_exception_decoder
build_flags =
-I./src/
-DCORE_DEBUG_LEVEL=1
-DBOARD_HAS_PSRAM
-mfix-esp32-psram-cache-issue
-fmax-errors=5
-Wno-error=misleading-indentation

and an example of the output…

ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3818,len:0x1758
load:0x403c9700,len:0x4
load:0x403c9704,len:0xbb8
load:0x403cc700,len:0x2e9c
SHA-256 comparison failed:
Calculated: f5cc54bad044390b3790ef21ab5424a5667ef7024e7cd2b5e69567bff022555b
Expected: ffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffffff
Attempting to boot anyway...
entry 0x403c98fc
␛[0;32mI (45) boot: ESP-IDF 5.1.2.231118 2nd stage bootloader␛[0m
␛[0;32mI (45) boot: compile time Dec  1 2023 17:49:32␛[0m
␛[0;32mI (45) boot: Multicore bootloader␛[0m
␛[0;32mI (49) boot: chip revision: v0.1␛[0m
␛[0;32mI (53) boot.esp32s3: Boot SPI Speed : 80MHz␛[0m
␛[0;32mI (57) boot.esp32s3: SPI Mode       : DIO␛[0m
␛[0;32mI (62) boot.esp32s3: SPI Flash Size : 16MB␛[0m
␛[0;32mI (67) boot: Enabling RNG early entropy source...␛[0m
␛[0;32mI (72) boot: Partition Table:␛[0m
␛[0;32mI (76) boot: ## Label            Usage          Type ST Offset   Length␛[0m
␛[0;32mI (83) boot:  0 nvs              WiFi data        01 02 00009000 00005000␛[0m
␛[0;32mI (91) boot:  1 otadata          OTA data         01 00 0000e000 00002000␛[0m
␛[0;32mI (98) boot:  2 app0             OTA app          00 10 00010000 00140000␛[0m
␛[0;32mI (106) boot:  3 app1             OTA app          00 11 00150000 00140000␛[0m
␛[0;32mI (113) boot:  4 spiffs           Unknown data     01 82 00290000 00170000␛[0m
␛[0;32mI (121) boot:  5 coredump         Unknown data     01 03 00400000 00010000␛[0m
␛[0;32mI (128) boot: End of partition table␛[0m
␛[0;32mI (133) esp_image: segment 0: paddr=00010020 vaddr=3c0b0020 size=2c6c4h (181956) map␛[0m
␛[0;32mI (162) esp_image: segment 1: paddr=0003c6ec vaddr=3fc9b000 size=0392ch ( 14636) load␛[0m
␛[0;32mI (165) esp_image: segment 2: paddr=00040020 vaddr=42000020 size=a7198h (684440) map␛[0m
␛[0;32mI (246) esp_image: segment 3: paddr=000e71c0 vaddr=3fc9e92c size=00ef8h (  3832) load␛[0m
␛[0;32mI (247) esp_image: segment 4: paddr=000e80c0 vaddr=40374000 size=16f28h ( 93992) load␛[0m
␛[0;32mI (267) esp_image: segment 5: paddr=000feff0 vaddr=50000000 size=00054h (    84) load␛[0m
␛[0;32mI (268) esp_image: segment 6: paddr=000ff04c vaddr=600fe000 size=001b4h (   436) load␛[0m
␛[0;32mI (282) boot: Loaded app from partition at offset 0x10000␛[0m
␛[0;32mI (283) boot: Disabling RNG early entropy source...␛[0m
␛[0;32mI (296) cpu_start: Multicore app␛[0m
␛[0;32mI (296) cpu_start: Pro cpu up.␛[0m
␛[0;32mI (296) cpu_start: Starting app cpu, entry point is 0x40377af0␛[0m
␛[0;32mI (0) cpu_start: App cpu up.␛[0m
␛[0;32mI (315) cpu_start: Pro cpu start user code␛[0m
␛[0;32mI (315) cpu_start: cpu freq: 160000000 Hz␛[0m
␛[0;32mI (315) cpu_start: Application information:␛[0m
␛[0;32mI (318) cpu_start: Project name:     AI_S3_wake_test_build_up␛[0m
␛[0;32mI (324) cpu_start: App version:      f75b4e5-dirty␛[0m
␛[0;32mI (330) cpu_start: Compile time:     Dec  1 2023 17:44:59␛[0m
␛[0;32mI (336) cpu_start: ELF file SHA256:  7d4a3b457b698b6f...␛[0m
␛[0;32mI (342) cpu_start: ESP-IDF:          5.1.2.231118␛[0m
␛[0;32mI (347) cpu_start: Min chip rev:     v0.0␛[0m
␛[0;32mI (352) cpu_start: Max chip rev:     v0.99 ␛[0m
␛[0;32mI (357) cpu_start: Chip rev:         v0.1␛[0m
␛[0;32mI (361) heap_init: Initializing. RAM available for dynamic allocation:␛[0m
␛[0;32mI (369) heap_init: At 3FCA4290 len 00045480 (277 KiB): DRAM␛[0m
␛[0;32mI (375) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM␛[0m
␛[0;32mI (381) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM␛[0m
␛[0;32mI (388) heap_init: At 600FE1B4 len 00001E34 (7 KiB): RTCRAM␛[0m
␛[0;32mI (395) spi_flash: detected chip: gd␛[0m
␛[0;32mI (398) spi_flash: flash io: dio␛[0m
␛[0;32mI (403) sleep: Configure to isolate all GPIO pins in sleep state␛[0m
␛[0;32mI (409) sleep: Enable automatic switching of GPIO sleep configuration␛[0m
␛[0;32mI (416) app_start: Starting scheduler on CPU0␛[0m
␛[0;32mI (421) app_start: Starting scheduler on CPU1␛[0m
␛[0;32mI (421) main_task: Started on CPU0␛[0m
␛[0;32mI (431) main_task: Calling app_main()␛[0m
␛[0;32mI (458) main_task: Returned from app_main()␛[0m
␛[0;32mI (459) gpio: GPIO[48]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 ␛[0m
␛[0;31mE (463) task_wdt: esp_task_wdt_add(747): TWDT was never initialized␛[0m
␛[0;32mI (671) gpio: GPIO[18]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (671) gpio: GPIO[8]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (679) gpio: GPIO[9]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (688) gpio: GPIO[12]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (697) gpio: GPIO[13]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (706) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (716) gpio: GPIO[15]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (725) gpio: GPIO[11]| InputEn: 1| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (734) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 ␛[0m
␛[0;32mI (2747) pp: pp rom version: e7ae62f␛[0m
␛[0;32mI (2747) net80211: net80211 rom version: e7ae62f␛[0m
I (2749) wifi:wifi driver task: 3fcb1bac, prio:23, stack:6656, core=0
I (2765) wifi:wifi firmware version: 91b9630
I (2766) wifi:wifi certification version: v7.0
I (2766) wifi:config NVS flash: enabled
I (2766) wifi:config nano formating: disabled
I (2770) wifi:Init data frame dynamic rx buffer num: 32
I (2775) wifi:Init static rx mgmt buffer num: 5
I (2779) wifi:Init management short buffer num: 32
I (2784) wifi:Init dynamic tx buffer num: 32
I (2788) wifi:Init static tx FG buffer num: 2
I (2792) wifi:Init static rx buffer size: 1600
I (2796) wifi:Init static rx buffer num: 4
I (2800) wifi:Init dynamic rx buffer num: 32
␛[0;32mI (2805) wifi_init: rx ba win: 6␛[0m
␛[0;32mI (2808) wifi_init: tcpip mbox: 32␛[0m
␛[0;32mI (2812) wifi_init: udp mbox: 6␛[0m
␛[0;32mI (2816) wifi_init: tcp mbox: 6␛[0m
␛[0;32mI (2820) wifi_init: tcp tx win: 5744␛[0m
␛[0;32mI (2824) wifi_init: tcp rx win: 5744␛[0m
␛[0;32mI (2828) wifi_init: tcp mss: 1440␛[0m
␛[0;32mI (2832) wifi_init: WiFi IRAM OP enabled␛[0m
␛[0;32mI (2837) wifi_init: WiFi RX IRAM OP enabled␛[0m
␛[0;32mI (2843) phy_init: phy_version 620,ec7ec30,Sep  5 2023,13:49:13␛[0m
I (2886) wifi:mode : sta (34:85:18:96:f0:a0)
I (2887) wifi:enable tsf
I (2889) wifi:Set ps type: 1, coexist: 0

I (2902) wifi:new:<7,0>, old:<1,0>, ap:<255,255>, sta:<7,0>, prof:1
I (2904) wifi:state: init -> auth (b0)
I (2911) wifi:state: auth -> init (8a0)
I (2912) wifi:new:<7,0>, old:<7,0>, ap:<255,255>, sta:<7,0>, prof:1
I (2928) wifi:new:<7,0>, old:<7,0>, ap:<255,255>, sta:<7,0>, prof:1
I (2929) wifi:state: init -> auth (b0)
I (2935) wifi:state: auth -> assoc (0)
I (2942) wifi:state: assoc -> run (10)
2

Try configuring the debug level to only warning or higher, so that info logs (I) are not shown.

3

Hi Max. Isn’t that what the build option

-DCORE_DEBUG_LEVEL=1

in my platformio.ini should do?

4

Ah, but configure it in the menuconfig instead, not in build_flags.

5

My goodness… there are a lot of log settings in the sdkconfig… I had to set everything to 0 and work my way back up…
6

Anything setting above

CONFIG_LOG_DEFAULT_LEVEL=0

still gives me a bunch of serial output like the following which I show below…

This is very different than what I got with similar settings before esp-idf 5.1.
Are there other settings I need to look at or will I just have to go into each library and see what they are logging there? This really has destroyed the usefulness of ESP_LOG for me. I use it extensively in my code and now the output has a ton of additional messaging that totally buggers up my apps. Sigh. (I am assuming this is not a platformio issue at this point…)

D (1968) nvs: nvs_open_from_partition phy 0␛[0m
D (1972) nvs: nvs_get cal_version 4␛[0m
D (1976) nvs: nvs_get_str_or_blob cal_mac␛[0m
D (1981) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit␛[0m
D (1987) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit␛[0m
D (1994) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit␛[0m
D (2001) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit␛[0m
D (2008) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit␛[0m
D (2015) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit␛[0m
D (2022) nvs: nvs_get_str_or_blob cal_data␛[0m
D (2033) nvs: nvs_close 7␛[0m
D (2034) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 8 bit␛[0m
D (2036) efuse: In EFUSE_BLK1__DATA1_REG is used 8 bits starting with 0 bit␛[0m
D (2043) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 24 bit␛[0m
D (2050) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 16 bit␛[0m
D (2057) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 8 bit␛[0m
D (2064) efuse: In EFUSE_BLK1__DATA0_REG is used 8 bits starting with 0 bit␛[0m
D (2074) temperature_sensor: range changed, change to index 2␛[0m
D (2088) wifi:filter: set rx policy=0
I (2088) wifi:mode : sta (34:85:18:96:f0:a0)
I (2089) wifi:enable tsf
D (2089) wifi:filter: set rx policy=1