Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Spontaneous Power Cycles and Intermittent Boot Loops #249

Open
rv4mike opened this issue Feb 8, 2025 · 19 comments
Open

Spontaneous Power Cycles and Intermittent Boot Loops #249

rv4mike opened this issue Feb 8, 2025 · 19 comments
Assignees
Labels
bug Something isn't working

Comments

@rv4mike
Copy link

rv4mike commented Feb 8, 2025

All I get is solid white LED with clicking sound from the speaker.  Did factory reset, reloaded the firmware. Logs attached.

esp-web-tools-logs.txt

@rv4mike rv4mike added the bug Something isn't working label Feb 8, 2025
@that1guy
Copy link
Collaborator

We have a Sat1 in our possession that reproduces this issue. We're investigating. Stay tuned!

@philgrocks
Copy link

Connected to the computer and I got these logs.

12:56:05]ESP-ROM:esp32s3-20210327
[12:56:05]Build:Mar 27 2021
[12:56:05]rst:0x15 (USB_UART_CHIP_RESET),boot:0xa (SPI_FAST_FLASH_BOOT)
[12:56:05]Saved PC:0x4216843e
[12:56:05]SPIWP:0xee
[12:56:05]mode:DIO, clock div:1
[12:56:05]load:0x3fce3808,len:0x16c4
[12:56:05]load:0x403c9700,len:0xbc0
[12:56:05]load:0x403cc700,len:0x2e90
[12:56:05]entry 0x403c9950
[12:56:05]I (24) boot: ESP-IDF 4.4.8 2nd stage bootloader
[12:56:05]I (24) boot: compile time 15:29:19
[12:56:05]I (25) boot: Multicore bootloader
[12:56:05]I (26) boot: chip revision: v0.2
[12:56:05]I (30) boot.esp32s3: Boot SPI Speed : 80MHz
[12:56:05]I (35) boot.esp32s3: SPI Mode : DIO
[12:56:05]I (40) boot.esp32s3: SPI Flash Size : 16MB
[12:56:05]I (45) boot: Enabling RNG early entropy source...
[12:56:05]I (50) boot: Partition Table:
[12:56:05]I (54) boot: ## Label Usage Type ST Offset Length
[12:56:05]I (61) boot: 0 otadata OTA data 01 00 00009000 00002000
[12:56:05]I (68) boot: 1 phy_init RF data 01 01 0000b000 00001000
[12:56:05]I (76) boot: 2 app0 OTA app 00 10 00010000 007c0000
[12:56:05]I (83) boot: 3 app1 OTA app 00 11 007d0000 007c0000
[12:56:05]I (91) boot: 4 nvs WiFi data 01 02 00f90000 0006d000
[12:56:05]I (98) boot: End of partition table
[12:56:05]I (102) esp_image: segment 0: paddr=00010020 vaddr=3c170020 size=14480ch (1329164) map
[12:56:05]I (349) esp_image: segment 1: paddr=00154834 vaddr=3fc9dd10 size=04974h ( 18804) load
[12:56:05]I (354) esp_image: segment 2: paddr=001591b0 vaddr=40374000 size=06e68h ( 28264) load
[12:56:05]I (361) esp_image: segment 3: paddr=00160020 vaddr=42000020 size=16a920h (1485088) map
[12:56:05]I (630) esp_image: segment 4: paddr=002ca948 vaddr=4037ae68 size=12ea0h ( 77472) load
[12:56:06]I (657) boot: Loaded app from partition at offset 0x10000
[12:56:06]I (658) boot: Disabling RNG early entropy source...
[12:56:06]I (658) cpu_start: Multicore app
[12:56:06]I (662) opi psram: vendor id : 0x0d (AP)
[12:56:06]I (666) opi psram: dev id : 0x02 (generation 3)
[12:56:06]I (672) opi psram: density : 0x03 (64 Mbit)
[12:56:06]I (677) opi psram: good-die : 0x01 (Pass)
[12:56:06]I (682) opi psram: Latency : 0x01 (Fixed)
[12:56:06]I (686) opi psram: VCC : 0x01 (3V)
[12:56:06]I (691) opi psram: SRF : 0x01 (Fast Refresh)
[12:56:06]I (696) opi psram: BurstType : 0x01 (Hybrid Wrap)
[12:56:06]I (702) opi psram: BurstLen : 0x01 (32 Byte)
[12:56:06]I (707) opi psram: Readlatency : 0x02 (10 cycles@Fixed)
[12:56:06]I (713) opi psram: DriveStrength: 0x00 (1/1)
[12:56:06]I (718) MSPI Timing: PSRAM timing tuning index: 10
[12:56:06]I (723) spiram: Found 64MBit SPI RAM device
[12:56:06]I (728) spiram: SPI RAM mode: sram 80m
[12:56:06]I (733) spiram: PSRAM initialized, cache is in normal (1-core) mode.
[12:56:06]I (740) cpu_start: Pro cpu up.
[12:56:06]I (743) cpu_start: Starting app cpu, entry point is 0x403779b4
[12:56:06]I (0) cpu_start: App cpu up.
[12:56:06]I (1169) spiram: SPI SRAM memory test OK
[12:56:06]I (1178) cpu_start: Pro cpu start user code
[12:56:06]I (1178) cpu_start: cpu freq: 240000000
[12:56:06]I (1178) cpu_start: Application information:
[12:56:06]I (1179) cpu_start: Project name: satellite1
[12:56:06]I (1179) cpu_start: App version: 2024.11.2
[12:56:06]I (1179) cpu_start: Compile time: Dec 19 2024 15:24:15
[12:56:06]I (1179) cpu_start: ELF file SHA256: 5424abe94cb4c30f...
[12:56:06]I (1179) cpu_start: ESP-IDF: 4.4.8
[12:56:06]I (1180) cpu_start: Min chip rev: v0.0
[12:56:06]I (1180) cpu_start: Max chip rev: v0.99
[12:56:06]I (1180) cpu_start: Chip rev: v0.2
[12:56:06]I (1180) heap_init: Initializing. RAM available for dynamic allocation:
[12:56:06]I (1180) heap_init: At 3FCA9258 len 000404B8 (257 KiB): D/IRAM
[12:56:06]I (1181) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DIRAM
[12:56:06]I (1181) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
[12:56:06]I (1181) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
[12:56:06]I (1182) spiram: Adding pool of 8192K of external SPI memory to heap allocator
[12:56:06]I (1182) spi_flash: detected chip: gd
[12:56:06]I (1183) spi_flash: flash io: dio
[12:56:06]I (1185) sleep: Configure to isolate all GPIO pins in sleep state
[12:56:06]I (1186) sleep: Enable automatic switching of GPIO sleep configuration
[12:56:06]I (1186) coexist: coexist rom version e7ae62f
[12:56:06]I (1187) cpu_start: Starting scheduler on PRO CPU.
[12:56:06]I (0) cpu_start: Starting scheduler on APP CPU.
[12:56:06][W][esp-idf:000]: I (94) gpio: GPIO[45]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1429) gpio: GPIO[6]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1430) gpio: GPIO[5]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1442) gpio: GPIO[10]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1444) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1653) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1732) pp: pp rom version: e7ae62f
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1733) net80211: net80211 rom version: e7ae62f
[12:56:06]
[12:56:06][W][esp-idf:000]: I (1735) wifi:
[12:56:06][W][esp-idf:000]: wifi driver task: 3fcb608c, prio:23, stack:6656, core=0
[12:56:06][W][esp-idf:000]:
[12:56:06]
[12:56:06][W][esp-idf:000][wifi]: I (1736) system_api: Base MAC address is not set
[12:56:06]
[12:56:06][W][esp-idf:000][wifi]: I (1737) system_api: read default base MAC address from EFUSE
[12:56:06]
[12:56:06][W][esp-idf:000][wifi]: I (1745) wifi:
[12:56:06][W][esp-idf:000][wifi]: wifi firmware version: ff661c3
[12:56:06][W][esp-idf:000][wifi]:
[12:56:06]
[12:56:06][W][esp-idf:000][wifi]: I (1746) wifi:
[12:56:06][W][esp-idf:000][wifi]: wifi certification version: v7.0
[12:56:06][W][esp-idf:000][wifi]:
[12:56:06]
[12:56:06][W][esp-idf:000][wifi]: I (1747) wifi:
[12:56:06][W][esp-idf:000][wifi]: config NVS flash: enabled
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1749) wifi:
[12:56:07][W][esp-idf:000][wifi]: config nano formating: disabled
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1750) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init data frame dynamic rx buffer num: 32
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1752) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init static rx mgmt buffer num: 5
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1753) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init management short buffer num: 32
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1754) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init dynamic tx buffer num: 32
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1756) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init tx cache buffer num: 32
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1757) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init static tx FG buffer num: 2
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1759) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init static rx buffer size: 1600
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1760) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init static rx buffer num: 16
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1761) wifi:
[12:56:07][W][esp-idf:000][wifi]: Init dynamic rx buffer num: 32
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1763) wifi_init: rx ba win: 16
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1764) wifi_init: tcpip mbox: 32
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1764) wifi_init: udp mbox: 6
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1765) wifi_init: tcp mbox: 6
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1765) wifi_init: tcp tx win: 5760
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1766) wifi_init: tcp rx win: 5760
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1766) wifi_init: tcp mss: 1440
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1767) wifi_init: WiFi/LWIP prefer SPIRAM
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1767) wifi_init: WiFi IRAM OP enabled
[12:56:07]
[12:56:07][W][esp-idf:000]: I (1768) wifi_init: WiFi RX IRAM OP enabled
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1771) phy_init: phy_version 670,b7bc9b9,Apr 30 2024,10:54:13
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1807) wifi:
[12:56:07][W][esp-idf:000][wifi]: mode : sta (d8:3b:da:40:74:b4)
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1808) wifi:
[12:56:07][W][esp-idf:000][wifi]: enable tsf
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1810) wifi:
[12:56:07][W][esp-idf:000][wifi]: Set ps type: 1
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]: I (1821) wifi:
[12:56:07][W][esp-idf:000][wifi]: Set ps type: 1
[12:56:07]
[12:56:07][W][esp-idf:000][wifi]:
[12:56:07]
[12:56:07][W][component:157]: Component wifi set Warning flag: scanning for networks
[12:56:07][W][esp-idf:000]: I (1842) BLE_INI: BT controller compile version [ba3b3e3]
[12:56:07]
[12:56:07][W][esp-idf:000][btController]: I (1844) BLE_INIT: Bluetooth MAC: d8:3b:da:40:74:b6
[12:56:07]
[12:56:07]
[12:56:09][W][esp-idf:000] I (3844) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2
[12:56:09]
[12:56:09]MSG READER TASK STARTED
[12:56:15][W][esp-idf:000][wifi]: I (10304) wifi:
[12:56:15][W][esp-idf:000][wifi]: new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
[12:56:15][W][esp-idf:000][wifi]:
[12:56:15]
[12:56:15][W][esp-idf:000][wifi]: I (10307) wifi:
[12:56:15][W][esp-idf:000][wifi]: state: init -> auth (b0)
[12:56:15][W][esp-idf:000][wifi]:
[12:56:15]
[12:56:16][W][esp-idf:000][wifi]: I (10969) wifi:
[12:56:16][W][esp-idf:000][wifi]: state: auth -> assoc (0)
[12:56:16][W][esp-idf:000][wifi]:
[12:56:16]
[12:56:16][W][esp-idf:000][wifi]: I (10984) wifi:
[12:56:16][W][esp-idf:000][wifi]: Association refused temporarily, comeback time 1000 (TUs)
[12:56:16][W][esp-idf:000][wifi]:
[12:56:16]
[12:56:17][W][esp-idf:000][wifi]: I (12010) wifi:
[12:56:17][W][esp-idf:000][wifi]: state: assoc -> assoc (0)
[12:56:17][W][esp-idf:000][wifi]:
[12:56:17]
[12:56:17][W][esp-idf:000][wifi]: I (12032) wifi:
[12:56:17][W][esp-idf:000][wifi]: state: assoc -> init (9c0)
[12:56:17][W][esp-idf:000][wifi]:
[12:56:17]
[12:56:17][W][esp-idf:000][wifi]: I (12034) wifi:
[12:56:17][W][esp-idf:000][wifi]: Coexist: Wi-Fi connect fail, apply reconnect coex policy
[12:56:17]
[12:56:17][W][esp-idf:000][wifi]:
[12:56:17]
[12:56:17][W][esp-idf:000][wifi]: I (12036) wifi:
[12:56:17][W][esp-idf:000][wifi]: new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
[12:56:17][W][esp-idf:000][wifi]:
[12:56:17]
[12:56:17][W][wifi_esp32:712]: Event: Disconnected ssid='Hiwinders' bssid=[redacted] reason='Association Failed'
[12:56:17][W][wifi:653]: Error while connecting to network.
Terminal disconnected: NetworkError: The device has been lost.

@philgrocks
Copy link

Another one... This shows a panic!

[13:03:57][W][esp-idf:000][ann_read]: I (460720) HTTP_CLIENT: Body received in fetch header state, 0x3fcda5af, 305
[13:03:57]
[13:04:14][W][esp-idf:000][ann_read]: I (477387) HTTP_CLIENT: Body received in fetch header state, 0x3fcda7b3, 305
[13:04:14]
[13:15:27]Guru Meditation Error: Core 0 panic'ed (StoreProhibited). Exception was unhandled.
[13:15:27]
[13:15:27]Core 0 register dump:
[13:15:27]PC : 0x40388310 PS : 0x00060133 A0 : 0x80388928 A1 : 0x3fcb5d20
[13:15:27]A2 : 0x3d800014 A3 : 0x3d80001c A4 : 0xc05e17fd A5 : 0x000808e8
[13:15:27]A6 : 0x02cb3f0c A7 : 0x00ffffff A8 : 0x00000000 A9 : 0x00000009
[13:15:27]A10 : 0xc05e17fd A11 : 0x000006a4 A12 : 0x3d800038 A13 : 0x3d80007c
[13:15:27]A14 : 0x00060f20 A15 : 0x00000001 SAR : 0x0000001b EXCCAUSE: 0x0000001d
[13:15:27]EXCVADDR: 0xc05e1809 LBEG : 0x40056f5c LEND : 0x40056f72 LCOUNT : 0xffffffff
[13:15:27]
[13:15:27]
[13:15:27]Backtrace: 0x4038830d:0x3fcb5d20 0x40388925:0x3fcb5d40 0x40379247:0x3fcb5d60 0x4037930e:0x3fcb5d90 0x40378831:0x3fcb5de0 0x4216881d:0x3fcb5e00 0x4038af79:0x3fcb5e30 0x4038b8c0:0x3fcb5e60 0x4038bd31:0x3fcb5ea0 0x40041502:0x3fcb5ee0 0x4038a71d:0x3fcb5f10
[13:15:27]
[13:15:27]
[13:15:27]
[13:15:27]
[13:15:27]ELF file SHA256: 5424abe94cb4c30f
[13:15:27]
[13:15:27]Rebooting...
[13:15:27]ESP-ROM:esp32s3-20210327
[13:15:27]Build:Mar 27 2021
[13:15:27]rst:0xc (RTC_SW_CPU_RST),boot:0xa (SPI_FAST_FLASH_BOOT)
[13:15:27]Saved PC:0x40378050
[13:15:27]SPIWP:0xee
[13:15:27]mode:DIO, clock div:1
[13:15:27]load:0x3fce3808,len:0x16c4
[13:15:27]load:0x403c9700,len:0xbc0
[13:15:27]load:0x403cc700,len:0x2e90
[13:15:28]entry 0x403c9950
[13:15:28]I (24) boot: ESP-IDF 4.4.8 2nd stage bootloader
[13:15:28]I (24) boot: compile time 15:29:19
[13:15:28]I (24) boot: Multicore bootloader
[13:15:28]I (26) boot: chip revision: v0.2
[13:15:28]I (30) boot.esp32s3: Boot SPI Speed : 80MHz
[13:15:28]I (35) boot.esp32s3: SPI Mode : DIO
[13:15:28]I (39) boot.esp32s3: SPI Flash Size : 16MB
[13:15:28]I (44) boot: Enabling RNG early entropy source...
[13:15:28]I (49) boot: Partition Table:
[13:15:28]I (53) boot: ## Label Usage Type ST Offset Length
[13:15:28]I (60) boot: 0 otadata OTA data 01 00 00009000 00002000
[13:15:28]I (68) boot: 1 phy_init RF data 01 01 0000b000 00001000
[13:15:28]I (75) boot: 2 app0 OTA app 00 10 00010000 007c0000
[13:15:28]I (83) boot: 3 app1 OTA app 00 11 007d0000 007c0000
[13:15:28]I (90) boot: 4 nvs WiFi data 01 02 00f90000 0006d000
[13:15:28]I (98) boot: End of partition table
[13:15:28]I (102) esp_image: segment 0: paddr=00010020 vaddr=3c170020 size=14480ch (1329164) map
[13:15:28]I (349) esp_image: segment 1: paddr=00154834 vaddr=3fc9dd10 size=04974h ( 18804) load
[13:15:28]I (353) esp_image: segment 2: paddr=001591b0 vaddr=40374000 size=06e68h ( 28264) load
[13:15:28]I (361) esp_image: segment 3: paddr=00160020 vaddr=42000020 size=16a920h (1485088) map
[13:15:28]I (630) esp_image: segment 4: paddr=002ca948 vaddr=4037ae68 size=12ea0h ( 77472) load
[13:15:28]I (657) boot: Loaded app from partition at offset 0x10000
[13:15:28]I (657) boot: Disabling RNG early entropy source...
[13:15:28]I (658) cpu_start: Multicore app
[13:15:28]I (662) opi psram: vendor id : 0x0d (AP)
[13:15:28]I (666) opi psram: dev id : 0x02 (generation 3)
[13:15:28]I (671) opi psram: density : 0x03 (64 Mbit)
[13:15:28]I (676) opi psram: good-die : 0x01 (Pass)
[13:15:28]I (681) opi psram: Latency : 0x01 (Fixed)
[13:15:28]I (686) opi psram: VCC : 0x01 (3V)
[13:15:28]I (691) opi psram: SRF : 0x01 (Fast Refresh)
[13:15:28]I (696) opi psram: BurstType : 0x01 (Hybrid Wrap)
[13:15:28]I (701) opi psram: BurstLen : 0x01 (32 Byte)
[13:15:28]I (706) opi psram: Readlatency : 0x02 (10 cycles@Fixed)
[13:15:28]I (712) opi psram: DriveStrength: 0x00 (1/1)
[13:15:28]I (718) MSPI Timing: PSRAM timing tuning index: 5
[13:15:28]I (723) spiram: Found 64MBit SPI RAM device
[13:15:28]I (728) spiram: SPI RAM mode: sram 80m
[13:15:28]I (732) spiram: PSRAM initialized, cache is in normal (1-core) mode.
[13:15:28]I (739) cpu_start: Pro cpu up.
[13:15:28]I (743) cpu_start: Starting app cpu, entry point is 0x403779b4
[13:15:28]I (731) cpu_start: App cpu up.
[13:15:29]I (1175) spiram: SPI SRAM memory test OK
[13:15:29]I (1184) cpu_start: Pro cpu start user code
[13:15:29]I (1184) cpu_start: cpu freq: 240000000
[13:15:29]I (1184) cpu_start: Application information:
[13:15:29]I (1185) cpu_start: Project name: satellite1
[13:15:29]I (1185) cpu_start: App version: 2024.11.2
[13:15:29]I (1185) cpu_start: Compile time: Dec 19 2024 15:24:15
[13:15:29]I (1185) cpu_start: ELF file SHA256: 5424abe94cb4c30f...
[13:15:29]I (1185) cpu_start: ESP-IDF: 4.4.8
[13:15:29]I (1186) cpu_start: Min chip rev: v0.0
[13:15:29]I (1186) cpu_start: Max chip rev: v0.99
[13:15:29]I (1186) cpu_start: Chip rev: v0.2
[13:15:29]I (1186) heap_init: Initializing. RAM available for dynamic allocation:
[13:15:29]I (1186) heap_init: At 3FCA9258 len 000404B8 (257 KiB): D/IRAM
[13:15:29]I (1187) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DIRAM
[13:15:29]I (1187) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
[13:15:29]I (1187) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
[13:15:29]I (1188) spiram: Adding pool of 8192K of external SPI memory to heap allocator
[13:15:29]I (1188) spi_flash: detected chip: gd
[13:15:29]I (1189) spi_flash: flash io: dio
[13:15:29]I (1191) sleep: Configure to isolate all GPIO pins in sleep state
[13:15:29]I (1192) sleep: Enable automatic switching of GPIO sleep configuration
[13:15:29]I (1192) coexist: coexist rom version e7ae62f
[13:15:29]I (1193) cpu_start: Starting scheduler on PRO CPU.
[13:15:29]I (0) cpu_start: Starting scheduler on APP CPU.
[13:15:29][W][esp-idf:000]: I (94) gpio: GPIO[45]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1431) gpio: GPIO[6]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1433) gpio: GPIO[5]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1445) gpio: GPIO[10]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1447) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1656) pio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1735) pp: pp rom version: e7ae62f
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1736) net80211: net80211 rom version: e7ae62f
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1738) wifi:
[13:15:29][W][esp-idf:000]: wifi driver task: 3fcb608c, prio:23, stack:6656, core=0
[13:15:29][W][esp-idf:000]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1739) system_api: Base MAC address is not set
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1740) system_api: read default base MAC address from EFUSE
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1748) wifi:
[13:15:29][W][esp-idf:000][wifi]: wifi firmware version: ff661c3
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1749) wifi:
[13:15:29][W][esp-idf:000][wifi]: wifi certification version: v7.0
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1750) wifi:
[13:15:29][W][esp-idf:000][wifi]: config NVS flash: enabled
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1752) wifi:
[13:15:29][W][esp-idf:000][wifi]: config nano formating: disabled
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1753) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init data frame dynamic rx buffer num: 32
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1755) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init static rx mgmt buffer num: 5
[13:15:29][W][esp-idf:000][wifi:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1756) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init management short buffer num: 32
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1757) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init dynamic tx buffer num: 32
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1759) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init tx cache buffer num: 32
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1760) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init static tx FG buffer num: 2
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1762) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init static rx buffer size: 1600
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1763) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init static rx buffer num: 16
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1764) wifi:
[13:15:29][W][esp-idf:000][wifi]: Init dynamic rx buffer num: 32
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1766) wifi_init: rx ba win: 16
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1767) wifi_init: tcpip mbox: 32
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1767) wifi_init: udp mbox: 6
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1768) wifi_init: tcp mbox: 6
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1768) wifi_init: tcp tx win: 5760
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1769) wifi_init: tcp rx win: 5760
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1769) wifi_init: tcp mss: 1440
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1770) wifi_init: WiFi/LWIP prefer SPIRAM
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1770) wifi_init: WiFi IRAM OP enabled
[13:15:29]
[13:15:29][W][esp-idf:000]: I (1771) wifi_init: WiFi RX IRAM OP enabled
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1774) phy_init: phy_version 670,b7bc9b9,Apr 30 2024,10:54:13
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1811) wifi:
[13:15:29][W][esp-idf:000][wifi]: mode : sta (d8:3b:da:40:74:b4)
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1813) wifi:
[13:15:29][W][esp-idf:000][wifi]: enable tsf
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1815) wifi:
[13:15:29][W][esp-idf:000][wifi]: Set ps type: 1
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]:
[13:15:29]
[13:15:29][W][esp-idf:000][wifi]: I (1825) wifi:
[13:15:29][W][esp-idf:000][wifi]: Set ps type: 1
[13:15:29]
[13:15:29][W][esp-idf:000][ifi]:
[13:15:29]
[13:15:29][W][component:157]: Component wifi set Warning flag: scanning for networks
[13:15:29][W][esp-idf:000]: I (1848) BLE_INIT: BT controller compile version [ba3b3e3]
[13:15:29]
[13:15:29][W][esp-idf:000][btController]: I (1850) BLE_INIT: Bluetooth MAC: d8:3b:da:40:74:b6
[13:15:29]
[13:15:29]
[13:15:31][W][esp-idf:000]: I (3848) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2
[13:15:31]
[13:15:31]MSG READER TASK STARTED
[13:15:38][W][esp-idf:000][wifi]: I (10319) wifi:
[13:15:38][W][esp-idf:000][wifi]: new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
[13:15:38][W][esp-idf:000][wifi]:
[13:15:38]
[13:15:38][W][esp-idf:000][wifi]: I (10321) wifi:
[13:15:38][W][esp-idf:000][wifi]: state: init -> auth (b0)
[13:15:38][W][esp-idf:000][wifi]:
[13:15:38]
[13:15:38][W][esp-idf:000][wifi]: I (10988) wifi:
[13:15:38][W][esp-idf:000][wifi]: state: auth -> assoc (0)
[13:15:38][W][esp-idf:000][wifi]:
[13:15:38]
[13:15:38][W][esp-idf:000][wifi]: I (11002) wifi:
[13:15:38][W][esp-idf:000][wifi]: Association refused temporarily, comeback time 1000 (TUs)
[13:15:38][W][esp-idf:000][wifi]:
[13:15:38]
[13:15:39][W][esp-idf:000][wifi]: I (12028) wifi:
[13:15:39][W][esp-idf:000][wifi]: state: assoc -> assoc (0)
[13:15:39][W][esp-idf:000][wifi]:
[13:15:39]
[13:15:39][W][esp-idf:000][wifi]: I (12053) wifi:
[13:15:39][W][esp-idf:000][wifi]: state: assoc -> init (9c0)
[13:15:39][W][esp-idf:000][wifi]:
[13:15:39]
[13:15:39][W][esp-idf:000][wifi]: I (12055) wifi:
[13:15:39][W][esp-idf:000][wifi]: Coexist: Wi-Fi connect fail, apply reconnect coex policy
[13:15:39]
[13:15:39][W][esp-idf:000][wifi]:
[13:15:39]
[13:15:39][W][esp-idf:000][wifi]: I (12056) wifi:
[13:15:39][W][esp-idf:000][wifi]: new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
[13:15:39][W][esp-idf:000][wifi]:
[13:15:39]
[13:15:39][W][wifi_esp32:712]: Event: Disconnected ssid='Hiwinders' bssid=[redacted] reason='Association Failed'
[13:15:39][W][wifi:653]: Error while connecting to network.
[13:15:39][W][esp-idf:000][wifi]: I (12114) wifi:
[13:15:39][W][esp-idf:000][wifi]: new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
[13:15:39][W][esp-idf:000][wifi]:
[13:15:39]
[13:15:39][W][esp-idf:000][wifi]: I (12117) wifi:
[13:15:40][W][esp-idf:000][wifi]: state: init -> auth (b0)
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12787) wifi:
[13:15:40][W][esp-idf:000][wifi]: state: auth -> assoc (0)
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12799) wifi:
[13:15:40][W][esp-idf:000][wifi]: state: assoc -> run (10)
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12815) wifi:
[13:15:40][W][esp-idf:000][wifi]: connected with Hiwinders, aid = 2, channel 6, BW20, bssid = 9c:05:d6:6a:bc:30
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12817) wifi:
[13:15:40][W][esp-idf:000][wifi]: security: WPA3-SAE, phy: bgn, rssi: -40
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12819) wifi:
[13:15:40][W][esp-idf:000][wifi]: pm start, type: 1
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12821) wifi:
[13:15:40][W][esp-idf:000][wifi]: set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12833) wifi:
[13:15:40][W][esp-idf:000][wifi]: AP's beacon interval = 102400 us, DTIM period = 2
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:40][W][esp-idf:000][wifi]: I (12838) wifi:
[13:15:40][W][esp-idf:000][wifi]: idx:0 (ifx:0, 9c:05:d6:6a:bc:30), tid:6, ssn:2, winSize:64
[13:15:40][W][esp-idf:000][wifi]:
[13:15:40]
[13:15:41][W][esp-idf:000][sys_evt]: I (13825) esp_netif_handlers: sta ip: 192.168.1.150, mask: 255.255.255.0, gw: 192.168.1.1
[13:15:41]
[13:15:41][W][esp-idf:000][wifi]: I (13876) wifi:
[13:15:41][W][esp-idf:000][wifi]: idx:1 (ifx:0, 9c:05:d6:6a:bc:30), tid:0, ssn:0, winSize:64
[13:15:41][W][esp-idf:000][wifi]:
[13:15:41]
[13:15:42][W][esp-idf:000]: I (14207) esp-x509-crt-bundle: Certificate validated
[13:15:42]
[13:15:42][W][component:237]: Component http_request.update took a long time for an operation (960 ms).
[13:15:42][W][component:238]: Components should block for at most 30 ms.
[13:15:42][W][component:170]: Component wifi cleared Warning flag
[13:15:42][W][component:157]: Component api set Warning flag: unspecified
[13:15:45][W][component:170]: Component api cleared Warning flag
[13:15:47][W][esp-idf:000][BTU_TASK]: (19812) BT_APPL: bta_dm_disable BTA_DISABLE_DELAY set to 200 ms
[13:15:47]
[13:15:47][W][component:237]: Component esp32_ble took a long time for an operation (209 ms).
[13:15:47][W][component:238]: Components should block for at most 30 ms.
[13:15:49][W][esp-idf:000][microphone_task]: I (21830) I2S: DMA Malloc info, datalen=blocksize=4088, dma_buf_count=6
[13:15:49]
[13:15:49][W][esp-idf:000][microphone_task]: I (21832) I2S: DMA Malloc info, datalen=blocksize=4088, dma_buf_count=6
[13:15:49]

@that1guy
Copy link
Collaborator

Just wanted to share the results of all the customer troubleshooting polls here. Here is link to actual polls.

Image

@that1guy
Copy link
Collaborator

Another one... This shows a panic!

These logs are really helpful @philgrocks. Thank you! Please let me know if any of the information below is not accurate.

For the record - below are details on the customer's device that is panicking:

  • The panic typically occurs immediately AFTER the customer utters the wake word. However, the customer has also seen the device fall into boot loops immediately upon powering up the device.
  • ESP firmware version: 0.0.4 (original factory firmware)
  • ESP Dashboard has not "taken control" of the device
  • Customer is not running any mmWave sensors.
  • Anker 60W USB-C power adapter reproduces the panic consistently, but this could change over time, we think.
  • Apple branded 29W USB-C power adapter reproduces the panic intermittently.
  • Another Anker 60W usb c adapter which DOES not reproduce the panic issue, but again this could change over time, we think.
  • Another Anker Nano 30W usb c adapter which DOES not reproduce the panic issue.

@that1guy
Copy link
Collaborator

that1guy commented Feb 17, 2025

@philgrocks can you tell me if this panic occurs when you've unplugged the speaker from the built-in amplifier and are just running a 3.5mm external speaker with a USB-C power adapter?

Also, does the panic occur when you plug into a 5v USB-C computer or laptop connection? NOTE: You must plug in an external 3.5mm speaker as 5v will not power the amplifier and built-in speaker.

@philgrocks
Copy link

philgrocks commented Feb 17, 2025 via email

@philgrocks
Copy link

@philgrocks can you tell me if this panic occurs when you've unplugged the speaker from the built-in amplifier and are just running a 3.5mm external speaker with a USB-C power adapter?

Using external powered speaker off of 3.5mm Jack

Also, does the panic occur when you plug into a 5v USB-C computer or laptop connection? NOTE: You must plug in an external 3.5mm speaker as 5v will not power the amplifier and built-in speaker.

The panic has occurred with my 2018 MacBook Pro as power source or with USB-C power supplies. I'm always using 3.5mm speaker connection.

@philgrocks
Copy link

Here is another log from this morning. A bit different (not a panic, but "abort() was called...". I was asking for the time three times over about 10 minutes. Third time it crashed.

Let me know if you want me to keep posting these.

[09:03:51][W][esp-idf:000][ann_read]: I (26147090) HTTP_CLIENT: Body received in fetch header state, 0x3fcca8df, 305
[09:03:51]
[09:04:14][W][esp-idf:000][ann_read]: I (26170838) HTTP_CLIENT: Body received in fetch header state, 0x3fcca6db, 305
[09:04:14]
[09:12:34][W][esp-idf:000][ann_read]: I (26670152) HTTP_CLIENT: Body received in fetch header state, 0x3fcca6db, 305
[09:12:34]
[09:12:34]
[09:12:34]abort() was called at PC 0x420885a8 on core 0
[09:12:34]
[09:12:34]
[09:12:34]Backtrace: 0x4037844e:0x3fcd1eb0 0x40381d51:0x3fcd1ed0 0x40389a4a:0x3fcd1ef0 0x420885a8:0x3fcd1f60 0x4208eb75:0x3fcd1f80 0x42087f57:0x3fcd1fa0 0x42087c4f:0x3fcd1fd0 0x4201a868:0x3fcd1ff0 0x4201a0d9:0x3fcd2020 0x4201a47d:0x3fcd2070
[09:12:34]
[09:12:34]
[09:12:34]
[09:12:34]
[09:12:34]ELF file SHA256: 5424abe94cb4c30f
[09:12:34]
[09:12:34]Rebooting...
[09:12:34]ESP-ROM:esp32s3-20210327
[09:12:34]Build:Mar 27 2021
[09:12:34]rst:0xc (RTC_SW_CPU_RST),boot:0xa (SPI_FAST_FLASH_BOOT)
[09:12:34]Saved PC:0x40378050
[09:12:34]SPIWP:0xee
[09:12:34]mode:DIO, clock div:1
[09:12:34]load:0x3fce3808,len:0x16c4
[09:12:34]load:0x403c9700,len:0xbc0
[09:12:34]load:0x403cc700,len:0x2e90
[09:12:34]entry 0x403c9950
[09:12:34]I (24) boot: ESP-IDF 4.4.8 2nd stage bootloader
[09:12:34]I (24) boot: compile time 15:29:19
[09:12:34]I (24) boot: Multicore bootloader
[09:12:34]I (26) boot: chip revision: v0.2
[09:12:34]I (30) boot.esp32s3: Boot SPI Speed : 80MHz
[09:12:34]I (35) boot.esp32s3: SPI Mode : DIO
[09:12:34]I (39) boot.esp32s3: SPI Flash Size : 16MB
[09:12:34]I (44) boot: Enabling RNG early entropy source...
[09:12:34]I (49) boot: Partition Table:
[09:12:34]I (53) boot: ## Label Usage Type ST Offset Length
[09:12:34]I (60) boot: 0 otadata OTA data 01 00 00009000 00002000
[09:12:34]I (68) boot: 1 phy_init RF data 01 01 0000b000 00001000
[09:12:34]I (75) boot: 2 app0 OTA app 00 10 00010000 007c0000
[09:12:34]I (83) boot: 3 app1 OTA app 00 11 007d0000 007c0000
[09:12:34]I (90) boot: 4 nvs WiFi data 01 02 00f90000 0006d000
[09:12:34]I (98) boot: End of partition table
[09:12:34]I (102) esp_image: segment 0: paddr=00010020 vaddr=3c170020 size=14480ch (1329164) map
[09:12:34]I (349) esp_image: segment 1: paddr=00154834 vaddr=3fc9dd10 size=04974h ( 18804) load
[09:12:34]I (353) esp_image: segment 2: paddr=001591b0 vaddr=40374000 size=06e68h ( 28264) load
[09:12:34]I (361) esp_image: segment 3: paddr=00160020 vaddr=42000020 size=16a920h (1485088) map
[09:12:35]I (630) esp_image: segment 4: paddr=002ca948 vaddr=4037ae68 size=12ea0h ( 77472) load
[09:12:35]I (657) boot: Loaded app from partition at offset 0x10000
[09:12:35]I (657) boot: Disabling RNG early entropy source...
[09:12:35]I (658) cpu_start: Multicore app
[09:12:35]I (661) opi psram: vendor id : 0x0d (AP)
[09:12:35]I (666) opi psram: dev id : 0x02 (generation 3)
[09:12:35]I (671) opi psram: density : 0x03 (64 Mbit)
[09:12:35]I (676) opi psram: good-die : 0x01 (Pass)
[09:12:35]I (681) opi psram: Latency : 0x01 (Fixed)
[09:12:35]I (686) opi psram: VCC : 0x01 (3V)
[09:12:35]I (690) opi psram: SRF : 0x01 (Fast Refresh)
[09:12:35]I (696) opi psram: BurstType : 0x01 (Hybrid Wrap)
[09:12:35]I (701) opi psram: BurstLen : 0x01 (32 Byte)
[09:12:35]I (706) opi psram: Readlatency : 0x02 (10 cycles@Fixed)
[09:12:35]I (712) opi psram: DriveStrength: 0x00 (1/1)
[09:12:35]I (718) MSPI Timing: PSRAM timing tuning index: 11
[09:12:35]I (723) spiram: Found 64MBit SPI RAM device
[09:12:35]I (728) spiram: SPI RAM mode: sram 80m
[09:12:35]I (732) spiram: PSRAM initialized, cache is in normal (1-core) mode.
[09:12:35]I (739) cpu_start: Pro cpu up.
[09:12:35]I (743) cpu_start: Starting app cpu, entry point is 0x403779b4
[09:12:35]I (731) cpu_start: App cpu up.
[09:12:35]I (1175) spiram: SPI SRAM memory test OK
[09:12:35]I (1184) cpu_start: Pro cpu start user code
[09:12:35]I (1184) cpu_start: cpu freq: 240000000
[09:12:35]I (1184) cpu_start: Application information:
[09:12:35]I (1185) cpu_start: Project name: satellite1
[09:12:35]I (1185) cpu_start: App version: 2024.11.2
[09:12:35]I (1185) cpu_start: Compile time: Dec 19 2024 15:24:15
[09:12:35]I (1185) cpu_start: ELF file SHA256: 5424abe94cb4c30f...
[09:12:35]I (1185) cpu_start: ESP-IDF: 4.4.8
[09:12:35]I (1186) cpu_start: Min chip rev: v0.0
[09:12:35]I (1186) cpu_start: Max chip rev: v0.99
[09:12:35]I (1186) cpu_start: Chip rev: v0.2
[09:12:35]I (1186) heap_init: Initializing. RAM available for dynamic allocation:
[09:12:35]I (1186) heap_init: At 3FCA9258 len 000404B8 (257 KiB): D/IRAM
[09:12:35]I (1187) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DIRAM
[09:12:35]I (1187) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
[09:12:35]I (1187) heap_init: At 600FE000 len 00002000 (8 KiB): RTCRAM
[09:12:35]I (1188) spiram: Adding pool of 8192K of external SPI memory to heap allocator
[09:12:35]I (1188) spi_flash: detected chip: gd
[09:12:35]I (1189) spi_flash: flash io: dio
[09:12:35]I (1191) sleep: Configure to isolate all GPIO pins in sleep state
[09:12:35]I (1192) sleep: Enable automatic switching of GPIO sleep configuration
[09:12:35]I (1192) coexist: coexist rom version e7ae62f
[09:12:35]I (1193) cpu_start: Starting scheduler on PRO CPU.
[09:12:35]I (0) cpu_start: Starting scheduler on APP CPU.
[09:12:35][W][esp-idf:000]: I (92) gpio: GPIO[45]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[09:12:35]
[09:12:35][W][esp-idf:000]: I (1427) gpio: GPIO[6]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0
[09:12:35]
[09:12:35][W][esp-idf:000]: I (1429) gpio: GPIO[5]| InputEn: 1| OutputEn: 1| OpenDrain: 1| Pullup: 1| Pulldown: 0| Intr:0
[09:12:35]
[09:12:35][W][esp-idf:000]: I (1441) gpio: GPIO[10]|InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[09:12:35]
[09:12:35][W][esp-idf:000]: I (1443) gpio: GPIO[4]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0
[09:12:35]
[09:12:35][W][esp-idf:000]: I (1652) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0
[09:12:35]
[09:12:36][W][esp-idf:000]: I (1731) pp: pp rom version: e7ae62f
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1732) net80211: net80211 rom version: e7ae62f
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1734) wifi:
[09:12:36][W][esp-idf:000]: wifi driver task: 3fcb608c, prio:23, stack:6656, core=0
[09:12:36][W][esp-idf:000]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1735) system_api: Base MAC address is not set
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1736) system_api: read default base MAC address from EFUSE
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1744) wifi:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1745) wifi:
[09:12:36][W][esp-idf:000][wifi]: wifi certification version: v7.0
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1747) wifi:
[09:12:36][W][esp-idf:000][wifi]: config NVS flash: enabled
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1748) wifi:
[09:12:36][W][esp-idf:000][wifi]: config nano formating: disabled
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1749) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init data frame dynamic rx buffer num: 32
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1751) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init static rx mgmt buffer num: 5
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1752) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init management short buffer num: 32
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1753) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init dynamic tx buffer num: 32
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1755) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init tx cache buffer num: 32
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1756) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init static tx FG buffer num: 2
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1758) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init static rx buffer size: 1600
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1759) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init static rx buffer num: 16
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1761) wifi:
[09:12:36][W][esp-idf:000][wifi]: Init dynamic rx buffer num: 32
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1762) wifi_init: rx ba win: 16
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1763) wifi_init: tcpip mbox: 32
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1764) wifi_init: udp mbox: 6
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1764) wifi_init: tcp mbox: 6
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1765) wifi_init: tcp tx win: 5760
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1765) wifi_init: tcp rx win: 5760
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1766) wifi_init: tcp mss: 1440
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1766) wifi_init: WiFi/LWIP prefer SPIRAM
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1767) wifi_init: WiFi IRAM OP enabled
[09:12:36]
[09:12:36][W][esp-idf:000]: I (1767) wifi_init: WiFi RX IRAM OP enabled
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1770) phy_init: phy_version 670,b7bc9b9,Apr 30 2024,10:54:13
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1805) wifi:
[09:12:36][W][esp-idf:000][wifi]: mode : sta (d8:3b:da:40:74:b4)
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1807) wifi:
[09:12:36][W][esp-idf:000][wifi]: enable tsf
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1809) wifi:
[09:12:36][W][esp-idf:000][wifi]: Set ps type: 1
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]: I (1820) wifi:
[09:12:36][W][esp-idf:000][wifi]: Set ps type: 1
[09:12:36]
[09:12:36][W][esp-idf:000][wifi]:
[09:12:36]
[09:12:36][W][component:157]: Component wifi set Warning flag: scanning for networks
[09:12:36][W][esp-df:000]: I (1840) BLE_INIT: BT controller compile version [ba3b3e3]
[09:12:36]
[09:12:36][W][esp-idf:000][btController]: I (1842) BLE_INIT: Bluetooth MAC: d8:3b:da:40:74:b6
[09:12:36]
[09:12:36]
[09:12:38][W][esp-idf:000]: I (3839) gpio: GPIO[1]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2
[09:12:38]
[09:12:38]MSG READER TASK STARTED
[09:12:44][W][esp-idf:000][wifi]: I (10300) wifi:
[09:12:44][W][esp-idf:000][wifi]: new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
[09:12:44][W][esp-idf:000][wifi]:
[09:12:44]
[09:12:44][W][esp-idf:000][wifi]: I (10303) wifi:
[09:12:44][W][esp-idf:000][wifi]: state: init -> auth (b0)
[09:12:44][W][esp-idf:000][wifi]:
[09:12:44]
[09:12:45][W][esp-idf:000][wifi]: I (11120) wifi:
[09:12:45][W][esp-idf:000][wifi]: state: auth -> assoc (0)
[09:12:45][W][esp-idf:000][wifi]:
[09:12:45]
Terminal disconnected: NetworkError: The device has been lost.

@that1guy that1guy changed the title Infinite Boot Loop Spontaneous Power Cycles and Intermittent Boot Loops Feb 18, 2025
@alextrical
Copy link
Contributor

Thank you for the logs,

We are investigating this issue, and have been preforming multiple tests to track down the source of the issue causing the reboots.

From lowering the voltage to heating the unit up until it becomes unstable, we have managed to identify that there are a few different ways to achieve the crash logs similar to the ones philgrocks posted

Specifically, if the device is powered by a USB 5V supply (as would be coming from a mackbook i believe) the buck regulator and backfeed protection diode drop the voltage to a point where the voltage is close to the limit of what the ESP32 can handle for input.

We believe adding an increased capacitance on the 3.3V rail of the Core board can greatly improve system stability at the 5V or over 75C ranges

@philgrocks
Copy link

A suggestion:

Back in the day (80' and 90's) we used to do 4 corner testing... One axis was temperature and the other voltage.

Taking the device to the limits of the specs for the most picky component in a device.

Now in a residential environment I double temps are ever below 50 degrees F or more than 100... But if the device was used in an outdoor barn or something the ranges could exceed this.

We would also construct a test program that kept I/O, Memory, CPU all very busy looking for glitches (memory corruption in RAM, bad data reads from ROM, etc).

--
Lastly I see discussion as USB 5V supply, but I have used other USB power supplies that support ability to negotiate to 9V, but it doesn't seem that this happens. I have tried 2 different USB power monitors and neither shows a negotiation to 9V.

It is possible my cheap USB C meters are not very capable, but I never saw them getting in the way of 5V to 9V negotiation before.

@that1guy
Copy link
Collaborator

that1guy commented Mar 4, 2025

We have new hardware incoming from manufacturer and we continue running tests to squash this bug. More info incoming.

@alextrical
Copy link
Contributor

alextrical commented Mar 6, 2025

Migrating notes from internal ticket, for transparency.
We have been performing numerous tests to try and recreate the error outlined in this issue.

From testing it looks like the voltage fluctuations on the 3.3v rail cause instability in the ESP32, resulting in odd behaviour.

This is made worse by thermals inside the enclosure reaching 70+C causing the linear regulator to not be able to smooth out the current draw while transmitting on 2.4Ghz.


Reboot at 72C ESP32 internal temp, 74.35C on AHT20. Board was problem Rev4.1 board recieved from as a return from customer experiencing reboots. This behaviour was recreatable multiple times on this Core Board

\x1B[0;36m[D][sensor:094]: 'Heap Max Block': Sending state 88064.00000 B with 0 decimals of accuracy\x1B[0m
\x1B[0;36m[D][sensor:094]: 'Free PSRAM': Sending state 7272355.00000 B with 0 decimals of accuracy\x1B[0m
\x1B[0;36m[D][text_sensor:064]: 'Compat. w/ CORE hw': Sending state 'v1.0.0-beta.1'\x1B[0m
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x4038456c  PS      : 0x00060233  A0      : 0x80384f03  A1      : 0x3fccf870  
A2      : 0x3d800014  A3      : 0x000006a7  A4      : 0xfffffffc  A5      : 0x00000000  
A6      : 0x3fcac694  A7      : 0x3fcac648  A8      : 0x9326c327  A9      : 0x00000000  
A10     : 0x00000002  A11     : 0x000006a6  A12     : 0x3d898330  A13     : 0x00060223  
A14     : 0x00060220  A15     : 0x00000001  SAR     : 0x00000008  EXCCAUSE: 0x0000001c  
EXCVADDR: 0x9326c32b  LBEG    : 0x40056fc5  LEND    : 0x40056fe7  LCOUNT  : 0x00000000  


Backtrace: 0x40384569:0x3fccf870 0x40384f00:0x3fccf890 0x403790c5:0x3fccf8b0 0x403861a5:0x3fccf8d0 0x40386fe5:0x3fccf8f0 0x4003f3cb:0x3fccf910 0x420bbe21:0x3fccf930 0x42072693:0x3fccf950 0x42111859:0x3fccf970 0x420ec890:0x3fccf990 0x42078123:0x3fccf9b0 0x42074db2:0x3fccf9d0 0x42075fa4:0x3fccfa10 0x42076062:0x3fccfa70 0x4208a037:0x3fccfa90 0x421126f3:0x3fccfab0 0x4206d1f6:0x3fccfad0 0x42019875:0x3fccfb10 0x420198d9:0x3fccfb30 0x42019124:0x3fccfb50




ELF file SHA256: 8a9d520f7a748983

Rebooting...
\0\x80ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0xa (SPI_FAST_FLASH_BOOT)
Saved PC:0x4201a593
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3808,len:0x16c4
load:0x403c9700,len:0xbd4
load:0x403cc700,len:0x2fb0
entry 0x403c9954
\x1B[0;32mI (29) boot: ESP-IDF 4.4.8 2nd stage bootloader\x1B[0m
\x1B[0;32mI (29) boot: compile time 12:36:54\x1B[0m
\x1B[0;32mI (29) boot: Multicore bootloader\x1B[0m

Voltage trace taken at point of reboot, the voltage droped to 2.48V and resulted in a "Core Panic"
Image

@alextrical
Copy link
Contributor

alextrical commented Mar 6, 2025

Using the same setup as above, adding a 100uF Electrolytic capacitor to the 3.3v rail, pushed the temperature at which the Core board became unstable.


Reboot at 100C ESP32 internal temp, 94.41C on AHT20. Board was problem Rev4.1 board returned by a Customer, with addition of 100uF on the 3.3v rail

\x1B[0;36m[D][sensor:094]: 'Heap Max Block': Sending state 90112.00000 B with 0 decimals of accuracy\x1B[0m
\x1B[0;36m[D][sensor:094]: 'Free PSRAM': Sending state 7263635.00000 B with 0 decimals of accuracy\x1B[0m
Guru Meditation Error: Core  0 panic'ed (StoreProhibited). Exception was unhandled.

Core  0 register dump:
PC      : 0x403846af  PS      : 0x00060a33  A0      : 0x80384f03  A1      : 0x3fccf980  
A2      : 0x3d800014  A3      : 0x55555155  A4      : 0x00000005  A5      : 0x3fc9ad20  
A6      : 0x00060023  A7      : 0x00000001  A8      : 0x3d8984d8  A9      : 0x00000000  
A10     : 0x00000008  A11     : 0x00000018  A12     : 0x3d8984e0  A13     : 0x14554451  
A14     : 0x3d8b9228  A15     : 0x00000019  SAR     : 0x0000001b  EXCCAUSE: 0x0000001d  
EXCVADDR: 0x14554459  LBEG    : 0x40056fc5  LEND    : 0x40056fe7  LCOUNT  : 0x00000000  


Backtrace: 0x403846ac:0x3fccf980 0x40384f00:0x3fccf9a0 0x403790c5:0x3fccf9c0 0x403861a5:0x3fccf9e0 0x40386fe5:0x3fccfa00 0x4003f3cb:0x3fccfa20 0x420bbe21:0x3fccfa40 0x42072693:0x3fccfa60 0x42111859:0x3fccfa80 0x420ec890:0x3fccfaa0 0x42078123:0x3fccfac0 0x42074db2:0x3fccfae0 0x42075fa4:0x3fccfb20 0x42076062:0x3fccfb80 0x4208a037:0x3fccfba0 0x421126f3:0x3fccfbc0 0x4206d1f6:0x3fccfbe0 0x42019875:0x3fccfc20 0x420198d9:0x3fccfc40 0x42019124:0x3fccfc60




ELF file SHA256: 8a9d520f7a748983

Rebooting...
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0xc (RTC_SW_CPU_RST),boot:0x2b (SPI_FAST_FLASH_BOOT)
Saved PC:0x40377d98
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3808,len:0x16c4
load:0x403c9700,len:0xbd4
load:0x403cc700,len:0x2fb0
entry 0x403c9954
\x1B[0;32mI (29) boot: ESP-IDF 4.4.8 2nd stage bootloader\x1B[0m
\x1B[0;32mI (29) boot: compile time 12:36:54\x1B[0m
\x1B[0;32mI (29) boot: Multicore bootloader\x1B[0m

I believe i missed the exact point where the reset happened in the scope trace

Image

@alextrical
Copy link
Contributor

Second test. Aborted due to passing 110C
Reached 124C ESP32 internal temp, 98.4C on AHT20. Board was problem Rev4.1 board returned by a customer, with addition of 100uF on the 3.3v rail

Image

@alextrical
Copy link
Contributor

Other boards we tested performed better, but all exibited some form of issues with fluctuations on the 3.3v rail, If the voltage droped below 2.48V odd issues where likeley to occur.

We have fabricated a new Core board to test the solution, the results can be seen below.


Test aborted at 111.4C(232.52F) ESP32 internal temp, 101.3C(214.34F) on AHT20. Board is Rev6, with addition of 200uF on the 3.3v rail, change of 3.3v regulator to LM1117, and 100uF added to 5v Rail.

Image

@philgrocks
Copy link

FYI... I saw a note about the thermal testing and the the results were worse when the board was mounted in an enclosure.

My board is not in any enclosure and it is at room temperature. Around 72 degrees F.

@ben-gineering ben-gineering self-assigned this Mar 7, 2025
@ryanhindinger
Copy link

I have not been able to pull any logs--and it sounds like the culprit has been identified and this is just further confirmation--but my Sat1 went into an enclosure for the first time today and I pretty immediately saw this boot loop behavior with no change to software or use. So that would lend credence to the idea that this is a thermal issue.

@ben-gineering
Copy link

ben-gineering commented Mar 10, 2025

our best current theory of what is happening is that at one point the voltage to the SDRAM chip is low enough for it refuse data transmission. since the esp chip itself is less sensitive to low voltage than the SDRAM chip, it detects this and reboots. depending on what the esp has been doing it reports a different reset reason (can be read in home assistant) and/or error logs.

as for causes, as far as we can tell this sort of reboot can be forced by either running the whole system on under voltage, running it at high temperatures (above ~70C) or a combination of both. our guess is that the higher temperatures seem to increase noise on the power rails which in turn produces spikes low enough to cause the SDRAM chip to fail.

in the long term this will be fixed by reevaluating the power circuit. our current short term mitigation strategy is to run the system at 9V and add capacitors to the 3.3V and 5V rails of the core board to stabilize both the power for esp32 and the SDRAM chip. a similar setup is in testing with 7 devkits currently running for 5 days.

test6 all new sat1s 9v, all enclosures, leds 100%, media_player pink noise, added 3.3Vcore caps

  • OFF io d63e54
    • rev4hat rev3core
    • 5V 3A USBPD (xlayer)
  • leda 4e1a60
    • rev6hat rev4.2core rev1shoe
    • 9V USBC breakout labPSU
  • pandia 4cc904
    • rev6hat rev4.2core rev1shoe
    • poe injector via shoe
  • OFF europa 92a56c
    • rev4hat rev4core
    • 5V RPI USB
  • himalia 919bb4
    • rev6hat rev4.2core rev1shoe
    • mmwave_ld2410 connected, but firmware not enabled
    • 9V 3A anker nano 4
  • adrastea 4e1a78
    • rev6hat rev4.2core rev1shoe
    • 9V 3A anker nano 4
  • OFF ganymede 910f70
    • rev5hat rev4core
  • themisto 9197e4
    • rev6hat rev4.2core rev1shoe
    • 9V 3A anker nano 3
  • callisto 9197e8
    • rev6hat rev4.2core rev1shoe
    • mmwave_ld2450 connected, but firmware not enabled
    • 9V USBC breakout labPSU
  • kallichore 4cc914
    • rev6hat rev4.2core rev1shoe
    • 9V USBC breakout labPSU

Image
Image
Image
Image
Image

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
None yet
Development

No branches or pull requests

6 participants