Firmware stops executing, prints garbage, requires reset

[jonking]

Environment

Development Kit: none
Module or chip used: ESP32-WROOM-32D
IDF version (run git describe --tags to find it):
v4.1-beta2-141-g84b51781c
Build System: idf.py
Compiler version (run xtensa-esp32-elf-gcc --version to find it):
xtensa-esp32-elf-gcc (crosstool-NG esp-2019r2) 8.2.0
Operating System: Linux
Using an IDE?: VS code
Power Supply: Battery

Problem Description

I have several boards running my firmware (about 10). Occasionally (once a week) these boards stop executing their code. I can diagnose this because the board will connect to wifi and push data to our backend. We take a timestamp each time this handshake occurs (every five minutes) so we can get a sense of what our units are doing. When the ESP32 is not polling wifi it sleeps for 5 minutes.

However, sometimes they just drop out infinitely and stop executing their code. We have set up several monitored units to catch the output when this occurs and this is what we caught. It occurred after a sleep period during startup.

Has anyone seen something like this before? Is there anyway I can diagnose further to understand what is happening?

Debug Logs
I (12) boot: ESP-IDF v4.1-dirty 2nd stage bootloader
I (12) boot: compile time 09:05:57
I (12) boot: chip revision: 1
I (14) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (21) boot.esp32: SPI Speed : 40MHz
I (26) boot.esp32: SPI Mode : DIO
I (30) boot.esp32: SPI Flash Size : 4MB
I (35) boot: Enabling RNG early entropy source...
I (40) boot: Partition Table:
I (44) boot: ## Label Usage Type ST Offset Length
I (51) boot: 0 nvs WiFi data 01 02 00009000 00006000
I (58) boot: 1 otadata OTA data 01 00 0000f000 00002000
I (66) boot: 2 phy_init RF data 01 01 00011000 00001000
I (73) boot: 3 ota_0 OTA app 00 10 00020000 00150000
I (81) boot: 4 ota_1 OTA app 00 11 00170000 00150000
I (88) boot: End of partition table
I (92) boot_comm: chip revision: 1, min. application chip revision: 0
I (99) esp_image: segment 0: paddr=0x00170020 vaddr=0x3f400020 size=0x384b0 (230576) map
I (196) esp_image: segment 1: paddr=0x001a84d8 vaddr=0x3ffbdb60 size=0x042e4 ( 17124) load
I (204) esp_image: segment 2: paddr=0x001ac7c4 vaddr=0x40080000 size=0x00404 ( 1028) load
0x40080000: _WindowOverflow4 at C:/Users/TonyWu/Desktop/esp-idf/components/freertos/xtensa_vectors.S:1778

I (204) esp_image: segment 3: paddr=0x001acbd0 vaddr=0x40080404 size=0x03448 ( 13384) load
I (218) esp_image: segment 4: paddr=0x001b0020 vaddr=0x400d0020 size=0xef52c (980268) map
0x400d0020: _stext at ??:?

I (594) esp_image: segment 5: paddr=0x0029f554 vaddr=0x4008384c size=0x1a878 (108664) load
0x4008384c: r_ea_alarm_set at ??:?

I (641) esp_image: segment 6: paddr=0x002b9dd4 vaddr=0x400c0000 size=0x00064 ( 100)
I (658) boot: Loaded app from partition at offset 0x170000
I (658) boot: Disabling RNG early entropy source...
I (658) cpu_start: Pro cpu up.
I (662) cpu_start: Application information:
I (667) cpu_start: Project name: oto-template
I (672) cpu_start: App version: f8f79036
I (677) cpu_start: Compile time: Sep 16 2020 17:07:27
I (683) cpu_start: ELF file SHA256: 6971aecc21d58d35...
I (689) cpu_start: ESP-IDF: v4.1-beta2-141-g84b51781c
I (696) cpu_start: Starting app cpu, entry point is 0x400814b4
0x400814b4: call_start_cpu1 at C:/Users/TonyWu/Desktop/esp-idf/components/esp32/cpu_start.c:271


I (0) cpu_start: App cpu up.
I (706) heap_init: Initializing. RAM available for dynamic allocation:
I (713) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (719) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (725) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (731) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM
I (737) heap_init: At 3FFCEB18 len 000114E8 (69 KiB): DRAM
I (744) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (750) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (756) heap_init: At 4009E0C4 len 00001F3C (7 KiB): IRAM
I (762) cpu_start: Pro cpu start user code
I (781) spi_flash: detected chip: generic
I (781) spi_flash: flash io: dio
I (782) cpu_start: S�`���~����f` �����~��������� �~������f~`�~���f�������~��~���`�~��x��`��~�f�~�xf��fx`�� �f��f��x������~f���~��~���������x��`�����`���fx�fx`��~��f��~��~���`�~����� �~���f�~�`����f����`���~����f` �����~��������� �~������f~`�~���������`�f������ff������

[jonking]

Anyone have any thoughts on this? Or any ideas on how I could debug this issue? I have been able to recreate several times. Help would be greatly appreciated.

[ESP_Sprite]

Any chance you're having power supply issues there? Battery nearly empty making the 3.3V line drop too low when the ESP32 is at that point in the startup process perhaps?

[rfleming]

Bit random, but when it does go all weird, have you tried changing your baud rate on your serial terminal app? Like drop it down to 76800 etc. Check the logic with your scope to see the actual timing.

I know this doesn't relate to your issue too much because it works all normally for a while. Though when I was using the sparkfun boards since it has a different reference crystal everything outputs from the terminal correctly at 115200, then as soon as it enters the application it goes all crazy. I do think in my situation that the default in-built stuff uses an internal slower crystal then upon app entry points uses the external. But still, could be something interesting to check? Crystal drift