[1] Opening COM3 at 115200 baud and resetting board... EN pulsed. Waiting for boot output... ets Jul 29 2019 12:21:46 rst:0x1 (POWERON_RESET),boot:0x13 (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:7176 load:0x40078000,len:16092 ho 0 tail 12 room 4 load:0x40080400,len:4 load:0x40080404,len:3912 entry 0x40080640 I (31) boot: ESP-IDF v5.3.1-dirty 2nd stage bootloader I (31) boot: compile time Mar 4 2026 13:08:05 I (31) boot: Multicore bootloader I (36) boot: chip revision: v3.1 I (40) boot.esp32: SPI Speed : 40MHz I (44) boot.esp32: SPI Mode : DIO I (49) boot.esp32: SPI Flash Size : 8MB I (53) boot: Enabling RNG early entropy source... I (59) boot: Partition Table: I (62) boot: ## Label Usage Type ST Offset Length I (70) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (77) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (84) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (92) boot: 3 ota_0 OTA app 00 10 00010000 00180000 I (99) boot: 4 ota_1 OTA app 00 11 00190000 00180000 I (107) boot: 5 storage Unknown data 01 40 00310000 00020000 I (114) boot: End of partition table I (119) esp_image: segment 0: paddr=00010020 vaddr=3f400020 size=409d0h (264656) map I (218) esp_image: segment 1: paddr=000509f8 vaddr=3ff80063 size=00008h ( 8) load I (218) esp_image: segment 2: paddr=00050a08 vaddr=3ffbdb60 size=0648ch ( 25740) load I (233) esp_image: segment 3: paddr=00056e9c vaddr=40080000 size=0917ch ( 37244) load I (248) esp_image: segment 4: paddr=00060020 vaddr=400d0020 size=ffbf0h (1047536) map I (607) esp_image: segment 5: paddr=0015fc18 vaddr=4008917c size=11f50h ( 73552) load I (636) esp_image: segment 6: paddr=00171b70 vaddr=400c0000 size=00064h ( 100) load I (637) esp_image: segment 7: paddr=00171bdc vaddr=50000000 size=0004ch ( 76) load I (656) boot: Loaded app from partition at offset 0x10000 I (656) boot: Disabling RNG early entropy source... I (668) cpu_start: Multicore app W (830) clk: 32 kHz XTAL not found, switching to internal 150 kHz oscillator I (838) cpu_start: Pro cpu start user code I (838) cpu_start: cpu freq: 160000000 Hz I (839) app_init: Application information: I (843) app_init: Project name: SC-F001 I (848) app_init: App version: e2451fc-dirty I (853) app_init: Compile time: Mar 5 2026 16:20:24 I (859) app_init: ELF file SHA256: 3aee52b89... I (865) app_init: ESP-IDF: v5.3.1-dirty I (870) efuse_init: Min chip rev: v0.0 I (875) efuse_init: Max chip rev: v3.99  I (880) efuse_init: Chip rev: v3.1 I (885) heap_init: Initializing. RAM available for dynamic allocation: I (892) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM I (898) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM I (904) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM I (910) heap_init: At 3FFCDD48 len 000122B8 (72 KiB): DRAM I (916) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM I (922) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM I (929) heap_init: At 4009B0CC len 00004F34 (19 KiB): IRAM I (937) spi_flash: detected chip: generic I (940) spi_flash: flash io: dio W (944) i2c: This driver is an old driver, please migrate your application code to adapt `driver/i2c_master.h` I (955) coexist: coex firmware version: 4482466 I (960) main_task: Started on CPU0 I (970) main_task: Calling app_main() W (970) RTC: Slow clock source is 0 — expected XTAL32K (1). Check sdkconfig. I (970) RTC: Wakeup: normal boot I (980) MAIN: Firmware: V_e2451fc-dirty (2026-03-05 22:20:22) I (980) MAIN: Version: e2451fc-dirty I (990) MAIN: Branch: main I (990) MAIN: Built: 2026-03-05 22:20:22 I (990) STORAGE: Initializing storage system... I (1000) STORAGE: Storage partition found: size=131072 bytes I (1010) STORAGE: Log init: scanning 28 sectors with bisection I (1030) STORAGE: Log system initialized (bisection). Head: 131072, Tail: 16384 I (1030) STORAGE: Log writer task started I (1030) STORAGE: Log wr ======================================== UART JSON Interface Ready ======================================== Type 'HELP' for available commands Type 'GET' to see system status > I (1050) UART: UART interface started I (1050) gpio: GPIO[25]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0  I (1060) RF: RF receiver task started on core 0 I (1070) BTDM_INIT: BT controller compile version [b022216] I (1070) BTDM_INIT: Bluetooth MAC: 94:54:c5:38:c4:3a I (1080) phy_init: phy_version 4830,54550f7,Jun 20 2024,14:22:08 E (1090) phy_init: esp_phy_load_cal_data_from_nvs: NVS has not been initialized. Call nvs_flash_init before starting WiFi/BT. W (1100) phy_init: failed to load RF calibration data (0x1101), falling back to full calibration W (1170) phy_init: saving new calibration data because of checksum failure, mode(2) E (1410) BT_OSI: config_new: NVS not initialized. Call nvs_flash_init before initializing bluetooth. W (1410) BT_BTC: btc_config_init unable to load config file; starting unconfigured.  E (1410) BT_OSI: config_save: NVS not initialized. Call nvs_flash_init before initializing bluetooth. E (1420) BT_OSI: config_save, err_code: 0x2  E (1480) BT_APPL: bta_gattc_co_cache_addr_init, Line = 436, nvs flash open fail, err_code = 1101 E (1500) BT_OSI: config_save: NVS not initialized. Call nvs_flash_init before initializing bluetooth. E (1500) BT_OSI: config_save, err_code: 0x2  E (1510) BT_OSI: config_save: NVS not initialized. Call nvs_flash_init before initializing bluetooth. E (1520) BT_OSI: config_save, err_code: 0x2  E (1520) BT_OSI: config_save: NVS not initialized. Call nvs_flash_init before initializing bluetooth. E (1530) BT_OSI: config_save, err_code: 0x2  E (1540) BT_OSI: config_save: NVS not initialized. Call nvs_flash_init before initializing bluetooth. E (1550) BT_OSI: config_save, err_code: 0x2  I (1560) BT_HID: Scanning for HID devices (3s)... I (1560) BT_HID: BLE HID host initialised I (1560) gpio: GPIO[14]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3  I (1570) WEBSERVER: Initializing webserver... I (1570) gpio: GPIO[27]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3  I (1590) WEBSERVER: AP LAUNCHING I (1610) WEBSERVER: AP LAUNCHING... I (1610) WEBSERVER: HI THERE I (1630) wifi:wifi driver task: 3ffe2808, prio:23, stack:6656, core=0 I (1640) wifi:wifi firmware version: ccaebfa I (1640) wifi:wifi certification version: v7.0 I (1640) wifi:config NVS flash: enabled I (1640) wifi:config nano formating: disabled I (1640) wifi:Init data frame dynamic rx buffer num: 32 I (1650) wifi:Init static rx mgmt buffer num: 5 I (1650) wifi:Init management short buffer num: 32 I (1650) wifi:Init dynamic tx buffer num: 32 I (1660) wifi:Init static rx buffer size: 1600 I (1660) wifi:Init static rx buffer num: 10 I (1670) wifi:Init dynamic rx buffer num: 32 I (1680) wifi_init: rx ba win: 6 I (1680) wifi_init: accept mbox: 6 I (1680) wifi_init: tcpip mbox: 32 I (1680) wifi_init: udp mbox: 6 I (1690) wifi_init: tcp mbox: 6 I (1690) wifi_init: tcp tx win: 5760 I (1690) wifi_init: tcp rx win: 5760 I (1700) wifi_init: tcp mss: 1440 I (1710) wifi:mode : softAP (94:54:c5:38:c4:39) I (1720) wifi:Total power save buffer number: 16 I (1720) wifi:Init max length of beacon: 752/752 I (1720) wifi:Init max length of beacon: 752/752 I (1730) esp_netif_lwip: DHCP server started on interface WIFI_AP_DEF with IP: 192.168.4.1 I (1730) DNS_SERVER: DNS server started on port 53 I (1740) mdns_mem: mDNS task will be created from internal RAM I (1740) WEBSERVER: SoftAP ready. SSID: sc.local, Channel: 6, Password: password I (1760) WEBSERVER: Access at: http://sc.local or http://sc.local.local or http://192.168.4.1 I (1760) WEBSERVER: AP LAUNCHED I (1760) WEBSERVER: STARTING HTTP I (1770) WEBSERVER: HTTP server started successfully I (1770) WEBSERVER: Registered URI handler: / I (1780) WEBSERVER: Registered URI handler: /get I (1780) WEBSERVER: Registered URI handler: /post I (1790) WEBSERVER: Registered URI handler: /log I (1790) WEBSERVER: Registered URI handler: /ota I (1800) WEBSERVER: Registered URI handler: /* I (1800) WEBSERVER: Webserver initialization complete E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated I (2110) wifi:new:<6,1>, old:<6,1>, ap:<6,1>, sta:<255,255>, prof:6, snd_ch_cfg:0x0 I (2110) wifi:station: 84:5c:f3:b4:49:ed join, AID=1, bgn, 40U E rmt: hw buffer too small, received symbols truncated I (2170) WEBSERVER: Station connected, AID=1 I (2210) esp_netif_lwip: DHCP server assigned IP to a client, IP is: 192.168.4.2 I (2670) wifi:idx:2 (ifx:1, 84:5c:f3:b4:49:ed), tid:0, ssn:23, winSize:64 E rmt: hw buffer too small, received symbols truncated > > W (3320) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI W (3420) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated I (4570) BT_HID: Found 0 HID device(s) I (4570) BT_HID: No HID devices found, retrying in 2000ms... E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated > > E rmt: hw buffer too small, received symbols truncated I (6570) BT_HID: Scanning for HID devices (3s)... E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated > > I (9580) BT_HID: Found 0 HID device(s) I (9580) BT_HID: No HID devices found, retrying in 2000ms... E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated W (11560) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI I (11580) BT_HID: Scanning for HID devices (3s)... W (11600) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated > > E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated I (14600) BT_HID: Found 0 HID device(s) I (14600) BT_HID: No HID devices found, retrying in 2000ms... E rmt: hw buffer too small, received symbols truncated > > E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated I (16600) BT_HID: Scanning for HID devices (3s)... E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated > > Boot complete. Multi-cycle mode: 30 cycles × 120s = ~60 min [INIT] Syncing device RTC to host time (1773161170)... POST: {"time": 1773161170} I (19210) COMMS: Setting time to 1773161170 I (19210) ALARM: SET FOR 1773161828 (in 658 s) I (19210) STORAGE: Wrote; Tail/Head are now 16384/131093 { "status": "ok", "params_updated": 0, "params_failed": 0, "cmd_executed": false } > > Accepted. [INIT] Baseline RTCDEBUG: RTCDEBUG === RTC DEBUG === reset_reason: POWER_ON (1) wakeup_cause: UNDEFINED (normal boot/reset) (0) slow_clk_src: NOT XTAL32K — check crystal! (0) rtc_set: true current_time: 1773161170 (2026-03-10 16:46:10 UTC) rtc_backup_s: 1773161170 (2026-03-10 16:46:10 UTC) rtc_sleep_entry_s: 0 (N/A UTC) next_alarm_s: 1773161828 (2026-03-10 16:57:08 UTC) uptime: 18s clock_offset: 1773161152s (current - uptime; stable = good) sleep_add: 0s (added to entry_s on this boot, 0 if no sleep) ================= > > I (19610) BT_HID: Found 0 HID device(s) I (19610) BT_HID: No HID devices found, retrying in 2000ms... W (19850) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI W (19900) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated I (21610) BT_HID: Scanning for HID devices (3s)... E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated Traceback (most recent call last): File "C:\data\stockcropper-sw\SC-F001\logtool\rtc_test.py", line 510, in main() ~~~~^^ File "C:\data\stockcropper-sw\SC-F001\logtool\rtc_test.py", line 504, in main ok = run_multi_cycle(ser, args.port, args.cycles, args.boot_timeout) File "C:\data\stockcropper-sw\SC-F001\logtool\rtc_test.py", line 288, in run_multi_cycle baseline_raw = send_cmd(ser, "RTCDEBUG", timeout=5.0) File "C:\data\stockcropper-sw\SC-F001\logtool\rtc_test.py", line 98, in send_cmd return _read_until_prompt(ser, timeout, nudge=False) File "C:\data\stockcropper-sw\SC-F001\logtool\rtc_test.py", line 84, in _read_until_prompt raise TimeoutError( f"Device prompt not seen within {timeout}s.\nOutput so far:\n{buf}" ) TimeoutError: Device prompt not seen within 5.0s. Output so far: RTCDEBUG === RTC DEBUG === reset_reason: POWER_ON (1) wakeup_cause: UNDEFINED (normal boot/reset) (0) slow_clk_src: NOT XTAL32K — check crystal! (0) rtc_set: true current_time: 1773161170 (2026-03-10 16:46:10 UTC) rtc_backup_s: 1773161170 (2026-03-10 16:46:10 UTC) rtc_sleep_entry_s: 0 (N/A UTC) next_alarm_s: 1773161828 (2026-03-10 16:57:08 UTC) uptime: 18s clock_offset: 1773161152s (current - uptime; stable = good) sleep_add: 0s (added to entry_s on this boot, 0 if no sleep) ================= > > I (19610) BT_HID: Found 0 HID device(s) I (19610) BT_HID: No HID devices found, retrying in 2000ms... W (19850) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI W (19900) httpd_txrx: httpd_resp_send_err: 404 Not Found - Nothing matches the given URI E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated I (21610) BT_HID: Scanning for HID devices (3s)... E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated E rmt: hw buffer too small, received symbols truncated