A stack overflow in task rmaker_queue_task has been detected. (MEGH-5360) - Githubissues

espressif / esp-rainmaker

ESP RainMaker Agent for firmware development

Apache License 2.0

431 stars 145 forks source link

A stack overflow in task rmaker_queue_task has been detected. (MEGH-5360) #305

Closed Tianbawen closed 3 months ago

Tianbawen commented 3 months ago

Answers checklist.

[X] I have read the Rainmaker documentation and the issue is not addressed there.
[X] I have updated my IDF branch (release/vX.Y) to the latest version and checked that the issue is present there. This is not applicable if you are using Rainmaker with Arduino.
[X] I have searched the Rainmaker forum and issue tracker for a similar issue and not found a similar issue.

IDF / ESP32-Arduino version.

idf v4.4.6

Operating System used.

Windows

How did you build your project?

Command line with idf.py

Development Kit.

ESP32s3n16r8

What is the expected behavior?

Smooth connection to rainmaker app

What is the actual behavior?

fc7a0e2c7fbecdc5c31b5c93b289d8df

Steps to reproduce.

Debug Logs.

[0;32mI (41318) esp_rmaker_user_mapping: Sending status SUCCESS[0m
D (41324) protocomm_ble: Response from  write:[0m
D (41328) protocomm_ble: 08 d0 a0 88 e6 56 54 76 65 6e a4 c1 a0 b2 3b 54 [0m
D (41335) protocomm_ble: 97 ec [0m
D (41415) protocomm_ble: Inside read w/ session - 0 on param 54 0[0m
D (41415) protocomm_ble: Reading attr value first time[0m
D (41495) protocomm_ble: Inside write with session - 0 on attr handle = 48 
len = 23, is_prep = 0[0m
D (41496) protocomm_ble: is_prep not set[0m
D (41498) WiFiProvConfig: In wifi_prov_config_command_dispatcher Cmd=2[0m
D (41504) WiFiProvConfig: Enter cmd_set_config_handler[0m
D (41509) wifi_prov_handlers: Wi-Fi Credentials Received[0m
D (41515) protocomm_ble: Response from  write:[0m
D (41519) protocomm_ble: c3 44 52 cb [0m
D (41575) protocomm_ble: Inside read w/ session - 0 on param 48 0[0m
D (41575) protocomm_ble: Reading attr value first time[0m
D (41655) protocomm_ble: Inside write with session - 0 on attr handle = 48 
len = 4, is_prep = 0[0m
D (41655) protocomm_ble: is_prep not set[0m
D (41657) WiFiProvConfig: In wifi_prov_config_command_dispatcher Cmd=4[0m
D (41664) WiFiProvConfig: Enter cmd_apply_config_handler[0m
D (41669) wifi_prov_mgr: Received Wi-Fi SSID     : tianber[0m
D (41675) wifi_prov_mgr: Received Wi-Fi Password : 1******8[0m
D (41680) nvs: nvs_get opmode 1[0m
D (41684) wifi:clear blacklist
D (41686) nvs: nvs_set_blob sta.ssid 36[0m
D (41692) nvs: nvs_set_blob sta.pswd 65[0m
D (41696) nvs: nvs_set bssid.set 1 0[0m
D (41698) nvs: nvs_set sta.lis_intval 2 3[0m
D (41702) nvs: nvs_set sta.chan 1 0[0m
D (41706) nvs: nvs_set sta.scan_method 1 0[0m
D (41710) nvs: nvs_set sta.sort_method 1 0[0m
D (41714) nvs: nvs_set sta.minrssi 1 -127[0m
D (41718) nvs: nvs_set sta.minauth 1 0[0m
D (41722) nvs: nvs_set_blob sta.apsw 2[0m
D (41727) nvs: nvs_set sta.pmf_e 1 1[0m
D (41729) nvs: nvs_set sta.pmf_r 1 0[0m
D (41733) nvs: nvs_set sta.rrm_e 1 0[0m
D (41737) nvs: nvs_set sta.btm_e 1 0[0m
D (41740) nvs: nvs_set sta.mbo_e 1 0[0m
D (41744) nvs: nvs_set sta.bss_retry 1 0[0m
D (41748) nvs: nvs_set sta.trans_d 1 0[0m
D (41752) nvs: nvs_set sta.sae_h2e 1 2[0m
D (41756) nvs: nvs_set_blob sta.apinfo 700[0m
D (41762) wifi_prov_mgr: execute_event_cb : 2[0m
D (41764) event: running post WIFI_PROV_EVENT:2 with handler 0x4200b120 and context 0x3fcec258 on loop 0x3fceb2e0[0m
[0;32mI (41774) app_wifi: Received Wi-Fi credentials
    SSID     : tianber
    Password : 12345678[0m
D (41783) wifi_prov_handlers: Wi-Fi Credentials Applied[0m
D (41789) protocomm_ble: Response from  write:[0m
D (41793) protocomm_ble: ad c0 5a d7 [0m
D (41855) protocomm_ble: Inside read w/ session - 0 on param 48 0[0m
D (41855) protocomm_ble: Reading attr value first time[0m
D (42763) wifi:Start wifi connect
D (42763) wifi:connect status 0 -> 0
D (42763) wifi:connect chan=0
D (42764) wifi:first chan=1
D (42764) wifi:connect status 0 -> 1
D (42767) wifi:filter: set rx policy=3
D (42770) wifi:clear scan ap list
D (42773) wifi:start scan: type=0x50f, priority=2, cb=0x42102950, arg=0x0, ss_state=0x1, time=42779097, index=0
D (42783) wifi:perform scan: ss_state=0x9, chan<1,0>, dur<0,120>
D (43029) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (43030) wifi:perform scan: ss_state=0x9, chan<2,0>, dur<0,120>
D (43271) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (43271) wifi:perform scan: ss_state=0x9, chan<3,0>, dur<0,120>
D (43512) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (43513) wifi:perform scan: ss_state=0x9, chan<4,0>, dur<0,120>
D (43754) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (43754) wifi:perform scan: ss_state=0x9, chan<5,0>, dur<0,120>
D (43936) protocomm_ble: Inside write with session - 0 on attr handle = 48 
len = 2, is_prep = 0[0m
D (43936) protocomm_ble: is_prep not set[0m
D (43938) WiFiProvConfig: In wifi_prov_config_command_dispatcher Cmd=0[0m
D (43944) WiFiProvConfig: Enter cmd_get_status_handler[0m
D (43950) wifi_prov_handlers: Got state : connecting[0m
D (43955) protocomm_ble: Response from  write:[0m
D (43959) protocomm_ble: a3 56 e6 2f ef f7 [0m
D (43995) wifi:scan end: arg=0x0, status=0, ss_state=0x3
D (43996) wifi:perform scan: ss_state=0x9, chan<6,0>, dur<0,120>
D (44000) wifi:rsn valid: gcipher=3 ucipher=3 akm=5

D (44001) wifi:profile match: ss_state=0x7
D (44004) wifi:scan end: arg=0x0, status=0, ss_state=0x7
D (44009) wifi:find first mathched ssid, scan done
D (44014) wifi:filter: set rx policy=4
D (44017) wifi:first chan=1
D (44019) wifi:handoff_cb: status=0
D (44023) wifi:ap found, mac=9a:90:71:7d:f1:ee
D (44027) wifi:new_bss=0x3fca3168, cur_bss=0x0, new_chan=<6,0>, cur_chan=1
D (44033) wifi:filter: set rx policy=5
I (44037) wifi:new:<6,0>, old:<1,0>, ap:<255,255>, sta:<6,0>, prof:1
D (44043) wifi:connect_op: status=0, auth=5, cipher=3 
D (45089) nvs: nvs_set_blob sta.apinfo 700[0m
D (45096) wifi:auth mode is not none
D (45097) wifi:connect_bss: auth=1, reconnect=0
I (45097) wifi:state: init -> auth (b0)
D (45098) wifi:start 1s AUTH timer
D (45100) wifi:clear scan ap list
D (45104) protocomm_ble: Inside read w/ session - 0 on param 48 0[0m
D (45106) wifi:recv auth: seq=2, status=0
I (45113) wifi:state: auth -> assoc (0)
D (45117) wifi:restart connect 1s timer for assoc
D (45121) protocomm_ble: Reading attr value first time[0m
D (45136) wifi:recv assoc: type=0x10
D (45137) wifi:filter: set rx policy=6
I (45137) wifi:state: assoc -> run (10)
D (45137) wifi:start 10s connect timer for 4 way handshake
I (45160) wifi:connected with tianber, aid = 2, channel 6, BW20, bssid = 9a:90:71:7d:f1:ee
I (45161) wifi:security: WPA2-PSK, phy: bgn, rssi: -20
D (45162) wifi:remove all except 9a:90:71:7d:f1:ee from rc list
D (45168) wifi:clear blacklist
D (45171) nvs: nvs_set sta.chan 1 6[0m
D (45175) nvs: nvs_set_blob sta.apinfo 700[0m
D (45184) wifi:filter: set rx policy=7
I (45184) wifi:pm start, type: 1

I (45185) wifi:set rx beacon pti, rx_bcn_pti: 14, bcn_timeout: 14, mt_pti: 25000, mt_time: 10000
D (45193) wifi:Send sta connected event
D (45197) wifi:connect status 1 -> 5
D (45200) wifi:obss scan is disabled
D (45203) wifi:start obss scan: obss scan is stopped
D (45208) event: running post WIFI_EVENT:4 with handler 0x4200b120 and context 0x3fcec28c on loop 0x3fceb2e0[0m
D (45218) event: running post WIFI_EVENT:4 with handler 0x420ae9c0 and context 0x3fcec5a4 on loop 0x3fceb2e0[0m
D (45228) esp_netif_handlers: esp_netif action connected with netif0x3fcec2f0 from event_id=4[0m
D (45237) esp_netif_lwip: check: remote, if=0x3fcec2f0 fn=0x420a8bac
[0m
D (45243) esp_netif_lwip: esp_netif_up_api esp_netif:0x3fcec2f0[0m
D (45249) esp_netif_lwip: check: local, if=0x3fcec2f0 fn=0x420a9430
[0m
D (45256) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3fcec2f0[0m
D (45263) esp_netif_lwip: call api in lwip: ret=0x0, give sem[0m
D (45268) esp_netif_lwip: check: remote, if=0x3fcec2f0 fn=0x420a8790
[0m
D (45275) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3fcec2f0[0m
D (45282) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3fcec2f0[0m
D (45289) esp_netif_lwip: if0x3fcec2f0 start ip lost tmr: no need start because netif=0x3fcec370 interval=120 ip=0[0m
D (45299) esp_netif_lwip: starting dhcp client[0m
D (45304) esp_netif_lwip: call api in lwip: ret=0x0, give sem[0m
D (45310) event: running post WIFI_EVENT:4 with handler 0x42016d40 and context 0x3fcbec6c on loop 0x3fceb2e0[0m
I (45340) wifi:AP's beacon interval = 102400 us, DTIM period = 2
D (45341) wifi:set max rate: from <rate=130, phy=3, sig=0> to <rate=144, phy=3 sig=0>
D (45343) wifi:sig_b=0, sig_g=0, sig_n=0, max_b=22, max_g=108, max_n=144
D (45349) wifi:update trc
I (45356) wifi:<ba-add>idx:0 (ifx:0, 9a:90:71:7d:f1:ee), tid:0, ssn:0, winSize:64
D (46305) esp_netif_lwip: esp_netif_dhcpc_cb lwip-netif:0x3fcec370[0m
D (46305) esp_netif_lwip: if0x3fcec2f0 ip changed=1[0m
D (46306) event: running post IP_EVENT:0 with handler 0x4200b120 and context 0x3fcec2d0 on loop 0x3fceb2e0[0m
[0;32mI (46315) app_wifi: Connected with IP Address:192.168.198.78[0m
D (46322) event: running post IP_EVENT:0 with handler 0x420ae7ec and context 0x3fcec654 on loop 0x3fceb2e0[0m
D (46331) wifi_init_default: Got IP wifi default handler entered[0m
D (46337) esp_netif_handlers: esp_netif action got_ip with netif0x3fcec2f0 from event_id=0[0m
[0;32mI (46346) esp_netif_handlers: sta ip: 192.168.198.78, mask: 255.255.255.0, gw: 192.168.198.167[0m
D (46355) event: running post IP_EVENT:0 with handler 0x42011830 and context 0x3fcb1974 on loop 0x3fceb2e0[0m
D (46365) event: running post IP_EVENT:0 with handler 0x42016d40 and context 0x3fcbec8c on loop 0x3fceb2e0[0m
[0;32mI (46374) wifi_prov_mgr: STA Got IP[0m
D (46378) wifi_prov_mgr: Starting 30 sec timer for stop_prov_timer_cb()[0m
D (46385) wifi_prov_mgr: execute_event_cb : 4[0m
D (46390) event: running post WIFI_PROV_EVENT:4 with handler 0x4200b120 and context 0x3fcec258 on loop 0x3fceb2e0[0m
[0;32mI (46400) app_wifi: Provisioning successful[0m
[0;32mI (46405) esp_claim: Starting the Self Claim Process. This may take time.[0m
D (46405) event: no handlers have been registered for event RMAKER_EVENT:2 posted to loop 0x3fceb2e0[0m
[0;32mI (46405) HTTP_CLIENT: http_test_task running[0m
D (46405) rmt: rmt_source_clk_hz: 80000000
[0m
D (46413) esp_claim: Payload for https://esp-claiming.rainmaker.espressif.com/claim/initiate: {"mac_addr":"744DBD796FE8","platform":"esp32s3"}[0m
D (46431) rmt: Rmt Tx Channel 0|Gpio 2|Sclk_Hz 80000000|Div 2|Carrier_Hz 38000|Duty 33[0m
D (46444D (46452) intr_alloc: Connected src 40 to int 4 (cpu 1)[0m
) HTTP_CLIENT: Begin connect to: https://esp-claiming.rainmaker.espressif.com:443[0m
D (46465) esp-tls: host:esp-claiming.rainmaker.espressif.com: strlen 36[0m
D (46458) rmt: RMT translator init done[0m
[0;32mI (46476) LED_STRIP: Created LED strip object with RMT backend[0m
[0;32mI (46482) LED_STRIP: Start blinking LED strip[0m
D (46564) esp-tls: [sock=54] Resolved IPv4 address: 13.224.189.126[0m
D (46565) esp-tls: [sock=54] Connecting to server. HOST: esp-claiming.rainmaker.espressif.com, Port: 443[0m
D (46779) esp-tls-mbedtls: Use certificate bundle[0m
D (46782) esp-tls: handshake in progress...[0m
D (47153) esp-x509-crt-bundle: 136 certificates in bundle[0m
[0;32mI (47175) esp-x509-crt-bundle: Certificate validated[0m
D (48525) HTTP_CLIENT: Write header[3]: POST /claim/initiate HTTP/1.1
User-Agent: ESP32 HTTP Client/1.0
Host: esp-claiming.rainmaker.espressif.com
Content-Length: 48

[0m
D (48534) esp_claim: Wrote 48 of 48 bytes.[0m
D (50176) protocomm_ble: Inside write with session - 0 on attr handle = 48 
len = 2, is_prep = 0[0m
D (50176) protocomm_ble: is_prep not set[0m
D (50178) WiFiProvConfig: In wifi_prov_config_command_dispatcher Cmd=0[0m
D (50184) WiFiProvConfig: Enter cmd_get_status_handler[0m
D (50190) wifi_prov_handlers: Got state : connected[0m
D (50195) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3fcec2f0[0m
D (50201) wifi_prov_mgr: Stopping provisioning[0m
D (50206) wifi_prov_mgr: Provisioning scheduled for stopping[0m
D (50212) protocomm_ble: Response from  write:[0m
D (50216) protocomm_ble: da 52 c9 13 63 a4 13 81 26 2f 3d ad c1 46 52 99 [0m
D (50223) protocomm_ble: 0b 1e 9a a6 fd 27 a4 b6 94 25 94 e8 ad aa 98 26 [0m
D (50230) protocomm_ble: 49 ab 46 2d 6b b8 9c bd 5a a7 a6 [0m
D (50295) protocomm_ble: Inside read w/ session - 0 on param 48 0[0m
D (50296) protocomm_ble: Reading attr value first time[0m
D (50772) HTTP_CLIENT: on_message_begin[0m
D (50773) HTTP_CLIENT: HEADER=Content-Type:application/json[0m
D (50773) HTTP_CLIENT: HEADER=Content-Length:129[0m
D (50776) HTTP_CLIENT: HEADER=Connection:keep-alive[0m
D (50780) HTTP_CLIENT: HEADER=Date:Thu, 07 Mar 2024 08:04:04 GMT[0m
D (50787) HTTP_CLIENT: HEADER=x-amzn-RequestId:999c6c86-9cd6-4951-a594-f24d8561ca59[0m
D (50794) HTTP_CLIENT: HEADER=Access-Control-Allow-Origin:*[0m
D (50800) HTTP_CLIENT: HEADER=x-amz-apigw-id:UP819HUyIAMELYg=[0m
D (50806) HTTP_CLIENT: HEADER=X-Amzn-Trace-Id:Root=1-65e974f2-19a11f391001619d48762e0a;Parent=1314c7d06009895b;Sampled=0;lineage=924dbb09:0[0m
D (50818) HTTP_CLIENT: HEADER=X-Cache:Miss from cloudfront[0m
D (50824) HTTP_CLIENT: HEADER=Via:1.1 d8eef512ab23f23f549b4cd25ac5328c.cloudfront.net (CloudFront)[0m
D (50833) HTTP_CLIENT: HEADER=X-Amz-Cf-Pop:FRA2-C1[0m
D (50838) HTTP_CLIENT: HEADER=X-Amz-Cf-Id:fFgmh6hrjiOHx2kkmu_jXSMn6-0nsqVn9-mtfS-yrkcdPxnUAtWBRA==[0m
D (50847) HTTP_CLIENT: http_on_headers_complete, status=200, offset=563, nread=563[0m
D (50854) HTTP_CLIENT: http_on_body 129[0m
[0;32mI (50858) HTTP_CLIENT: Body received in fetch header state, 0x3fcf3763, 129[0m
D (50866) HTTP_CLIENT: http_on_message_complete, parser=3fcf5970[0m
D (50872) HTTP_CLIENT: content_length = 129[0m
D (50876) HTTP_CLIENT: is_data_remain=0, is_chunked=0, content_length=129[0m
D (50883) HTTP_CLIENT: is_data_remain=0, is_chunked=0, content_length=129[0m
D (50892) esp_claim: Claim Init Response: {"auth_id":"414591b3-d564-4caf-b561-4cdabca04b47","challenge":"bHjsFkiZt4eZPohZtXn6oqqtdR7KBOuZBQ62Fk1aZ996G1U28oVVqvtkr5XYCM6u"}[0m

***ERROR*** A stack overflow in task rmaker_queue_ta has been detected.

More Information.

No response

vikramdattu commented 3 months ago

Hi @Tianbawen since you have already closed the issue, I hope you have figured it out. You have debug logs enabled and hence, the rmaker_task needs few KB extra stack. You may increase this via menuconfig: ESP_RMAKER_WORK_QUEUE_TASK_STACK

Please note that you need this only while debugging and with debug logs enabled, you do not need to spend these extra memory.