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.

Sign up for GitHub

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

Jump to bottom

ESP-netif crashing all the time (broken), when creating an instance in the esp-mesh "ip_internal_network " example (IDFGH-4208) #6067

Closed
ramidomalys opened this issue Nov 3, 2020 · 4 comments
Closed

ESP-netif crashing all the time (broken), when creating an instance in the esp-mesh "ip_internal_network " example (IDFGH-4208) #6067

ramidomalys opened this issue Nov 3, 2020 · 4 comments

Comments

@ramidomalys
Copy link

Environment

  • Development Kit: [ESP32-DevKitC]

  • Kit version (DevKitC): |v4]

  • Module or chip used: [ESP32-WROVER-E]

  • IDF version v4.2-beta1-227-gf0e87c933

  • Build System: [idf.py]

  • Compiler version ( xtensa-esp32-elf-gcc (crosstool-NG esp-2020r3) 8.4.0)

  • Operating System: [Windows]

  • (Windows only) environment type: [ESP Command Prompt|].

  • Using an IDE?: [No|]

  • Power Supply: [USB|external 5V]

Problem Description

by building and flashing the esp-mesh "ip_internal_network " example ,
right after running menuconfig, setting my router settings, i invoke build and flash, it crashes after connecting to parent node ( router,) exactly after obtaining ip adress and trying to create the Mesh netif at line
mesh_netif.c :248 :esp_netif_action_start(netif_ap, NULL, 0, NULL);

Expected Behavior

continueing esp_netif_action_start , without crashing ...

Actual Behavior

crashing at line

mesh_netif.c :248 :esp_netif_action_start(netif_ap, NULL, 0, NULL);

last log before Guru Meditation Error :

D (12657) esp_netif_lwip: esp_netif_start_api Setting the lwip netif0x3ffbac80 UP
Guru Meditation Error: Core  1 panic'ed (InstrFetchProhibited). Exception was unhandled.

if we activate the example option ( CONFIG_MESH_USE_GLOBAL_DNS_IP ) the crash occur before the ip obtaining event , otherwise, the crash occur after obtaining ip event , seems unrelated but anyhow.

Steps to reproduce

  1. step1 clean install esp-idf, release/v4.2 , or master branch (both same behavior)

  2. configure ip_internal_network example using menuconfig

  3. build and flash the example

Code to reproduce this issue

ip_internal_network example code provided by idf

Debug Logs

I (2977) mesh_main: <MESH_EVENT_MESH_STARTED>ID:77:77:77:77:77:76
I (2987) mesh_main: mesh starts successfully, heap:153396, root not fixed

D (6867) event: running post WIFI_EVENT:1 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

I (6867) mesh: [S3]SFR_3DD0_2GEXT, 10:da:43:c1:9f:b2, channel:3, rssi:-66
I (6877) mesh: find router:[ssid_len:14]SFR_3DD0_2GEXT, rssi:-66, 10:da:43:c1:9f:b2(encrypted), new channel:3, old channel:0
I (6887) mesh: [FIND][ch:0]AP:28, otherID:0, MAP:0, idle:0, candidate:0, root:0[10:da:43:c1:9f:b2]router found
I (6897) mesh: [FIND:1]find a network, channel:3, cfg<channel:0, router:SFR_3DD0_2GEXT, 00:00:00:00:00:00>

D (6907) event: running post MESH_EVENT:22 with handler 0x400d5000 and context 0x3ffd028c on loop 0x3ffc016c
0x400d5000: mesh_event_handler at c:\users\rami_domalys\desktop\ip_internal_network\build/../main/mesh_main.c:204

V (6907) esp_adapter: thread sem get: sem=0x3ffd03a0
I (6917) mesh_main: <MESH_EVENT_FIND_NETWORK>new channel:3, router BSSID:00:00:00:00:00:00
I (6917) wifi:mode : sta (24:0a:c4:02:02:e8) + softAP (24:0a:c4:02:02:e9)
D (6937) nvs: nvs_set opmode 1 3
D (6937) nvs: nvs_set ap.chan 1 1
D (6947) nvs: nvs_set ap.sndchan 1 1
W (6947) wifi:<MESH AP>adjust channel:1, secondary channel offset:1(40U)
I (6957) wifi:Total power save buffer number: 8
D (6957) event: running post WIFI_EVENT:12 with handler 0x400e2904 and context 0x3ffc15a4 on loop 0x3ffc016c
0x400e2904: wifi_default_action_ap_start at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_wifi/src/wifi_default.c:114

V (6957) esp_adapter: thread sem get: sem=0x3ffd03a0
D (6967) event: running post WIFI_EVENT:12 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

D (6977) nvs: nvs_set ap.authmode 1 3
D (6987) nvs: nvs_set ap.chan 1 3
D (6987) nvs: nvs_set ap.sndchan 1 1
D (6997) nvs: nvs_set_blob ap.ssid 36
D (6997) nvs: nvs_set_blob ap.passwd 65
D (6997) nvs: nvs_set ap.hidden 1 1
D (7007) nvs: nvs_set ap.max.conn 1 6
D (7007) nvs: nvs_set bcn.interval 2 100
D (7007) nvs: nvs_set ap.chan 1 3
D (7017) nvs: nvs_set ap.sndchan 1 1
W (7017) wifi:<MESH AP>adjust channel:3, secondary channel offset:1(40U)
I (7027) wifi:Total power save buffer number: 8
D (7027) event: running post WIFI_EVENT:13 with handler 0x400e27ec and context 0x3ffc15cc on loop 0x3ffc016c
0x400e27ec: wifi_default_action_ap_stop at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_wifi/src/wifi_default.c:121

V (7027) esp_adapter: thread sem get: sem=0x3ffd03a0
D (7037) event: running post WIFI_EVENT:13 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

D (7057) event: running post WIFI_EVENT:12 with handler 0x400e2904 and context 0x3ffc15a4 on loop 0x3ffc016c
0x400e2904: wifi_default_action_ap_start at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_wifi/src/wifi_default.c:114

D (7067) event: running post WIFI_EVENT:12 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

D (7347) event: running post WIFI_EVENT:1 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

V (7347) esp_adapter: thread sem get: sem=0x3ffd03a0
V (7347) esp_adapter: thread sem get: sem=0x3ffd03a0
I (7357) mesh: [SCAN][ch:3]AP:2, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:1,i:1][10:da:43:c1:9f:b2]router found<>
V (7367) esp_adapter: thread sem get: sem=0x3ffd03a0
I (7367) mesh: 1315[SCAN]init rc[24:0a:c4:02:02:e9,-64], mine:0, voter:0
I (7377) mesh: 1353, vote myself, router rssi:-64 > voted rc_rssi:-120
V (7387) esp_adapter: thread sem get: sem=0x3ffd03a0
V (7387) esp_adapter: thread sem get: sem=0x3ffd03a0
V (7397) esp_adapter: thread sem get: sem=0x3ffd03a0
I (7397) mesh: [SCAN:1/10]rc[128][24:0a:c4:02:02:e9,-64], self[24:0a:c4:02:02:e8,-64,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,24:0a:c4:02:02:e9]

/* SCAN LOG*/ 

V (10707) esp_adapter: thread sem get: sem=0x3ffd03a0
D (11017) event: running post WIFI_EVENT:1 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

V (11747) esp_adapter: thread sem get: sem=0x3ffd03a0
I (11747) mesh: [SCAN][ch:3]AP:2, other(ID:0, RD:0), MAP:0, idle:0, candidate:1, root:0, topMAP:0[c:0,i:1][10:da:43:c1:9f:b2]router found<>
V (11757) esp_adapter: thread sem get: sem=0x3ffd03a0
I (11767) mesh: 1315[SCAN]init rc[24:0a:c4:02:02:e9,-65], mine:0, voter:0
V (11777) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11777) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11787) esp_adapter: thread sem get: sem=0x3ffd03a0
I (11787) mesh: [SCAN:13/13+x+]rc[128][24:0a:c4:02:02:e9,-65], self[24:0a:c4:02:02:e8,-65,reason:0,votes:1,idle][mine:1,voter:1(1.00)percent:1.00][128,1,24:0a:c4:02:02:e9]

D (11807) nvs: nvs_set_blob LAYER 2
I (11807) mesh: <nvs>write layer:0
V (11807) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11817) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11817) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11827) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11827) esp_adapter: thread sem get: sem=0x3ffd03a0
I (11837) mesh: [DONE]connect to router:SFR_3DD0_2GEXT, channel:3, rssi:-65, 10:da:43:c1:9f:b2[layer:0, assoc:0], my_vote_num:1/voter_num:1, rc[24:0a:c4:02:02:e9/-65/1]
V (11847) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11857) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11857) esp_adapter: thread sem get: sem=0x3ffd03a0
V (11867) esp_adapter: thread sem get: sem=0x3ffd03a0
I (11987) wifi:new:<3,1>, old:<3,1>, ap:<3,1>, sta:<3,0>, prof:3
I (11987) wifi:state: init -> auth (b0)
I (12057) wifi:state: auth -> assoc (0)
I (12067) wifi:state: assoc -> run (10)
I (12307) wifi:connected with SFR_3DD0_2GEXT, aid = 3, channel 3, BW20, bssid = 10:da:43:c1:9f:b2
I (12307) wifi:security: WPA2-PSK, phy: bgn, rssi: -64
D (12317) nvs: nvs_set sta.chan 1 3
D (12317) nvs: nvs_set_blob sta.apinfo 700
I (12327) wifi:pm start, type: 0

D (12327) event: running post WIFI_EVENT:4 with handler 0x400e294c and context 0x3ffc1554 on loop 0x3ffc016c
0x400e294c: wifi_default_action_sta_connected at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_wifi/src/wifi_default.c:88

V (12337) esp_adapter: thread sem get: sem=0x3ffd00d0
D (12337) esp_netif_handlers: esp_netif action connected with netif0x3ffc129c from event_id=4
D (12347) esp_netif_lwip: check: remote, if=0x3ffc129c fn=0x400dbc9c
0x400dbc9c: esp_netif_up_api at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1131


D (12357) esp_netif_lwip: esp_netif_up_api esp_netif:0x3ffc129c
D (12357) esp_netif_lwip: check: local, if=0x3ffc129c fn=0x400dc3e0
0x400dc3e0: esp_netif_update_default_netif_lwip at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:163


D (12367) esp_netif_lwip: esp_netif_update_default_netif_lwip 0x3ffc129c
V (12377) esp_netif_objects: esp_netif_next_unsafe 0x0
V (12377) esp_netif_objects: esp_netif_next_unsafe 0x3ffc129c
V (12387) esp_netif_lwip: esp_netif_is_netif_up esp_netif:0x3ffc129c
I (12387) wifi:D (12387) esp_netif_lwip: call api in lwip: ret=0x0, give sem
AP's beacon interval = 102400 us, DTIM period = 2
D (12407) esp_netif_lwip: check: remote, if=0x3ffc129c fn=0x400db838
0x400db838: esp_netif_dhcpc_start_api at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:929


D (12407) esp_netif_lwip: esp_netif_dhcpc_start_api esp_netif:0x3ffc129c
D (12417) esp_netif_lwip: esp_netif_start_ip_lost_timer esp_netif:0x3ffc129c
D (12427) esp_netif_lwip: if0x3ffc129c start ip lost tmr: no need start because netif=0x3ffc1320 interval=120 ip=0
D (12437) esp_netif_lwip: starting dhcp client
D (12437) esp_netif_lwip: call api in lwip: ret=0x0, give sem
D (12447) event: running post WIFI_EVENT:4 with handler 0x40119fa0 and context 0x3ffcf7d4 on loop 0x3ffc016c
0x40119fa0: mesh_wifi_event_cb at ??:?

V (12457) esp_adapter: thread sem get: sem=0x3ffd03a0
I (12457) mesh: [scan]new scanning time:600ms, beacon interval:300ms
V (12467) esp_adapter: thread sem get: sem=0x3ffd03a0
D (12477) nvs: nvs_set bcn.interval 2 300
V (12477) esp_adapter: thread sem get: sem=0x3ffd03a0
V (12477) esp_adapter: thread sem get: sem=0x3ffd03a0
V (12487) esp_adapter: thread sem get: sem=0x3ffd03a0
D (12487) nvs: nvs_set_blob LAYER 2
I (12497) mesh: <nvs>write layer:1
I (12497) mesh: <flush>upstream packets, connections(max):6, waiting:0, upQ:0
D (12497) event: running post MESH_EVENT:7 with handler 0x400d5000 and context 0x3ffd028c on loop 0x3ffc016c
0x400d5000: mesh_event_handler at c:\users\rami_domalys\desktop\ip_internal_network\build/../main/mesh_main.c:204

I (12507) mesh: <flush>root
I (12517) mesh_main: <MESH_EVENT_PARENT_CONNECTED>layer:0-->1, parent:10:da:43:c1:9f:b2<ROOT>, ID:77:77:77:77:77:76
I (12517) mesh: [TXQ]<max:32>up(0, be:0), down(0, be:0), mgmt:0, xon(req:0, rsp:0), bcast:0, wnd(0, parent:00:00:00:00:00:00)
I (12527) mesh_netif: Already wifi station, no need to do anything
I (12537) mesh: [RXQ]<max:32 = cfg:32 + extra:0>self:0, <max:32 = cfg:32 + extra:0>tods:0
I (12547) mesh_netif: mesh_netif_start_root_ap
V (12557) esp_netif_objects: esp_netif_next_unsafe 0x0
V (12567) esp_netif_objects: esp_netif_next_unsafe 0x3ffc129c
D (12567) esp_netif_objects: esp_netif_add_to_list 0x3ffbaa04
D (12577) esp_netif_objects: esp_netif_add_to_list netif added successfully (total netifs: 2)
I (12587) mesh_netif: Receiving task started
D (12587) esp_netif_lwip: check: remote, if=0x3ffbaa04 fn=0x400db968
0x400db968: esp_netif_set_dns_info_api at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:1327


D (12597) esp_netif_lwip: esp_netif_set_dns_info_api esp_netif:0x3ffbaa04
D (12597) esp_netif_lwip: set dns if=0x3ffbaa04 type=0 dns=8080808
D (12607) esp_netif_lwip: call api in lwip: ret=0x0, give sem
W (12617) mesh_netif: start_mesh_link_ap
W (12617) mesh_netif: esp_wifi_get_mac
W (12627) mesh_netif: esp_netif_set_mac
W (12627) mesh_netif: esp_netif_action_start
D (12637) esp_netif_handlers: esp_netif action has started with netif0x3ffbaa04 from event_id=0
D (12637) esp_netif_lwip: check: remote, if=0x3ffbaa04 fn=0x400dbaac
0x400dbaac: esp_netif_start_api at C:/Users/Rami_Domalys/Desktop/esp-idf/components/esp_netif/lwip/esp_netif_lwip.c:608


D (12647) esp_netif_lwip: esp_netif_start_api 0x3ffbaa04
D (12657) esp_netif_lwip: esp_netif_get_hostname esp_netif:0x3ffbaa04
D (12657) esp_netif_lwip: esp_netif_start_api Setting the lwip netif0x3ffbac80 UP
Guru Meditation Error: Core  1 panic'ed (InstrFetchProhibited). Exception was unhandled.

Core  1 register dump:
PC      : 0x00000000  PS      : 0x00060a30  A0      : 0x800f7106  A1      : 0x3ffbfd00
A2      : 0x3ffbaa04  A3      : 0x3ffbbb76  A4      : 0x0000002a  A5      : 0x3ffbbb5c
A6      : 0x3ffbf0ec  A7      : 0x00000000  A8      : 0x801776b0  A9      : 0x0000002a
A10     : 0x3ffbadd0  A11     : 0x3ffbbb76  A12     : 0x0000002a  A13     : 0x3ffbbb5c
A14     : 0x3f407c34  A15     : 0x3f408a34  SAR     : 0x00000010  EXCCAUSE: 0x00000014
EXCVADDR: 0x00000000  LBEG    : 0x4000c2e0  LEND    : 0x4000c2f6  LCOUNT  : 0xffffffff

Backtrace:0xfffffffd:0x3ffbfd00 |<-CORRUPTED


ELF file SHA256: 0469695f3ab1c02d

Rebooting...
ets Jun  8 2016 00:22:57

Additional info

  • [x ] sdkconfig file

sdkconfig.zip

  • [full log ]

full log.txt
@github-actions github-actions bot changed the title ESP-netif crashing all the time (broken), when creating an instance in the esp-mesh "ip_internal_network " example ESP-netif crashing all the time (broken), when creating an instance in the esp-mesh "ip_internal_network " example (IDFGH-4208) Nov 3, 2020
@Alvin1Zhang
Copy link
Collaborator

Thanks for reporting.

@david-cermak
Copy link
Collaborator

Hi @ramidomalys

Could you please check if after applying the patch below the issue persists? We've introduced a Tx optimization in WiFi/esp-netif layer recently, transmiting buffers by reference, but some examples haven't been updated, I'm afraid.
0001-examples-esp_mesh-Fix-internal-ip-mesh-example-to-us.patch.txt

@ramidomalys
Copy link
Author

Hello, thank you so much for this fast reply , indeed the patch corrected the bug i can confirm it run smoothly.
would this patch be pushed to the release/v4.2 branch ?
thank you.

@david-cermak
Copy link
Collaborator

would this patch be pushed to the release/v4.2 branch ?

Yes, we have to merge it to master first and then backport to the release/v4.2. Please keep this open, the issue will close automatically when fixed on master.

espressif-bot pushed a commit that referenced this issue Mar 20, 2021
@david-cermak
examples, esp_mesh: Fix internal ip mesh example to use transmit wrap…
66c89f1 
… function

Fixed regression caused by recent refactoring of WiFi Tx. If  wasn't defined all transmits end up in a crash.

Closes #6067
@dshil dshil mentioned this issue Mar 29, 2021
Closed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@david-cermak @Alvin1Zhang @ramidomalys