esp-wifi
esp-wifi copied to clipboard
esp-rs
lld_pdu.c assertions running BLE example on `esp32` chip
$ cargo "+esp" run --example ble --release --target xtensa-esp32-none-elf --features "esp32,ble"
Compiling esp-wifi v0.1.0 (/Users/brandonros/Desktop/esp-wifi)
Finished release [optimized] target(s) in 1.66s
Running `espflash --speed 921600 --monitor target/xtensa-esp32-none-elf/release/examples/ble`
Detected 2 serial ports. Ports which match a known common dev board are highlighted.
Serial port: /dev/tty.usbserial-02728E37
Connecting...
WARN setting baud rate higher than 115200 can cause issues.
Chip type: ESP32 (revision 3)
Crystal frequency: 40MHz
Flash size: 16MB
Features: WiFi, BT, Dual Core, 240MHz, Coding Scheme None
MAC address: 94:b9:7e:57:4b:18
App/part. size: 294688/16711680 bytes, 1.76%
[00:00:00] ######################################## 16/16 segment 0x1000 [00:00:00] ######################################## 1/1 segment 0x8000 [00:00:03] ######################################## 156/156 segment 0x10000
Flashing has completed!
Commands:
CTRL+R Reset chip
CTRL+C Exit
ets Jul 29 2019 12:21:46
rst:0x1 (POWERON_RESET),boot:0x17 (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:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
0x40078000 - r_rwip_reset
at ??:??
load:0x4007c428,len:4840
0x4007c428 - r_rwip_reset
at ??:??
entry 0x4007c6a0
0x4007c6a0 - r_rwip_reset
at ??:??
WARN - coex_register_bt_cb 0x40081698
0x40081698 - coex_bt_callback
at ??:??
WARN - coex_schm_register_btdm_callback 0x400df318
0x400df318 - coex_schm_btdm_callback
at ??:??
WARN - coex_wifi_channel_get
Ok(CommandComplete { num_packets: 5, opcode: 3075, data: [0] })
Ok(CommandComplete { num_packets: 5, opcode: 8198, data: [0] })
Ok(CommandComplete { num_packets: 5, opcode: 8200, data: [0] })
Ok(CommandComplete { num_packets: 5, opcode: 8202, data: [0] })
started advertising
ASSERT_PARAM(9 0), in lld_pdu.c at line 605
Exception occured Illegal Context { PC: 400816df, PS: 60c11, A0: 80081ac5, A1: 3ffff1e0, A2: 0, A3: 9, A4: 0, A5: 3f4110da, A6: 25d, A7: fffffffc, A8: 8000814b, A9: 3ffff150, A10: 0, A11: 3ffff173, A12: 3ffff11f, A13: 35, A14: 0, A15: 3ffff124, SAR: 4, EXCCAUSE: 0, EXCVADDR: 0, LBEG: 400819cd, LEND: 400819d5, LCOUNT: 0, THREADPTR: 0, SCOMPARE1: 0, BR: 0, ACCLO: 0, ACCHI: 0, M0: 0, M1: 0, M2: 0, M3: 0, F64R_LO: 0, F64R_HI: 0, F64S: 0, FCR: 0, FSR: 80, F0: 433b8000, F1: 426c0000, F2: 43800000, F3: 0, F4: 0, F5: 0, F6: 0, F7: 0, F8: 0, F9: 0, F10: 0, F11: 0, F12: 0, F13: 0, F14: 0, F15: 0 }
0x400816df
0x400816df - r_assert
at ??:??
0x40081ac5
0x40081ac5 - r_assert_param
at ??:??
0x40086364
0x40086364 - r_lld_pdu_rx_handler
at ??:??
0x40084be4
0x40084be4 - r_lld_evt_end
at ??:??
0x400848f5
0x400848f5 - r_lld_evt_end_isr
at ??:??
0x400870b1
0x400870b1 - r_rwble_isr
at ??:??
0x40088432
0x40088432 - r_rwbtdm_isr_wrapper
at ??:??
0x400d3521
0x400d3521 - RWBLE
at ??:??
0x4008ba44
0x4008ba44 - _ZN14esp_hal_common9interrupt8vectored16handle_interrupt17hd4ff79f68e7aaaf8E
at ??:??
0x4008b9fd
0x4008b9fd - _ZN14esp_hal_common9interrupt8vectored17handle_interrupts17h66a646a6760229b5E
at ??:??
0x4008af91
0x4008af91 - __level_3_interrupt
at ??:??
0x4008bc92
0x4008bc92 - .RestoreContext
at ??:??
ets Jul 29 2019 12:21:46
rst:0x1 (POWERON_RESET),boot:0x17 (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:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
0x40078000 - r_rwip_reset
at ??:??
load:0x4007c428,len:4840
0x4007c428 - r_rwip_reset
at ??:??
entry 0x4007c6a0
0x4007c6a0 - r_rwip_reset
at ??:??
WARN - coex_register_bt_cb 0x40081698
0x40081698 - coex_bt_callback
at ??:??
WARN - coex_schm_register_btdm_callback 0x400df318
0x400df318 - coex_schm_btdm_callback
at ??:??
WARN - coex_wifi_channel_get
Ok(CommandComplete { num_packets: 5, opcode: 3075, data: [0] })
Ok(CommandComplete { num_packets: 5, opcode: 8198, data: [0] })
Ok(CommandComplete { num_packets: 5, opcode: 8200, data: [0] })
Ok(CommandComplete { num_packets: 5, opcode: 8202, data: [0] })
started advertising
INFO - polled: Some(AsyncData(AclPacket { handle: 0, boundary_flag: FirstAutoFlushable, bc_flag: PointToPoint, data: [3, 0, 4, 0, 2, f, 2] }))
INFO - att: ExchangeMtu { mtu: 20f }
INFO - Requested MTU 527, returning 23
INFO - src_handle 0
INFO - data [3, 17, 0]
INFO - encoded_l2cap [3, 0, 4, 0, 3, 17, 0]
INFO - writing [2, 0, 20, 7, 0, 3, 0, 4, 0, 3, 17, 0]
INFO - polled: Some(Event(NumberOfCompletedPackets { number_of_connection_handles: 1, connection_handles: 0, completed_packets: 1 }))
INFO - polled: Some(AsyncData(AclPacket { handle: 0, boundary_flag: FirstAutoFlushable, bc_flag: PointToPoint, data: [3, 0, 4, 0, a, 3, 0] }))
INFO - att: ReadReq { handle: 3 }
INFO - src_handle 0
INFO - data [b, 48, 65, 6c, 6c, 6f, 20, 42, 61, 72, 65, 2d, 4d, 65, 74, 61, 6c, 20, 42, 4c, 45]
INFO - encoded_l2cap [15, 0, 4, 0, b, 48, 65, 6c, 6c, 6f, 20, 42, 61, 72, 65, 2d, 4d, 65, 74, 61, 6c, 20, 42, 4c, 45]
INFO - writing [2, 0, 20, 19, 0, 15, 0, 4, 0, b, 48, 65, 6c, 6c, 6f, 20, 42, 61, 72, 65, 2d, 4d, 65, 74, 61, 6c, 20, 42, 4c, 45]
INFO - polled: Some(Event(NumberOfCompletedPackets { number_of_connection_handles: 1, connection_handles: 0, completed_packets: 1 }))
ASSERT_PARAM(0 182), in lld_pdu.c at line 605
Exception occured Illegal Context { PC: 400816df, PS: 60811, A0: 80081ac5, A1: 3ffd8e80, A2: 0, A3: 0, A4: b6, A5: 3f4110da, A6: 25d, A7: fffffffc, A8: 8000814b, A9: 3ffd8df0, A10: 0, A11: 3ffd8e13, A12: 3ffd8dbf, A13: 35, A14: 0, A15: 3ffd8dc4, SAR: 4, EXCCAUSE: 0, EXCVADDR: 0, LBEG: 400819cd, LEND: 400819d5, LCOUNT: 0, THREADPTR: 0, SCOMPARE1: 0, BR: 0, ACCLO: 0, ACCHI: 0, M0: 0, M1: 0, M2: 0, M3: 0, F64R_LO: 0, F64R_HI: 0, F64S: 0, FCR: 0, FSR: 0, F0: 0, F1: 0, F2: 0, F3: 0, F4: 0, F5: 0, F6: 0, F7: 0, F8: 0, F9: 0, F10: 0, F11: 0, F12: 0, F13: 0, F14: 0, F15: 0 }
0x400816df
0x400816df - r_assert
at ??:??
0x40081ac5
0x40081ac5 - r_assert_param
at ??:??
0x40086364
0x40086364 - r_lld_pdu_rx_handler
at ??:??
0x40084be4
0x40084be4 - r_lld_evt_end
at ??:??
0x400848f5
0x400848f5 - r_lld_evt_end_isr
at ??:??
0x400870b1
0x400870b1 - r_rwble_isr
at ??:??
0x40088432
0x40088432 - r_rwbtdm_isr_wrapper
at ??:??
0x400d3521
0x400d3521 - RWBLE
at ??:??
0x4008ba44
0x4008ba44 - _ZN14esp_hal_common9interrupt8vectored16handle_interrupt17hd4ff79f68e7aaaf8E
at ??:??
0x4008b9fd
0x4008b9fd - _ZN14esp_hal_common9interrupt8vectored17handle_interrupts17h66a646a6760229b5E
at ??:??
0x4008af91
0x4008af91 - __level_3_interrupt
at ??:??
0x4008bc92
0x4008bc92 - .RestoreContext
at ??:??
Thanks for reporting this. This might be caused by a miscompilation / misoptimization but 1.65 should hopefully fix a few things.
I'd suggest let's wait for 1.65 and in the meantime, you might want to try different optimization levels which might or might not help
started advertising
INFO - polled: Some(AsyncData(AclPacket { handle: 0, boundary_flag: FirstAutoFlushable, bc_flag: PointToPoint, data: [3, 0, 4, 0, 2, f, 2] }))
INFO - att: ExchangeMtu { mtu: 20f }
INFO - Requested MTU 527, returning 23
INFO - src_handle 0
INFO - data [3, 17, 0]
INFO - encoded_l2cap [3, 0, 4, 0, 3, 17, 0]
INFO - writing [2, 0, 20, 7, 0, 3, 0, 4, 0, 3, 17, 0]
INFO - polled: Some(Event(NumberOfCompletedPackets { number_of_connection_handles: 1, connection_handles: 0, completed_packets: 1 }))
ASSERT_PARAM(0 182), in lld_pdu.c at line 605
!! A panic occured in '/Users/brandonros/.cargo/registry/src/github.com-1ecc6299db9ec823/xtensa-lx-rt-0.13.0/src/exception/esp32.rs', at line 102, column 5
PanicInfo {
payload: Any { .. },
message: Some(
Exception: Illegal, Context { PC: 400816df, PS: 00060411, A0: 80081ac5, A1: 3ffff120, A2: 00000000, A3: 00000000, A4: 000000b6, A5: 3f4115de, A6: 0000025d, A7: fffffffc, A8: 8000814b, A9: 3ffff090, A10: 00000000, A11: 3ffff0b3, A12: 3ffff05f, A13: 00000035, A14: 00000000, A15: 3ffff064, SAR: 00000004, EXCCAUSE: 00000000, EXCVADDR: 00000000, LBEG: 400819cd, LEND: 400819d5, LCOUNT: 00000000, THREADPTR: 00000000, SCOMPARE1: 00000000, BR: 00000000, ACCLO: 00000000, ACCHI: 00000000, M0: 00000000, M1: 00000000, M2: 00000000, M3: 00000000, F64R_LO: 00000000, F64R_HI: 00000000, F64S: 00000000, FCR: 00000000, FSR: 00000080, F0: 433b8000, F1: 426c0000, F2: 43800000, F3: 00000000, F4: 00000000, F5: 00000000, F6: 00000000, F7: 00000000, F8: 00000000, F9: 00000000, F10: 00000000, F11: 00000000, F12: 00000000, F13: 00000000, F14: 00000000, F15: 00000000 },
),
location: Location {
file: "/Users/brandonros/.cargo/registry/src/github.com-1ecc6299db9ec823/xtensa-lx-rt-0.13.0/src/exception/esp32.rs",
line: 102,
col: 5,
},
can_unwind: true,
}
Backtrace:
0x4008ba29
0x4008ba29 - __exception
at ??:??
0x4008bd25
0x4008bd25 - __naked_kernel_exception
at ??:??
0x40040003
0x40040003 - r_ld_sched_sniff_add
at ??:??
0x400816df
0x400816df - r_assert
at ??:??
0x40086364
0x40086364 - r_lld_pdu_rx_handler
at ??:??
0x40084be4
0x40084be4 - r_lld_evt_end
at ??:??
0x400848f5
0x400848f5 - r_lld_evt_end_isr
at ??:??
0x400870b1
0x400870b1 - r_rwble_isr
at ??:??
0x40088432
0x40088432 - r_rwbtdm_isr_wrapper
at ??:??
0x400d3751
0x400d3751 - RWBLE
at ??:??
get this after compiling, flashing, running, grabbing iPhone, connecting with BT Inspector app
could you elaborate more on what optimization levels I should try? really love the progress you've made in this area and want to try to work around this blocker
[profile.dev]
opt-level = 0
[profile.release]
opt-level = 3
or something more custom?
ets Jul 29 2019 12:21:46
rst:0x1 (POWERON_RESET),boot:0x17 (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:0x3fff0048,len:12
ho 0 tail 12 room 4
load:0x3fff0054,len:4800
load:0x40078000,len:17448
0x40078000 - r_rwip_reset
at ??:??
load:0x4007c428,len:4840
0x4007c428 - r_rwip_reset
at ??:??
entry 0x4007c6a0
0x4007c6a0 - r_rwip_reset
at ??:??
WARN - coex_register_bt_cb 0x40081698
0x40081698 - coex_bt_callback
at ??:??
WARN - coex_schm_register_btdm_callback 0x400df714
0x400df714 - coex_schm_btdm_callback
at ??:??
WARN - coex_wifi_channel_get
started advertising
INFO - polled: Some(AsyncData(AclPacket { handle: 0, boundary_flag: FirstAutoFlushable, bc_flag: PointToPoint, data: [3, 0, 4, 0, 2, f, 2] }))
INFO - att: ExchangeMtu { mtu: 20f }
INFO - Requested MTU 527, returning 23
INFO - src_handle 0
INFO - data [3, 17, 0]
INFO - encoded_l2cap [3, 0, 4, 0, 3, 17, 0]
INFO - writing [2, 0, 20, 7, 0, 3, 0, 4, 0, 3, 17, 0]
INFO - polled: Some(Event(NumberOfCompletedPackets { number_of_connection_handles: 1, connection_handles: 0, completed_packets: 1 }))
ASSERT_PARAM(1 2), in lld_evt.c at line 2061
!! A panic occured in '/Users/brandonros/.cargo/registry/src/github.com-1ecc6299db9ec823/xtensa-lx-rt-0.13.0/src/exception/esp32.rs', at line 102, column 5
PanicInfo {
payload: Any { .. },
message: Some(
Exception: Illegal, Context { PC: 400816df, PS: 00060011, A0: 80081ac5, A1: 3ffff140, A2: 00000000, A3: 00000001, A4: 00000002, A5: 3f411326, A6: 0000080d, A7: fffffffb, A8: 8000814b, A9: 3ffff0b0, A10: 00000000, A11: 3ffff0d4, A12: 3ffff07f, A13: 00000031, A14: 00000000, A15: 3ffff085, SAR: 00000004, EXCCAUSE: 00000000, EXCVADDR: 00000000, LBEG: 400819cd, LEND: 400819d5, LCOUNT: 00000000, THREADPTR: 00000000, SCOMPARE1: 00000000, BR: 00000000, ACCLO: 00000000, ACCHI: 00000000, M0: 00000000, M1: 00000000, M2: 00000000, M3: 00000000, F64R_LO: 00000000, F64R_HI: 00000000, F64S: 00000000, FCR: 00000000, FSR: 00000080, F0: 433b8000, F1: 426c0000, F2: 43800000, F3: 00000000, F4: 00000000, F5: 00000000, F6: 00000000, F7: 00000000, F8: 00000000, F9: 00000000, F10: 00000000, F11: 00000000, F12: 00000000, F13: 00000000, F14: 00000000, F15: 00000000 },
),
location: Location {
file: "/Users/brandonros/.cargo/registry/src/github.com-1ecc6299db9ec823/xtensa-lx-rt-0.13.0/src/exception/esp32.rs",
line: 102,
col: 5,
},
can_unwind: true,
}
Backtrace:
0x4008ba29
0x4008ba29 - __default_exception
at ??:??
0x4008bd25
0x4008bd25 - __naked_user_exception
at ??:??
0x40040003
0x40040003 - r_ld_sched_sniff_add
at ??:??
0x400816df
0x400816df - r_assert
at ??:??
0x40084c3a
0x40084c3a - r_lld_evt_end
at ??:??
0x400848f5
0x400848f5 - r_lld_evt_end_isr
at ??:??
0x400870b1
0x400870b1 - r_rwble_isr
at ??:??
0x40088432
0x40088432 - r_rwbtdm_isr_wrapper
at ??:??
0x400d3751
0x400d3751 - RWBLE
at ??:??
0x4008ba10
0x4008ba10 - _ZN14esp_hal_common9interrupt8vectored16handle_interrupt17h9bc01e6c8b9ab782E
at ??:??
another just in case it helps
You might want to try opt-levels 1,2,"s" and "z" for release (in debug things tend to be way to slow so you really want release builds).
The assert happens in the closed-source driver (which I don't have access to). What happens according to the backtrace is that an RWBLE interrupt is raised and we call the registered callback (inside the driver). For some reason it's unhappy about something - that's all I see currently