search

fsievers22 / esphome-ble-remote

ESPHome external component for a BLE HID client
MIT License
25 stars 10 forks source link

crash with unhandled exception #23

Closed alexbilevskiy closed 1 year ago

alexbilevskiy commented 1 year ago

Crashes with both my remotes (chromecast remote / cheap chinese shutter button). Board is esp-wroom-32 Maybe this is because my board does not have psram? Not sure how to check it. But another board, esp32-cam, which definitely has psram, crashes the same way.

[I][esp32_ble_client:064]: [0] [2B:80:3C:5A:A1:11] 0x00 Attempting BLE connection
[I][esp32_ble_client:265]: [0] [2B:80:3C:5A:A1:11] auth complete. remote BD_ADDR: 2b803c5aa111
[D][ble_client_hid:131]: GATT HID service found on device 2B:80:3C:5A:A1:11
[I][esp32_ble_client:196]: [0] [2B:80:3C:5A:A1:11] Connected
[D][ble_client_hid:145]: GATTC search finished with status code 0
[D][esp32_ble_tracker:245]: Starting scan...
[D][ble_client_hid:036]: Reading client characteristics
[W][ble_client_hid:239]: read_char failed
[W][ble_client_hid:239]: read_char failed
[D][ble_client_hid:070]: Found 6 characteristics
Guru Meditation Error: Core  1 panic'ed (LoadProhibited). Exception was unhandled.

Core  1 register dump:
....

I'd be happy to try and fix myself, if you point where to look

kbouchard111 commented 1 year ago

I echo the sentiment, I'll gladly do some leg work if someone has a hint as to what maybe wrong.

I'm getting the same error message too. I originally thought it was due to lack of psram as I was also using a esp-wroom-32.

I later switched to a freenove esp32-wrover-e which has 8mb of psram (though apparently only 4mb is addressable due to a esp32 memory map limitation).

I'm testing with a GI 20s pro remote (with expectations that I'd have to play around with the hid mappings).

My esphome yaml config is: `esp32: board: esp-wrover-kit #modify to fit your board framework: #only works n esp-idf framework type: esp-idf

esphome: name: esp32cam-bleremote

external_components:

use ble_client_hid from this master branch in GitHub

Enable logging

logger:

level: INFO

level: VERY_VERBOSE

Enable Home Assistant API

api:

ota: password: !secret ota_pass

wifi: ssid: !secret wifi_ssid password: !secret wifi_password fast_connect: on use_address: 10.1.50.39 manual_ip: static_ip: 10.1.50.39 gateway: 10.1.0.1 subnet: 255.255.0.0

esp32_ble_tracker:

ble_client:

ble_client_hid:

sensor:

text_sensor:

I did try leaving the logger to INFO and had the same results which is why I switched to VERY_VERBOSE to try and get more information.

I've looked at the other issues and did see the notes stating that not all boards are compatible and psram is required. However there is no mention on esphome's page or here about how to enable psram which leads me to suspect its built into esphome already. This page https://esphome.io/components/display/ili9xxx.html?highlight=psram references that esphome can use psram and doesnt mention either that it needs to be switched on.

Regardless I even tried manually updating platformio.ini though I dont know if I did it correctly (still compiles without error). I've grabbed the info from https://thingpulse.com/esp32-how-to-use-psram/ the platformio.ini file I modified is in the folder /config/esphome/.esphome/build// and the following changes were made: [common] lib_deps = build_flags = -fpermissive -DCORE_DEBUG_LEVEL=5 -DBOARD_HAS_PSRAM -mfix-esp32-psram-cache-issue upload_flags =

There is another page https://stackoverflow.com/questions/58123580/how-to-fix-guru-meditation-error-core-1-paniced-loadprohibited-exception-w which talks about the core 1 panic'ed error with BLE and suggests its an upstream issue with the library (espressif??) however if that was the case I'd expect everyone/all boards to have the same issues and clearly there are successful setups.

My logs look like this before the crash causes the esp32 to reboot: [23:05:23][W][component:204]: Component ble_client took a long time for an operation (0.35 s). [23:05:23][W][component:205]: Components should block for at most 20-30ms. [23:05:23][V][esp32_ble:178]: (BLE) gap_event_handler - 2 [23:05:23][V][esp32_ble:178]: (BLE) gap_event_handler - 7 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 3 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=3 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 3 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=3 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 3 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=3 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 3 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=3 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 8 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=8 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 8 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=8 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 8 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=8 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 8 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=8 gattc_if=3 [23:05:23][W][component:204]: Component esp32_ble took a long time for an operation (0.11 s). [23:05:23][W][component:205]: Components should block for at most 20-30ms. [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 8 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=8 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_event [esp_gatt_if: 3] - 8 [23:05:23][V][esp32_ble_client:114]: [0] [46:E7:26:5B:19:13] gattc_event_handler: event=8 gattc_if=3 [23:05:23][V][esp32_ble:206]: (BLE) gattc_eveGuru Meditation Error: Core 1 panic'ed (LoadProhibited). Exception was unhandled. [23:05:23] [23:05:23]Core 1 register dump: [23:05:23]PC : 0x400d90c6 PS : 0x00060330 A0 : 0x800d9403 A1 : 0x3ffde490 [23:05:23]A2 : 0x3ffbb978 A3 : 0x00000014 A4 : 0x3ffbb97c A5 : 0x3ffbb97c [23:05:23]A6 : 0x3ffebd9c A7 : 0x3ffebd9c A8 : 0x3ffedb14 A9 : 0x3ffde440 [23:05:23]A10 : 0x00000036 A11 : 0x3ffebd1c A12 : 0x3ffebd1c A13 : 0x00000000 [23:05:23]A14 : 0x00000000 A15 : 0x800d0000 SAR : 0x00000016 EXCCAUSE: 0x0000001c [23:05:23]EXCVADDR: 0x00000014 LBEG : 0x4000c46c LEND : 0x4000c477 LCOUNT : 0x00000000 [23:05:23] [23:05:23] [23:05:23]Backtrace: 0x400d90c3:0x3ffde490 0x400d9400:0x3ffde4c0 0x400d95fd:0x3ffde510 0x400d9612:0x3ffde530 0x400d8a9d:0x3ffde550 0x400d8aae:0x3ffde570 0x401a136d:0x3ffde590 0x401a13f5:0x3ffde5b0 0x400e4374:0x3ffde5d0 0x400e659e:0x3ffde600 0x400db6c2:0x3ffde620

Thanks for all the hard work put into this project!

kbouchard111 commented 1 year ago

To cover the bases I can, I've ran the steps at: https://thingpulse.com/esp32-how-to-use-psram/ to confirm that the board I'm using does have psram.

Though it doesn't validate that esphome is enabling it or detecting it.

resulting output from sketch: Showing logs: [00:22:20]E (129) esp_core_dump_flashrcore dump partition found! [00:22:20]E (129) esp_core_dump_flash: No core dump partition found! [00:22:20][ 4][D][esp32-hal-cpu.c:244] setCpuFrequencyMhz(): PLL: 480 / 2 = 240 Mhz, APB: 80000000 Hz [00:22:20][ 457][I][esp32-hal-psram.c:96] psramInit(): **PSRAM enabled** [00:22:20][ 464][D][psram_test_esp32.ino:4] setup(): Total heap: 338828 [00:22:20][ 465][D][psram_test_esp32.ino:5] setup(): Free heap: 315948 [00:22:20][ 465][D][psram_test_esp32.ino:6] setup(): **Total PSRAM: 4192123** [00:22:20][ 471][D][psram_test_esp32.ino:7] setup(): Free PSRAM: 4192123

alexbilevskiy commented 1 year ago

Suddenly came up with idea after 2 weeks of procrastination. Backtrace can be decoded, esphome even can do it itself when reading logs via serial.

[19:08:02]Backtrace: 0x400d7deb:0x3ffcc9b0 0x400d8109:0x3ffcc9e0 0x400d8325:0x3ffcca30 0x400d833a:0x3ffcca50 0x400d77c5:0x3ffcca70 0x400d77d6:0x3ffcca90 0x401a5369:0x3ffccab0 0x401a53f1:0x3ffccad0 0x400e477c:0x3ffccaf0 0x400e68c2:0x3ffccb20 0x400da3ea:0x3ffccb40
WARNING Found stack trace! Trying to decode it
WARNING Decoded 0x400d7deb: std::_Rb_tree<unsigned short, std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*>, std::_Select1st<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> >, std::less<unsigned short>, std::allocator<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> > >::_M_lower_bound(std::_Rb_tree_node<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> >*, std::_Rb_tree_node_base*, unsigned short const&) at c:\users\alex\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_tree.h:1895
 (inlined by) std::_Rb_tree<unsigned short, std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*>, std::_Select1st<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> >, std::less<unsigned short>, std::allocator<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> > >::lower_bound(unsigned short const&) at c:\users\alex\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_tree.h:1210
 (inlined by) std::map<unsigned short, esphome::ble_client_hid::GATTReadData*, std::less<unsigned short>, std::allocator<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> > >::lower_bound(unsigned short const&) at c:\users\alex\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_map.h:1239
 (inlined by) std::map<unsigned short, esphome::ble_client_hid::GATTReadData*, std::less<unsigned short>, std::allocator<std::pair<unsigned short const, esphome::ble_client_hid::GATTReadData*> > >::operator[](unsigned short const&) at c:\users\alex\.platformio\packages\toolchain-xtensa-esp32\xtensa-esp32-elf\include\c++\8.4.0\bits/stl_map.h:495
WARNING Decoded 0x400d8109: esphome::ble_client_hid::BLEClientHID::configure_hid_client() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/components/ble_client_hid/ble_client_hid.cpp:290
WARNING Decoded 0x400d8325: esphome::ble_client_hid::BLEClientHID::loop() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/components/ble_client_hid/ble_client_hid.cpp:21
 (inlined by) esphome::ble_client_hid::BLEClientHID::loop() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/components/ble_client_hid/ble_client_hid.cpp:14
WARNING Decoded 0x400d833a: non-virtual thunk to esphome::ble_client_hid::BLEClientHID::loop()
WARNING Decoded 0x400d77c5: esphome::ble_client::BLEClient::loop() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/components/ble_client/ble_client.cpp:23 (discriminator 2)
WARNING Decoded 0x400d77d6: non-virtual thunk to esphome::ble_client::BLEClient::loop()
WARNING Decoded 0x401a5369: esphome::Component::call_loop() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/core/component.cpp:76
WARNING Decoded 0x401a53f1: esphome::Component::call() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/core/component.cpp:98
WARNING Decoded 0x400e477c: esphome::Application::loop() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/core/application.cpp:74 (discriminator 2)
WARNING Decoded 0x400e68c2: loop() at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/main.cpp:303
WARNING Decoded 0x400da3ea: esphome::loop_task(void*) at C:\devel\esphome\.esphome\build\esp32-ble-remote/src/esphome/components/esp32/core.cpp:75 (discriminator 1)

most intriguing part is configure_hid_client() at .... ble_client_hid.cpp:290 https://github.com/fsievers22/esphome-ble-remote/blob/master/components/ble_client_hid/ble_client_hid.cpp#L290 Reading manufacturer? Well, do we really need it? A little bit of hardcode never hurts

    this->manufacturer =
        (const char *)"NO_MANUFACTURER";

fingers crossed esphome run Damn it, crashes again at line 295! What now? Serial number?? More hardcoded strings...

    this->serial_number =
        (const char *)"NO_SERIAL";

esphome run ....

It's alive!

[19:16:29][D][esp32_ble_client:048]: [0] [2B:80:3C:5A:A1:11] Found device
[19:16:29][D][esp32_ble_tracker:214]: Pausing scan to make connection...
[19:16:29][I][esp32_ble_client:064]: [0] [2B:80:3C:5A:A1:11] 0x00 Attempting BLE connection
[19:16:29][I][esp32_ble_client:265]: [0] [2B:80:3C:5A:A1:11] auth complete. remote BD_ADDR: 2b803c5aa111
[19:16:30][D][ble_client_hid:131]: GATT HID service found on device 2B:80:3C:5A:A1:11
[19:16:30][I][esp32_ble_client:196]: [0] [2B:80:3C:5A:A1:11] Connected
[19:16:30][D][ble_client_hid:145]: GATTC search finished with status code 0
[19:16:30][D][esp32_ble_tracker:246]: Starting scan...
[19:16:30][D][ble_client_hid:036]: Reading client characteristics
[19:16:30][W][ble_client_hid:239]: read_char failed
[19:16:30][W][ble_client_hid:239]: read_char failed
[19:16:30][D][ble_client_hid:070]: Found 6 characteristics
[19:16:30][D][ble_client_hid:300]: Parse HID Report Map
[19:16:30][D][hid_parser:041]: Report Map:
[19:16:30][D][hid_parser:060]: 5, C
[19:16:30][D][hid_parser:060]: 9, 1
.....
[19:16:31][D][ble_client_hid:184]: Received HID input report from handle 19
[19:16:31][D][hid_parser:350]: Parsing HID report with report ID (2)
[19:16:31][D][hid_parser:128]: get usage for index 1 with list size 4
[19:16:31][D][hid_parser:448]: HIDReportItemValue(usage_page: 12, usage: 234, value: 1)
[19:16:31][D][text_sensor:064]: 'Last Event Usage': Sending state 'Volume Decrement'

The end? Nah... Chinese button works fine but chromecast remote crashes on line 258. More hardcode, and google's remote also working:

    this->device_name =
        (const char *)"GOOGLE";

Seems like these strings are not exposed anywhere, so it's safe to hardcode.

p.s. For some reason battery level sensor does not work, but i guess it's completely different issue.

fsievers22 commented 1 year ago

Thank you very much for your contribution, I have tried to fix the bug with the help of your findings in the dev-branch, without hardcoding. It would be great if you could test if that fix is working for you.

kbouchard111 commented 1 year ago

Thank you very much for your contribution, I have tried to fix the bug with the help of your findings in the dev-branch, without hardcoding. It would be great if you could test if that fix is working for you.

Great job!!! I just tried it using source: github://fsievers22/esphome-ble-remote@dev and its no longer panic'ng and its now working. I've tested it with a esp32-wrover-e board (has 8mb of psram) as well as a esp-wroom-32 without psram. Both are working. Though I can't say if the lack of psram will cause long term stability issues, either way looks like the change you implemented on dev is good.

alexbilevskiy commented 1 year ago

@fsievers22 thanks! Its now working with shutter button, but still crashing with the chromecast remote:

esphome::ble_client_hid::BLEClientHID::parse_characteristic_data(esphome::esp32_ble_client::BLEService*, unsigned short) at components/ble_client_hid/ble_client_hid.cpp:250
esphome::ble_client_hid::BLEClientHID::configure_hid_client() at components/ble_client_hid/ble_client_hid.cpp:265
esphome::ble_client_hid::BLEClientHID::loop() at components/ble_client_hid/ble_client_hid.cpp:21
fsievers22 commented 1 year ago

I have just pushed another commit that hopefully fixes it for the chromecast remote aswell.

alexbilevskiy commented 1 year ago

Yep, now everything's fine! Many thanks