Bootloader appeared to erase 128k flash while booting
Posted: Thu Mar 28, 2024 7:11 am
Hi all,
I have a battery-operated PCB that has an ESP32-WROOM-32E-N16 module on it. During a brownout condition, it recently showed the following logs:
(clip custom app logs. This tried to play audio via I2S immediately before the brownout in the next segment)
The "invalid header" text repeats indefinitely. The log data was captured with "tio", not esp_monitor, so I'm confident that no commands for erasing flash would have been transmitted from the host.
I deflashed the unit, and found that the first 128k of flash is now erased (all bytes 0xff).
I'm sure I didn't touch the unit at the time of the brownout. But what has me very worried is that the bootloader code can erase itself and a large chunk of config and app data.
I have tried to reproduce this behaviour, and I can't. I've caused numerous brownouts and they all (aside from this one) have resulted in a correctly running bootloader. I've also tried searching for any posts on this here and on stack overflow but I haven't found anything mentioning flash erasing during the 2nd stage bootloader so far.
Does anyone have any insights on what could cause this, or what avenues of investigation I should follow next?
I have a battery-operated PCB that has an ESP32-WROOM-32E-N16 module on it. During a brownout condition, it recently showed the following logs:
Code: Select all
ets Jul 29 2019 12:21:46
rst:0x1 (POWERON_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:7492
load:0x40078000,len:14088
load:0x40080400,len:4740
entry 0x4008070c
I (29) boot: ESP-IDF v4.2 2nd stage bootloader
I (29) boot: compile time 21:50:38
I (29) boot: chip revision: 3
I (32) boot_comm: chip revision: 3, min. bootloader chip revision: 0
I (39) boot.esp32: SPI Speed : 40MHz
I (44) boot.esp32: SPI Mode : DIO
I (48) boot.esp32: SPI Flash Size : 16MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label Usage Type ST Offset Length
I (69) boot: 0 dev_keys unknown 40 00 0000b000 00005000
I (77) boot: 1 hwtest test app 00 20 00010000 00200000
I (84) boot: 2 otadata OTA data 01 00 00210000 00002000
I (91) boot: 3 nvs WiFi data 01 02 00212000 0000e000
I (99) boot: 4 coredump Unknown data 01 03 00220000 00010000
I (106) boot: 5 factory factory app 00 00 00230000 00300000
I (114) boot: 6 ota_0 OTA app 00 10 00530000 00300000
I (122) boot: 7 ota_1 OTA app 00 11 00830000 00300000
I (129) boot: 8 log unknown 41 00 00b30000 00300000
I (137) boot: 9 storage Unknown data 01 81 00e30000 00100000
I (144) boot: End of partition table
I (149) boot_comm: chip revision: 3, min. application chip revision: 0
I (156) esp_image: segment 0: paddr=0x00530020 vaddr=0x3f400020 size=0x1502fc (1377020) map
I (689) esp_image: segment 1: paddr=0x00680324 vaddr=0x3ffb0000 size=0x0500c ( 20492) load
I (698) esp_image: segment 2: paddr=0x00685338 vaddr=0x40080000 size=0x00404 ( 1028) load
I (699) esp_image: segment 3: paddr=0x00685744 vaddr=0x40080404 size=0x0a8d4 ( 43220) load
I (724) esp_image: segment 4: paddr=0x00690020 vaddr=0x400d0020 size=0xbb8c0 (768192) map
I (1017) esp_image: segment 5: paddr=0x0074b8e8 vaddr=0x4008acd8 size=0x0d3b0 ( 54192) load
I (1041) esp_image: segment 6: paddr=0x00758ca0 vaddr=0x400c0000 size=0x00064 ( 100) load
I (1041) esp_image: segment 7: paddr=0x00758d0c vaddr=0x50000000 size=0x00014 ( 20) load
I (1048) esp_image: segment 8: paddr=0x00758d28 vaddr=0x00000000 size=0x07258 ( 29272)
I (1081) boot: Loaded app from partition at offset 0x530000
I (1081) boot: Disabling RNG early entropy source...
I (1082) cpu_start: Pro cpu up.
I (1085) cpu_start: Application information:
I (1090) cpu_start: Project name: test
I (1095) cpu_start: App version: v1.0.8
I (1100) cpu_start: Compile time: Mar 26 2024 07:20:46
I (1107) cpu_start: ELF file SHA256: 63a2c99ecfc845e2...
I (1113) cpu_start: ESP-IDF: v4.2
I (1118) cpu_start: Starting app cpu, entry point is 0x40081b40
I (0) cpu_start: App cpu up.
I (1128) heap_init: Initializing. RAM available for dynamic allocation:
I (1135) heap_init: At 3FFAE6E0 len 00001920 (6 KiB): DRAM
I (1141) heap_init: At 3FFBB578 len 00024A88 (146 KiB): DRAM
I (1147) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (1154) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (1160) heap_init: At 40098088 len 00007F78 (31 KiB): IRAM
I (1167) cpu_start: Pro cpu start user code
I (1185) spi_flash: detected chip: generic
I (1186) spi_flash: flash io: dio
I (1186) esp_core_dump_flash: Init core dump to flash
I (1190) esp_core_dump_flash: Found partition 'coredump' @ 220000 65536 bytes
I (1197) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
Code: Select all
Brownout detector was triggered
ets Jul 29 2019 12:21:46
rst:0xc (SW_CPU_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:7492
load:0x40078000,len:14088
load:0x40080400,len:4740
entry 0x4008070c
I (29) boot: ESP-IDF v4.2 2nd stage bootloader
I (29) boot: compile time 21:50:38
I (29) boot: chip revision: 3
I (32) boot_comm: chip revision: 3, min. bootloader chip revision: 0
ets Jul 29 2019 12:21:46
rst:0x10 (RTCWDT_RTC_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
ets Jul 29 2019 12:21:46
rst:0x10 (RTCWDT_RTC_RESET),boot:0x17 (SPI_FAST_FLASH_BOOT)
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
invalid header: 0xffffffff
ets Jul 29 2019 12:21:46
I deflashed the unit, and found that the first 128k of flash is now erased (all bytes 0xff).
I'm sure I didn't touch the unit at the time of the brownout. But what has me very worried is that the bootloader code can erase itself and a large chunk of config and app data.
I have tried to reproduce this behaviour, and I can't. I've caused numerous brownouts and they all (aside from this one) have resulted in a correctly running bootloader. I've also tried searching for any posts on this here and on stack overflow but I haven't found anything mentioning flash erasing during the 2nd stage bootloader so far.
Does anyone have any insights on what could cause this, or what avenues of investigation I should follow next?