Rainmaker instability - repeated uninvited reset

avnergid
Posts: 6
Joined: Fri Mar 27, 2020 7:36 pm

Rainmaker instability - repeated uninvited reset

Postby avnergid » Tue May 28, 2024 1:02 pm

Went back to the basic vanilla Switch example. Way to reproduce:
1. Enrol the switch.
2. On and Off from the app works fine. form the button, not always stable.
3. Wait 5 minutes.
4. Hit the button for a short time.
5. The device immediately resets itself.
Note in the logs the wait gap between time 129930 to 424580.

I ruled out any "mechanical" problem with the button being pulled up. a simple sketch of digitalWrite(32,digitalRead(34));
works perfectly well my setup.

This is repeating itself almost every time.



I (117050) app_main: MQTT Published. Msg id: 53825.
I (117090) esp_rmaker_node_config: Generated Node config of length 1466
I (117190) app_main: MQTT Published. Msg id: 53470.
I (117230) app_main: MQTT Published. Msg id: 33547.
I (126940) app_reset: Release button to trigger factory reset.
I (127120) esp_rmaker_node_config: Generated Node config of length 1466
W (129930) httpd_txrx: httpd_sock_err: error in recv : 104
I (292420) esp_rmaker_time: SNTP Synchronised.
I (292420) esp_rmaker_time: The current time is: Tue May 28 15:54:47 2024 +0300[IDT], DST: Yes.
I (424570) app_main: Node reset to factory defaults.
I (424580) esp_rmaker_user_mapping: User Node mapping reset detected.
I (424580) esp_rmaker_user_mapping: MQTT Publish: {"node_id":"CeUTsx5925JpFvLJPxKjMm","user_id":"esp-rmaker","secret_key":"failed","reset":true}
I (424850) app_main: MQTT Published. Msg id: 42029.
I (424850) esp_rmaker_user_mapping: User Node association message published successfully.
W (424860) app_main: Unhandled RainMaker Event: 7
I (426810) app_main: Rebooting in 2 seconds.
I (428790) app_reset: Release button now for Wi-Fi reset. Keep pressed for factory reset.
I (428810) wifi:state: run -> init (0)
I (428810) wifi:pm stop, total sleep time: 326718183 us / 370442854 us

I (428810) wifi:<ba-del>idx:1, tid:0
I (428810) wifi:<ba-del>idx:0, tid:6
I (428810) wifi:new:<6,0>, old:<6,0>, ap:<255,255>, sta:<6,0>, prof:1
E (428820) wifi:NAN WiFi stop
I (428820) app_wifi: Disconnected. Connecting to the AP again...
E (428830) transport_base: poll_read select error 113, errno = Software caused connection abort, fd = 54
E (428840) mqtt_client: Poll read error: 119, aborting connection
W (428850) esp_mqtt_glue: MQTT Disconnected. Will try reconnecting in a while...
I (428850) app_main: MQTT Disconnected.
I (428860) wifi:flush txq
I (428860) wifi:stop sw txq
I (428860) wifi:lmac stop hw txq
ets Jun 8 2016 00:22:57

rst:0xc (SW_CPU_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:7172
load:0x40078000,len:15628
load:0x40080400,len:4
0x40080400: _init at ??:?

load:0x40080404,len:3904
entry 0x40080640
I (29) boot: ESP-IDF v5.2.1-dirty 2nd stage bootloader
I (29) boot: compile time May 27 2024 20:11:37
I (29) boot: Multicore bootloader
I (34) boot: chip revision: v1.0
I (38) boot.esp32: SPI Speed : 40MHz
I (42) boot.esp32: SPI Mode : DIO
I (47) boot.esp32: SPI Flash Size : 4MB
I (51) boot: Enabling RNG early entropy source...
I (57) boot: Partition Table:
I (60) boot: ## Label Usage Type ST Offset Length
I (68) boot: 0 esp_secure_cert unknown 3f 06 0000d000 00002000
I (75) boot: 1 nvs_key NVS keys 01 04 0000f000 00001000
I (83) boot: 2 nvs WiFi data 01 02 00010000 00006000
I (90) boot: 3 otadata OTA data 01 00 00016000 00002000
I (98) boot: 4 phy_init RF data 01 01 00018000 00001000
I (105) boot: 5 ota_0 OTA app 00 10 00020000 00190000
I (113) boot: 6 ota_1 OTA app 00 11 001b0000 00190000
I (120) boot: 7 fctry WiFi data 01 02 00340000 00006000
I (128) boot: End of partition table
I (132) esp_image: segment 0: paddr=00020020 vaddr=3f400020 size=4e714h (321300) map
I (251) esp_image: segment 1: paddr=0006e73c vaddr=3ffbdb60 size=018dch ( 6364) load
I (253) esp_image: segment 2: paddr=00070020 vaddr=400d0020 size=108434h (1082420) map
I (627) esp_image: segment 3: paddr=0017845c vaddr=3ffbf43c size=0428ch ( 17036) load
I (634) esp_image: segment 4: paddr=0017c6f0 vaddr=40080000 size=1e418h (123928) load
I (698) boot: Loaded app from partition at offset 0x20000
I (698) boot: Disabling RNG early entropy source...
I (710) cpu_start: Multicore app
I (718) cpu_start: Pro cpu start user code
I (718) cpu_start: cpu freq: 160000000 Hz
I (719) cpu_start: Application information:
I (722) cpu_start: Project name: switch
I (726) cpu_start: App version: 1.0
I (731) cpu_start: Compile time: May 28 2024 15:49:01
I (737) cpu_start: ELF file SHA256: d616600c9...
I (742) cpu_start: ESP-IDF: v5.2.1-dirty
I (748) cpu_start: Min chip rev: v0.0
I (753) cpu_start: Max chip rev: v3.99
I (757) cpu_start: Chip rev: v1.0
I (762) heap_init: Initializing. RAM available for dynamic allocation:
I (769) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM
I (775) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM
I (781) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM
I (788) heap_init: At 3FFCB148 len 00014EB8 (83 KiB): DRAM
I (794) heap_init: At 3FFE0440 len 00003AE0 (14 KiB): D/IRAM
I (800) heap_init: At 3FFE4350 len 0001BCB0 (111 KiB): D/IRAM
I (807) heap_init: At 4009E418 len 00001BE8 (6 KiB): IRAM
I (815) spi_flash: detected chip: generic
I (817) spi_flash: flash io: dio
I (823) coexist: coex firmware version: 77cd7f8
I (828) main_task: Started on CPU0
I (838) main_task: Calling app_main()
I (838) esp_rmaker_console: Initialising UART on port 0
I (838) uart: queue free spaces: 8
I (838) esp_rmaker_commands: Registering command: reboot
I (848) esp_rmaker_commands: Registering command: up-time
I (848) esp_rmaker_commands: Registering command: mem-dump
I (858) esp_rmaker_commands: Registering command: task-dump
I (868) esp_rmaker_commands: Registering command: cpu-dump
I (868) esp_rmaker_commands: Registering command: sock-dump
I (878) esp_rmaker_commands: Registering command: heap-trace
I (888) esp_rmaker_commands: Registering command: reset-to-factory
I (888) esp_rmaker_commands: Registering command: local-time
I (898) esp_rmaker_commands: Registering command: tz-set
I (898) esp_rmaker_commands: Registering command: add-user
I (908) esp_rmaker_commands: Registering command: get-node-id
I (918) esp_rmaker_commands: Registering command: wifi-prov
I (918) esp_rmaker_commands: Registering command: cmd
I (928) gpio: GPIO[34]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:3
I (938) gpio: GPIO[32]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 1| Intr:0
W (948) ws2812_led: WS2812 LED is disabled
I (988) wifi:wifi driver task: 3ffd1df8, prio:23, stack:6656, core=0
I (988) wifi:wifi firmware version: a9f5b59
I (988) wifi:wifi certification version: v7.0
I (988) wifi:config NVS flash: enabled
I (988) wifi:config nano formating: disabled
I (998) wifi:Init data frame dynamic rx buffer num: 32
I (998) wifi:Init static rx mgmt buffer num: 5
I (1008) wifi:Init management short buffer num: 32
I (1008) wifi:Init dynamic tx buffer num: 32
I (1008) wifi:Init static rx buffer size: 1600
I (1018) wifi:Init static rx buffer num: 10
I (1018) wifi:Init dynamic rx buffer num: 32
I (1028) wifi_init: rx ba win: 6
I (1028) wifi_init: tcpip mbox: 32
I (1028) wifi_init: udp mbox: 6
I (1038) wifi_init: tcp mbox: 6
I (1038) wifi_init: tcp tx win: 5760
I (1048) wifi_init: tcp rx win: 5760
I (1048) wifi_init: tcp mss: 1440
I (1048) wifi_init: WiFi IRAM OP enabled
I (1058) wifi_init: WiFi RX IRAM OP enabled
I (1078) esp_rmaker_work_queue: Work Queue created.
I (1098) esp_mqtt_glue: AWS PPI: ?Platform=APN3|A0|RM|EX00|RMDev|1x0|7821847D5DB8
I (1098) esp_mqtt_glue: Initialising MQTT
I (1098) esp_rmaker_mqtt_budget: MQTT Budgeting initialised. Default: 100, Max: 1024, Revive count: 1, Revive period: 5
I (1118) app_main: RainMaker Initialised.
I (1118) esp_rmaker_node: Node ID ----- CeUTsx5925JpFvLJPxKjMm
I (1128) esp_rmaker_ota_using_topics: OTA enabled with Topics
I (1138) esp_rmaker_ota: OTA state = 2
I (1138) esp_rmaker_time: Initializing SNTP. Using the SNTP server: pool.ntp.org
I (1148) esp_rmaker_time_service: Time service enabled
I (1148) esp_rmaker_time: SNTP already initialized.
I (1158) app_insights: Enable CONFIG_ESP_INSIGHTS_ENABLED to get Insights.
I (1158) esp_rmaker_core: Starting RainMaker Work Queue task
I (1168) esp_rmaker_work_queue: RainMaker Work Queue task started.
I (1178) tag: 0x3ffdb830 e5 02 4e 6f 76 61 00 01 00 80 01 00 |..Nova......|
I (1188) wifi_prov_scheme_ble: BT memory released
I (1188) app_wifi: Starting provisioning
I (1208) phy_init: phy_version 4791,2c4672b,Dec 20 2023,16:06:06
W (1208) phy_init: failed to load RF calibration data (0x1102), falling back to full calibration
I (1298) wifi:mode : sta (78:21:84:7d:5d:b8)
I (1298) wifi:enable tsf
I (1308) BTDM_INIT: BT controller compile version [0f0c5a2]
I (1308) BTDM_INIT: Bluetooth MAC: 78:21:84:7d:5d:ba
I (1558) protocomm_nimble: BLE Host Task Started
I (1568) wifi_prov_mgr: Provisioning started with service name : PROV_36fb86
I (1578) app_wifi: Provisioning started
I (1578) esp_rmaker_local: Event 1
I (1578) app_wifi: Scan this QR code from the ESP RainMaker phone app for Provisioning.

ESP_Piyush
Posts: 268
Joined: Wed Feb 20, 2019 7:02 am

Re: Rainmaker instability - repeated uninvited reset

Postby ESP_Piyush » Tue May 28, 2024 2:03 pm

Can you provide information about the board being used here? I see this event in between

Code: Select all

I (126940) app_reset: Release button to trigger factory reset.
which means that there is some false button press event detected and then a button release event got triggered much later here

Code: Select all

I (424570) app_main: Node reset to factory defaults.
RainMaker internally uses the iot button component, which itself uses GPIO interrupts. Can you once check if this button example works fine for you and does not generate any false events?

Who is online

Users browsing this forum: No registered users and 12 guests