espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.5k stars 7.26k forks source link

小米SDK编译通过,运行异常 (IDFGH-4972) #6764

Closed YzY19930301 closed 3 years ago

YzY19930301 commented 3 years ago

小米SDK版本:2.1.8

ESP-idf相关信息: Branch: customer/maintain_v4.0_xiaomi_tsf_issue

Commit: 60b0e9749f5d7aa0521a9def16d95ca404b7a956

根据小米提供的SDK编译步骤成功编译,运行过程中,在连接网络发生设备重启,详细日志如下:

| | ||| ||| ||
|| || | | | | | | | | | | | | | | | | | | | ||| ||| |_|
JENKINS BUILD NUMBER: N/A BUILD TIME: Mar 22 2021,19:04:40 BUILT BY: N/A MIIO APP VER: 2.1.8_0001 MIIO MCU VER: MIIO DID: 306332625 MIIO NEW DID: 70000614335 MIIO WIFI MAC: 5ce50c27cad5 MIIO MODEL: hsgczx.toilet.ctv1 ARCH TYPE: esp32,0x0000a601 ARCH VER: v4.0.1-467-g6256124df FLASH INFO: manufacturer(0x68), memory type(0x40), capacity(0x16) 08:00:01.080 [I] miio_net: Wifi event[1] 08:00:01.080 [I] miio_net: Wifi scan done 08:00:01.080 [D] miio_net: insert ssid=wifi_2.4G&5G_test, bssid=9C:9D:7E:EA:D4:EE, pri=1, rssi=-20, authmode=4 08:00:01.090 [D] miio_net: wifi scanning channel 1 for 120ms... 08:00:01.090 [I] miio_monitor: work time = 1s, memory left = 88608 08:00:01.100 [D] miio_net: sta will close in 899s 08:00:01.100 [W] mible_gap: The system has stopped scaning (mible_gap_scan,240) 08:00:01.210 [I] miio_net: Wifi event[1] 08:00:01.210 [I] miio_net: Wifi scan done 08:00:01.210 [D] miio_net: wifi scanning channel 1 for 120ms... 08:00:01.450 [I] miio_net: Wifi event[1] 08:00:01.450 [I] miio_net: Wifi scan done 08:00:01.460 [D] miio_net: wifi scanning channel 1 for 120ms... 08:00:01.700 [I] miio_net: Wifi event[1] 08:00:01.700 [I] miio_net: Wifi scan done 08:00:01.700 [D] miio_net: wifi scanning channel 1 for 120ms... 08:00:01.940 [I] miio_net: Wifi event[1] 08:00:01.940 [I] miio_net: Wifi scan done 08:00:01.940 [D] miio_net: wifi scanning channel 6 for 120ms... 08:00:02.180 [I] miio_net: Wifi event[1] 08:00:02.180 [I] miio_net: Wifi scan done 08:00:02.190 [D] miio_net: wifi scanning channel 6 for 120ms... 08:00:02.190 [I] miio_monitor: work time = 2s, memory left = 88568 08:00:02.200 [D] miio_net: sta will close in 898s 08:00:02.430 [I] miio_net: Wifi event[1] 08:00:02.430 [I] miio_net: Wifi scan done 08:00:02.430 [D] miio_net: wifi scanning channel 6 for 120ms... 08:00:02.670 [I] miio_net: Wifi event[1] 08:00:02.670 [I] miio_net: Wifi scan done 08:00:02.680 [D] miio_net: wifi scanning channel 6 for 120ms... 08:00:02.920 [I] miio_net: Wifi event[1] 08:00:02.920 [I] miio_net: Wifi scan done 08:00:02.920 [D] miio_net: wifi scanning channel 6 for 120ms... 08:00:03.160 [I] miio_net: Wifi event[1] 08:00:03.160 [I] miio_net: Wifi scan done 08:00:03.160 [D] miio_net: wifi scanning channel 11 for 120ms... 08:00:03.410 [I] miio_net: Wifi event[1] 08:00:03.410 [I] miio_net: Wifi scan done 08:00:03.410 [D] miio_net: wifi scanning channel 11 for 120ms... 08:00:03.410 [D] miio_net: sta will close in 897s 08:00:03.650 [I] miio_net: Wifi event[1] 08:00:03.650 [I] miio_net: Wifi scan done 08:00:03.650 [D] miio_net: wifi scanning channel 11 for 120ms... 08:00:03.890 [I] miio_net: Wifi event[1] 08:00:03.900 [I] miio_net: Wifi scan done 08:00:03.900 [D] miio_net: wifi scanning channel 11 for 120ms... 08:00:04.140 [I] miio_net: Wifi event[1] 08:00:04.140 [I] miio_net: Wifi scan done 08:00:04.140 [D] miio_net: wifi scanning channel 11 for 120ms... 08:00:04.380 [I] miio_net: Wifi event[1] 08:00:04.380 [I] miio_net: Wifi scan done 08:00:04.390 [D] miio_net: wifi scanning channel 2 for 120ms... 08:00:04.630 [I] miio_net: Wifi event[1] 08:00:04.630 [I] miio_net: Wifi scan done 08:00:04.630 [D] miio_net: wifi scanning channel 3 for 120ms... 08:00:04.630 [I] miio_monitor: work time = 4s, memory left = 88564 08:00:04.640 [D] miio_net: sta will close in 896s 08:00:04.870 [I] miio_net: Wifi event[1] 08:00:04.870 [I] miio_net: Wifi scan done 08:00:04.870 [D] miio_net: wifi scanning channel 4 for 120ms... 08:00:05.120 [I] miio_net: Wifi event[1] 08:00:05.120 [I] miio_net: Wifi scan done 08:00:05.120 [D] miio_net: wifi scanning channel 5 for 120ms... 08:00:05.360 [I] miio_net: Wifi event[1] 08:00:05.360 [I] miio_net: Wifi scan done 08:00:05.360 [D] miio_net: wifi scanning channel 7 for 120ms... 08:00:05.600 [I] miio_net: Wifi event[1] 08:00:05.610 [I] miio_net: Wifi scan done 08:00:05.610 [D] miio_net: wifi scanning channel 8 for 120ms... 08:00:05.850 [I] miio_net: Wifi event[1] 08:00:05.850 [I] miio_net: Wifi scan done 08:00:05.850 [D] miio_net: wifi scanning channel 9 for 120ms... 08:00:05.850 [I] miio_monitor: work time = 5s, memory left = 88568 08:00:05.860 [D] miio_net: sta will close in 895s 08:00:06.090 [I] miio_net: Wifi event[1] 08:00:06.090 [I] miio_net: Wifi scan done 08:00:06.100 [D] miio_net: wifi scanning channel 10 for 120ms... 08:00:06.340 [I] miio_net: Wifi event[1] 08:00:06.340 [I] miio_net: Wifi scan done 08:00:06.340 [D] miio_net: wifi scanning channel 12 for 120ms... 08:00:06.580 [I] miio_net: Wifi event[1] 08:00:06.580 [I] miio_net: Wifi scan done 08:00:06.590 [D] miio_net: wifi scanning channel 13 for 120ms... 08:00:06.770 [W] mible_gap: The system has started scaning (mible_gap_scan,229) 08:00:06.770 [I] mible_gap: Start mible gap scan 08:00:06.830 [I] miio_net: Wifi event[1] 08:00:06.830 [I] miio_net: Wifi scan done 08:00:06.830 [D] miio_net: wifi scan finished, 1 wifi_2.4G&5G_test found. 08:00:06.830 [I] miio_net: bingo ssid=wifi_2.4G&5G_test, bssid=9C:9D:7E:EA:D4:EE, pri=1, rssi=-20 I (8304) wifi:new:<1,1>, old:<1,0>, ap:<255,255>, sta:<1,1>, prof:1 I (9294) wifi:state: init -> auth (b0) 08:00:08.090 [I] miio_monitor: work time = 7s, memory left = 88572 08:00:08.090 [D] miio_net: sta will close in 893s I (9364) wifi:state: auth -> assoc (0) I (9394) wifi:state: assoc -> run (10) I (9514) wifi:connected with wifi_2.4G&5G_test, aid = 2, channel 1, 40U, bssid = 9c:9d:7e:ea:d4:ee I (9514) wifi:security: WPA2-PSK, phy: bgn, rssi: -18 I (9514) wifi:pm start, type: 2

08:00:08.300 [I] miio_net: Wifi event[4] 08:00:08.300 [I] miio_net: Wifi station connected I (9594) wifi:AP's beacon interval = 102400 us, DTIM period = 1 08:00:09.300 [I] miio_monitor: work time = 8s, memory left = 87884 08:00:09.300 [D] miio_net: sta will close in 892s I (10814) tcpip_adapter: sta ip: 192.168.31.12, mask: 255.255.255.0, gw: 192.168.31.1 08:00:09.590 [I] miio_net: Wifi event[7] 08:00:09.590 [D] miio_net: Wifi ip=192.168.31.12,mask=255.255.255.0,gw=192.168.31.1 08:00:09.600 [I] miio_net: Wifi station got ip 08:00:09.600 [D] ot: event emit[id=2,txt=otn.mode,ext_len=4] 08:00:09.610 [D] miio_ot: otn.mode[2] happened! Guru Meditation Error: Core 0 panic'ed (InstrFetchProhibited). Exception was unhandled. Core 0 register dump: PC : 0x3ffcbd88 PS : 0x00060130 A0 : 0x8011c664 A1 : 0x3ffd6600
A2 : 0x3ffbfe28 A3 : 0x3ffd6640 A4 : 0x00000058 A5 : 0x3ffd6608
A6 : 0x6bd7c353 A7 : 0x00000005 A8 : 0x801c73fe A9 : 0x3ffd65b0
A10 : 0x3ffd02ec A11 : 0x0000000a A12 : 0x00000000 A13 : 0x00000001
A14 : 0x00000000 A15 : 0xf52e625c SAR : 0x0000000b EXCCAUSE: 0x00000014
EXCVADDR: 0x3ffcbd88 LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000000

ELF file SHA256: c1321ba738970397

Backtrace: 0x3ffcbd85:0x3ffd6600 |<-CORRUPTED

I (10516) esp_core_dump_flash: Save core dump to flash... I (10522) esp_core_dump_common: Found tasks: (17)! I (10656) esp_core_dump_flash: Core dump has been saved to flash. Rebooting... 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:0x3fff0018,len:4 load:0x3fff001c,len:7344 ho 0 tail 12 room 4 load:0x40078000,len:14584 ho 0 tail 12 room 4 load:0x40080400,len:4392 entry 0x40080730 I (76) boot: Chip Revision: 1 I (76) boot_comm: chip revision: 1, min. bootloader chip revision: 0 I (43) boot: ESP-IDF v4.0.1-467-g6256124df 2nd stage bootloader I (43) boot: compile time 19:03:32 I (43) boot: Enabling RNG early entropy source... I (49) boot: SPI Flash RID : 0x684016 I (54) boot: SPI Flash MF : 0x68 I (58) boot: SPI Flash ID : 0x4016 I (62) boot: SPI Speed : 40MHz I (66) boot: SPI Mode : DIO I (70) boot: SPI Flash Size : 4MB I (74) boot: Partition Table: I (78) boot: ## Label Usage Type ST Offset Length I (85) boot: 0 nvs WiFi data 01 02 00009000 00004000 I (93) boot: 1 otadata OTA data 01 00 0000d000 00002000 I (100) boot: 2 phy_init RF data 01 01 0000f000 00001000 I (108) boot: 3 miio_fw1 OTA app 00 10 00010000 00160000 I (115) boot: 4 miio_fw2 OTA app 00 11 00170000 00160000 I (123) boot: 5 test test app 00 20 002d0000 00013000 I (130) boot: 6 mimcu Unknown data 01 fd 002e3000 00100000 I (138) boot: 7 coredump Unknown data 01 03 003e3000 00010000 I (145) boot: 8 minvs Unknown data 01 fe 003f8000 00004000 I (153) boot: End of partition table I (157) boot_comm: chip revision: 1, min. application chip revision: 0 I (164) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x305c0 (198080) map I (244) esp_image: segment 1: paddr=0x000405e8 vaddr=0x3ffbdb60 size=0x03dbc ( 15804) load I (250) esp_image: segment 2: paddr=0x000443ac vaddr=0x3ffc191c size=0x006cc ( 1740) load I (251) esp_image: segment 3: paddr=0x00044a80 vaddr=0x40080000 size=0x00400 ( 1024) load I (260) esp_image: segment 4: paddr=0x00044e88 vaddr=0x40080400 size=0x0b188 ( 45448) load I (287) esp_image: segment 5: paddr=0x00050018 vaddr=0x400d0018 size=0xfb3e8 (1029096) map I (652) esp_image: segment 6: paddr=0x0014b408 vaddr=0x4008b588 size=0x124e4 ( 74980) load I (702) boot: Loaded app from partition at offset 0x10000 I (702) boot: Disabling RNG early entropy source... I (702) cpu_start: Pro cpu up. I (706) cpu_start: Application information: I (711) cpu_start: Project name: miio_app I (716) cpu_start: App version: 1 I (720) cpu_start: Compile time: Mar 22 2021 19:03:35 I (726) cpu_start: ELF file SHA256: c1321ba738970397... I (732) cpu_start: ESP-IDF: v4.0.1-467-g6256124df I (738) cpu_start: Single core mode I (743) heap_init: Initializing. RAM available for dynamic allocation: I (750) heap_init: At 3FFAFF10 len 000000F0 (0 KiB): DRAM I (756) heap_init: At 3FFB6388 len 00001C78 (7 KiB): DRAM I (762) heap_init: At 3FFB9A20 len 00004108 (16 KiB): DRAM I (768) heap_init: At 3FFBDB5C len 00000004 (0 KiB): DRAM I (774) heap_init: At 3FFD02D0 len 0000FD30 (63 KiB): DRAM I (780) heap_init: At 3FFE0440 len 0001FBC0 (126 KiB): D/IRAM I (787) heap_init: At 40078000 len 00008000 (32 KiB): IRAM I (793) heap_init: At 4009DA6C len 00002594 (9 KiB): IRAM I (799) cpu_start: Pro cpu start user code I (817) esp_core_dump_flash: Init core dump to flash I (817) esp_core_dump_flash: Found partition 'coredump' @ 3e3000 65536 bytes I (823) cpu_start: Found core dump 15588 bytes in flash @ 0x3e3000 I (827) cpu_start: Starting scheduler on PRO CPU. 08:00:00.010 [D] Addon: miIO 08:00:00.010 [D] : 0x4010878c: bind_stat 08:00:00.010 [D] : 0x40114a14: bleGetNearbyBandList 08:00:00.010 [D] : 0x40114958: bleStartSearchBand 08:00:00.020 [D] : 0x4010f004: ble_add_linkage 08:00:00.020 [D] : 0x4010fee4: ble_bind_notified 08:00:00.030 [D] : 0x4010f498: ble_del_linkage 08:00:00.030 [D] : 0x4010fad4: ble_enable_linkage 08:00:00.040 [D] : 0x40114eac: ble_gateway_enable 08:00:00.040 [D] : 0x4010f6dc: ble_get_linkage 08:00:00.050 [D] : 0x4010ec78: ble_scan 08:00:00.050 [D] : 0x40110124: ble_unbind_notified 08:00:00.060 [D] : 0x4010785c: config_router 08:00:00.060 [D] : 0x4010797c: config_router_safe 08:00:00.070 [D] : 0x4010864c: disable_local_restore 08:00:00.080 [D] : 0x4012146c: dyna_params 08:00:00.080 [D] : 0x401086d4: get_disable_local_restore 08:00:00.090 [D] : 0x4011e530: get_ota_progress 08:00:00.090 [D] : 0x4011e0a4: get_ota_state 08:00:00.100 [D] : 0x40100aa8: handshake 08:00:00.100 [D] : 0x4011d640: help 08:00:00.110 [D] : 0x4011cf78: info 08:00:00.110 [D] : 0x40121dc0: iperf_client

不知道是小米的patch缺少修改信息还是什么情况

ESP-Coco commented 3 years ago

InstrFetchProhibited 说明当前访问的是非法指令,通过PC地址发现,当前调用的地址区域并不是指令执行区域(0x4xxxxxxx),因此这个问题可能是野指针导致的。针对这个问题,建议排查:1. 是否存在二次开发,如果是的话需要排查自身代码 2. 如果未二次开发,可以在小米SDK不同的位置加log,初步确定哪些函数导致