search

h2zero / NimBLE-Arduino

A fork of the NimBLE library structured for compilation with Arduino, for use with ESP32, nRF5x.
https://h2zero.github.io/NimBLE-Arduino/
Apache License 2.0
698 stars 144 forks source link

Connection fails without any reason WROOM-32S #324

Closed Aryankids closed 2 years ago

Aryankids commented 2 years ago

Have compiled and uploaded the code successfully that is using your library i.e.

[am43]https://github.com/buxtronix/am43

to an ESP32 board but it cannot stay connected to the AM43 over Bluetooth. it gets disconnected (failed connection) almost instantly.

13:25:47.585 -> BLE scan complete. 13:25:47.622 -> Attempting to connect to: 02:98:c2:99:bd:ba ...[0298c299bdba] Connected 13:25:47.622 -> - Failed to connect. 13:25:48.453 -> Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled. 13:25:48.486 -> 13:25:48.486 -> Core 0 register dump: 13:25:48.486 -> PC : 0x40095b95 PS : 0x00060b33 A0 : 0x800db5cc A1 : 0x3ffdc230 13:25:48.486 -> A2 : 0x00000010 A3 : 0x3ffbf1c8 A4 : 0x00000000 A5 : 0x00000002 13:25:48.486 -> A6 : 0x00000002 A7 : 0x00000000 A8 : 0x80095b83 A9 : 0x00000110 13:25:48.486 -> A10 : 0x00000001 A11 : 0x3ffc60f8 A12 : 0x3ffc60f8 A13 : 0x00060b23 13:25:48.524 -> A14 : 0x00060b20 A15 : 0x00000001 SAR : 0x00000010 EXCCAUSE: 0x0000001c 13:25:48.524 -> EXCVADDR: 0x00000164 LBEG : 0x4009086c LEND : 0x40090877 LCOUNT : 0x00000000 13:25:48.524 -> 13:25:48.524 -> 13:25:48.524 -> Backtrace:0x40095b92:0x3ffdc2300x400db5c9:0x3ffdc250 0x400e14d1:0x3ffdc2d0 0x400e151b:0x3ffdc2f0 0x400e29c3:0x3ffdc310 0x400df90d:0x3ffdc370 0x400df741:0x3ffdc3a0 0x400e676b:0x3ffdc3d0 0x400e5298:0x3ffdc400 0x400e52a3:0x3ffdc420 0x400ec0ae:0x3ffdc440 0x400db967:0x3ffdc460 13:25:48.558 -> 13:25:48.558 -> 13:25:48.558 -> 13:25:48.558 -> 13:25:48.558 -> ELF file SHA256: 0000000000000000 13:25:48.558 -> 13:25:48.558 -> Rebooting... 13:25:48.558 -> ets Jun 8 2016 00:22:57 13:25:48.558 -> 13:25:48.558 -> rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) 13:25:48.558 -> configsip: 0, SPIWP:0xee 13:25:48.558 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 13:25:48.558 -> mode:DIO, clock div:1 13:25:48.558 -> load:0x3fff0030,len:1184 13:25:48.558 -> load:0x40078000,len:12804 13:25:48.592 -> ho 0 tail 12 room 4 13:25:48.592 -> load:0x40080400,len:3032 13:25:48.592 -> entry 0x400805e4 13:25:48.938 -> Starting Arduino BLE Client application... 13:25:48.938 -> Using NimBLE stack. 13:25:49.942 -> Wifi connecting to: MyNetwork ... 13:25:49.942 -> [WiFi-event] event: 0 13:25:50.047 -> [WiFi-event] event: 2 13:25:50.047 -> AllowList contains the following device(s): 13:25:50.047 -> Mac: 02:98:c2:99:bd:ba 13:25:50.254 -> Configuring WDT... 13:25:51.044 -> BLE Advertised Device found: Name: OfficeBlind, Address: 02:98:c2:99:bd:ba, manufacturer data: 0000, serviceUUID: 0xfe50 13:25:53.050 -> [WiFi-event] event: 4 13:25:53.494 -> [WiFi-event] event: 7 13:25:53.494 -> WiFi connected 13:25:53.494 -> IP address: 192.168.1.112 13:25:53.494 -> Attempting MQTT connection... 13:25:53.494 -> connected 13:25:54.487 -> MQTT [am43/enable]2: ON 13:25:54.487 -> Addr: enable Cmd: am43/enable 13:25:54.487 -> Enabling BLE Clients 13:26:00.276 -> BLE scan complete. 13:26:00.276 -> Attempting to connect to: 02:98:c2:99:bd:ba ...[0298c299bdba] Connected 13:26:00.276 -> - Failed to connect. 13:26:02.276 -> Up for 13s 13:26:12.287 -> BLE scan complete

Same Information in the debug mood:

17:30:59.395 -> I NimBLEScan: "New advertiser: 02:98:c2:99:bd:ba" 17:30:59.395 -> I NimBLEScan: "Updated advertiser: 02:98:c2:99:bd:ba" 17:30:59.395 -> BLE Advertised Device found: Name: OfficeBlind, Address: 02:98:c2:99:bd:ba, manufacturer data: 0000, serviceUUID: 0xfe50 17:30:59.740 -> [ 4151][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 4 - STA_CONNECTED 17:30:59.777 -> [WiFi-event] event: 4 17:31:00.151 -> [ 4561][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 7 - STA_GOT_IP 17:31:00.187 -> [ 4561][D][WiFiGeneric.cpp:880] _eventCallback(): STA IP: 192.168.1.112, MASK: 255.255.255.0, GW: 192.168.1.1 17:31:00.187 -> [WiFi-event] event: 7 17:31:00.187 -> WiFi connected 17:31:00.187 -> IP address: 192.168.1.112 17:31:00.187 -> Attempting MQTT connection... 17:31:00.187 -> I NimBLEScan: "New advertiser: ca:1e:d0:92:6d:06" 17:31:00.255 -> connected 17:31:06.962 -> D NimBLEScan: "discovery complete; reason=0" 17:31:06.962 -> BLE scan complete. 17:31:06.995 -> Attempting to connect to: 02:98:c2:99:bd:ba ...D NimBLEClient: ">> connect(02:98:c2:99:bd:ba)" 17:31:06.995 -> I NimBLEClient: "Connection established" 17:31:06.995 -> [0298c299bdba] Connected 17:31:06.995 -> D NimBLEClient: "<< connect()" 17:31:06.995 -> - Failed to connect. 17:31:07.491 -> D NimBLEClient: "Got Client event " 17:31:07.491 -> I NimBLEClient: "Connected event" 17:31:07.560 -> D NimBLEClient: "Got Client event " 17:31:07.593 -> I NimBLEClient: "mtu update event; conn_handle=0 mtu=247" 17:31:08.532 -> D NimBLEClient: "Got Client event " 17:31:08.532 -> D NimBLEClient: "Peer requesting to update connection parameters" 17:31:08.532 -> D NimBLEClient: "MinInterval: 20, MaxInterval: 20, Latency: 0, Timeout: 500" 17:31:08.532 -> Guru Meditation Error: Core 0 panic'ed (LoadProhibited). Exception was unhandled. 17:31:08.566 -> 17:31:08.566 -> Core 0 register dump: 17:31:08.566 -> PC : 0x400dde8f PS : 0x00060130 A0 : 0x800e4b54 A1 : 0x3ffdc8b0 17:31:08.566 -> A2 : 0x00000000 A3 : 0x3ffdd9f0 A4 : 0x3ffdc9ac A5 : 0x3f403137 17:31:08.566 -> A6 : 0x3f40281c A7 : 0x000001f4 A8 : 0x800dde85 A9 : 0x3ffdc860 17:31:08.566 -> A10 : 0x3ffdcd58 A11 : 0x3ffdd9f0 A12 : 0x3ffdca14 A13 : 0x3ffdc860 17:31:08.602 -> A14 : 0x00000014 A15 : 0x00000014 SAR : 0x00000004 EXCCAUSE: 0x0000001c 17:31:08.602 -> EXCVADDR: 0x00000010 LBEG : 0x40090e19 LEND : 0x40090e29 LCOUNT : 0xfffffffc 17:31:08.602 -> 17:31:08.602 -> 17:31:08.602 -> Backtrace:0x400dde8c:0x3ffdc8b00x400e4b51:0x3ffdc960 0x400e4b9b:0x3ffdc980 0x400e5011:0x3ffdc9a0 0x400eb437:0x3ffdca00 0x400eb3a6:0x3ffdca40 0x400ea0cf:0x3ffdca70 0x400e8bfc:0x3ffdcaa0 0x400e8c07:0x3ffdcac0 0x400efa12:0x3ffdcae0 0x400de222:0x3ffdcb00 17:31:08.635 -> 17:31:08.635 -> 17:31:08.635 -> 17:31:08.635 -> 17:31:08.635 -> ELF file SHA256: 0000000000000000 17:31:08.635 -> 17:31:08.635 -> Rebooting... 17:31:08.635 -> ets Jun 8 2016 00:22:57 17:31:08.635 -> 17:31:08.635 -> rst:0xc (SW_CPU_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT) 17:31:08.635 -> configsip: 0, SPIWP:0xee 17:31:08.635 -> clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00 17:31:08.635 -> mode:DIO, clock div:1 17:31:08.635 -> load:0x3fff0030,len:1184 17:31:08.635 -> load:0x40078000,len:12804 17:31:08.635 -> ho 0 tail 12 room 4 17:31:08.635 -> load:0x40080400,len:3032 17:31:08.670 -> entry 0x400805e4 17:31:09.014 -> [�����⸮⸮m�um⸮⸮⸮⸮2-hal-cpu.c:211] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz 17:31:09.014 -> Starting Arduino BLE Client application... 17:31:09.014 -> Using NimBLE stack. 17:31:10.018 -> Wifi connecting to: MyNetwork ... 17:31:10.052 -> [ 1040][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 0 - WIFI_READY 17:31:10.052 -> [WiFi-event] event: 0 17:31:10.119 -> [ 1130][D][WiFiGeneric.cpp:831] _eventCallback(): Arduino Event: 2 - STA_START 17:31:10.152 -> [WiFi-event] event: 2 17:31:10.152 -> AllowList contains the following device(s): 17:31:10.152 -> Mac: 02:98:c2:99:bd:ba 17:31:10.152 -> [ 1153][I][ArduinoOTA.cpp:141] begin(): OTA server at: esp32-58bf253703a8.local:3232 17:31:10.330 -> I NimBLEDevice: "BLE Host Task Started" 17:31:10.330 -> I NimBLEDevice: "NimBle host synced." 17:31:10.364 -> D NimBLEScan: ">> start(duration=10)" 17:31:10.364 -> D NimBLEScan: "<< start()" 17:31:10.364 -> Configuring WDT...

What I have noticed, although it is failed to connect over BLE and it cannot report back the status of the device, it does not allow any other Bluetooth devices to connect to the AM43 unless I unplug the ESP32 device to force it to release the connection. in other words connected but not connected

h2zero commented 2 years ago

Something strange is going on in your logs:

17:31:06.995 -> Attempting to connect to: 02:98:c2:99:bd:ba ...D NimBLEClient: ">> connect(02:98:c2:99:bd:ba)"
17:31:06.995 -> I NimBLEClient: "Connection established"
17:31:06.995 -> [0298c299bdba] Connected
17:31:06.995 -> D NimBLEClient: "<< connect()"
17:31:06.995 -> - Failed to connect.
17:31:07.491 -> D NimBLEClient: "Got Client event "
17:31:07.491 -> I NimBLEClient: "Connected event"
17:31:07.560 -> D NimBLEClient: "Got Client event "
17:31:07.593 -> I NimBLEClient: "mtu update event; conn_handle=0 mtu=247"

I NimBLEClient: "Connection established" should never happen before I NimBLEClient: "mtu update event; conn_handle=0 mtu=247" as the task is blocked until the MTU is updated.

Have any modifications been made to the library? What version of arduino-esp32 and NimBLE-Arduino are you using?

I'm not familiar with the WROOM-32S, did you mean SE? If it's an older module there has been known controller hardware issues with some.

Aryankids commented 2 years ago

Thanks for the speedy response. No, I have not made any changes. I used version 1.3.3 (NimBLE) and 2.0.2 esp3 i.e. the latest on both. I have not changed anything on AM43 side either. Happy to provide more logs if that helps.

re the board, this is the one I am using Board

h2zero commented 2 years ago

Thanks for the link to the board, the module appears to be just a standard one judging by the pictures. I'll attempt to repro the issue and get back to you.

Aryankids commented 2 years ago

happy to help and contribute. Pls let me know

h2zero commented 2 years ago

I've identified the issue, it's due to the new version of FreeRTOS in the latest arduino core. I'm looking into the fix.

h2zero commented 2 years ago

@Aryankids could you try the bugfix-task-notify branch in #326 and let me know if that works for you?

Aryankids commented 2 years ago

@h2zero many thanks for the prompt action. will give it a try and report back.

Aryankids commented 2 years ago

I did try it, the other issue does not seem to occur, but, I have now a new issue :

17:33:06.609 -> I NimBLEScan: "Updated advertiser: 2b:58:65:42:07:3e" 17:33:06.609 -> I NimBLEScan: "Updated advertiser: 64:e7:d8:6d:dc:d9" 17:33:06.681 -> D NimBLEScan: "discovery complete; reason=0" 17:33:06.715 -> BLE scan complete. 17:33:06.715 -> Attempting to connect to: 02:98:c2:99:bd:ba ...D NimBLEClient: ">> connect(02:98:c2:99:bd:ba)" 17:33:08.053 -> D NimBLEClient: "Got Client event " 17:33:08.053 -> I NimBLEClient: "Connected event" 17:33:08.362 -> lld_pdu_get_tx_flush_nb HCI packet count mismatch (1, 2) 17:33:08.362 -> D NimBLEClient: "Got Client event " 17:33:08.362 -> E NimBLEClient: "Connection failed; status=574 " 17:33:08.362 -> - Failed to connect.

h2zero commented 2 years ago

Glad that the original issue is resolved. This issue you're seeing now is just a failed connection, quite normal.

Aryankids commented 2 years ago

You are absolutely right, reattempted and got EVERYthing working. Many thanks for your help and support.

18:06:20.793 -> Attempting to connect to: 02:98:c2:99:bd:ba ...D NimBLEClient: ">> connect(02:98:c2:99:bd:ba)" 18:06:21.006 -> D NimBLEClient: "Got Client event " 18:06:21.040 -> I NimBLEClient: "Connected event" 18:06:21.113 -> D NimBLEClient: "Got Client event " 18:06:21.113 -> I NimBLEClient: "mtu update event; conn_handle=0 mtu=247" 18:06:21.113 -> I NimBLEClient: "Connection established" 18:06:21.113 -> [0298c299bdba] Connected 18:06:21.113 -> D NimBLEClient: "<< connect()" 18:06:21.113 -> - Connected to server 18:06:21.113 -> D NimBLEClient: ">> deleteServices"

Aryankids commented 2 years ago

issue resolved with the fix provided.

h2zero commented 2 years ago

Thanks for the feedback.