esp32-ble2mqtt: Restarts every 5 minutes and eventually becomes unresponsive.

Love this project! After trying and failing to build something custom for my use case (controlling a BLE motorised blind) I was very excited to find this project (and very grateful for your work).

After getting everything configured, built and flashed it worked great! Unfortunately, though, it only seems to work great for a short while, then either one of two things happen:

  1. The ESP32 restarts. Or at least the firmware restarts as I can see the history of Uptime values never seem to get above 360 (6 minutes).
  2. It becomes completely unresponsive.

I used remote logging to capture a few of these lock ups and in each case I see a very similar pattern. The log below shows a complete history from initial connection to lock-up:

2021-02-01 20:43:58.959820 (BLE2MQTT-AAB8.lan): I (8991) BLE2MQTT: Connected to the network, connecting to MQTT
2021-02-01 20:43:59.891463 (BLE2MQTT-AAB8.lan): I (9001) MQTT: Connecting MQTT client
2021-02-01 20:43:59.893458 (BLE2MQTT-AAB8.lan): I (9001) system_api: Base MAC address is not set, read default base MAC address from BLK0 of EFUSE
2021-02-01 20:43:59.902436 (BLE2MQTT-AAB8.lan): I (9941) BLE2MQTT: Discovered BLE device: 2d:74:aa:f2:6c:a2 (RSSI: -68), not connecting
2021-02-01 20:44:00.109021 (BLE2MQTT-AAB8.lan): I (10501) BLE2MQTT: Discovered BLE device: de:66:92:69:03:8c 
(RSSI: -79), connecting
2021-02-01 20:44:00.222717 (BLE2MQTT-AAB8.lan): W (10611) BT_APPL: bta_gattc_conn_cback() - cif=1 connected=0 conn_id=1 reason=0x003e
2021-02-01 20:44:00.290536 (BLE2MQTT-AAB8.lan): E (10621) BLE: Open failed, status = 0x85
2021-02-01 20:44:00.291534 (BLE2MQTT-AAB8.lan): I (10641) BLE2MQTT: Discovered BLE device: de:66:92:69:03:8c 
(RSSI: -78), connecting
2021-02-01 20:44:00.295523 (BLE2MQTT-AAB8.lan): I (10641) BLE2MQTT: Discovered BLE device: 23:b7:51:3d:dd:aa 
(RSSI: -81), not connecting
2021-02-01 20:44:00.388714 (BLE2MQTT-AAB8.lan): W (10751) BT_APPL: bta_gattc_conn_cback() - cif=1 connected=0 conn_id=1 reason=0x003e
2021-02-01 20:44:00.389712 (BLE2MQTT-AAB8.lan): E (10751) BLE: Open failed, status = 0x85
2021-02-01 20:44:00.708331 (BLE2MQTT-AAB8.lan): I (11091) BLE2MQTT: Discovered BLE device: de:66:92:69:03:8c 
(RSSI: -85), connecting
2021-02-01 20:44:00.923229 (BLE2MQTT-AAB8.lan): W (11261) BT_APPL: bta_gattc_conn_cback() - cif=1 connected=0 conn_id=1 reason=0x003e
2021-02-01 20:44:00.923229 (BLE2MQTT-AAB8.lan): E (11261) BLE: Open failed, status = 0x85
2021-02-01 20:44:00.923229 (BLE2MQTT-AAB8.lan): I (11281) BLE2MQTT: Discovered BLE device: 6a:97:25:03:7a:4c 
(RSSI: -85), not connecting
2021-02-01 20:44:00.933204 (BLE2MQTT-AAB8.lan): I (11291) BLE2MQTT: Discovered BLE device: 56:12:c5:68:3f:ac 
(RSSI: -64), not connecting
2021-02-01 20:44:01.241871 (BLE2MQTT-AAB8.lan): I (11601) BLE2MQTT: Discovered BLE device: de:66:92:69:03:8c 
(RSSI: -82), connecting
2021-02-01 20:44:01.898856 (BLE2MQTT-AAB8.lan): I (12211) BLE2MQTT: Discovered BLE device: 70:73:cb:ea:eb:bb 
(RSSI: -86), not connecting
2021-02-01 20:44:02.398413 (BLE2MQTT-AAB8.lan): I (12771) BLE2MQTT: Discovered BLE device: 56:36:66:89:28:76 
(RSSI: -90), not connecting
2021-02-01 20:44:03.316879 (BLE2MQTT-AAB8.lan): I (13571) BLE2MQTT: Discovered BLE device: 63:57:cd:c3:9a:d3 
(RSSI: -91), not connecting
2021-02-01 20:44:03.317877 (BLE2MQTT-AAB8.lan): I (13651) BLE2MQTT: Discovered BLE device: 40:40:40:12:80:b2 
(RSSI: -84), not connecting
2021-02-01 20:44:04.158517 (BLE2MQTT-AAB8.lan): I (14451) BLE2MQTT: Discovered BLE device: 73:c0:c5:d9:0a:07 
(RSSI: -78), not connecting
2021-02-01 20:44:09.169852 (BLE2MQTT-AAB8.lan): I (19501) BLE2MQTT: Connected to device: de:66:92:69:03:8c, scanning
2021-02-01 20:44:09.333787 (BLE2MQTT-AAB8.lan): E (19701) BT_APPL: service change write ccc failed
2021-02-01 20:44:11.916087 (BLE2MQTT-AAB8.lan): I (22151) BLE2MQTT: Publishing: de:66:92:69:03:8c/GenericAccess/DeviceName = S
2021-02-01 20:44:12.168417 (BLE2MQTT-AAB8.lan): I (22511) BLE2MQTT: Publishing: de:66:92:69:03:8c/GenericAccess/Appearance = 0
2021-02-01 20:44:12.301480 (BLE2MQTT-AAB8.lan): I (22631) BLE2MQTT: Publishing: de:66:92:69:03:8c/GenericAccess/PeripheralPreferredConnectionParameters = 16,32,0,80
2021-02-01 20:44:12.628205 (BLE2MQTT-AAB8.lan): I (22991) BLE2MQTT: Publishing: de:66:92:69:03:8c/DeviceInformation/ManufacturerNameString = WazombiLabs
2021-02-01 20:44:12.956356 (BLE2MQTT-AAB8.lan): I (23311) BLE2MQTT: Publishing: de:66:92:69:03:8c/DeviceInformation/SerialNumberString = R-0103-kristjan-202010151321-202c1e9-6.1
2021-02-01 20:44:13.191649 (BLE2MQTT-AAB8.lan): I (23471) BLE2MQTT: Publishing: de:66:92:69:03:8c/DeviceInformation/HardwareRevisionString = BLINDY_V9
2021-02-01 20:44:14.047338 (BLE2MQTT-AAB8.lan): I (23631) BLE2MQTT: Publishing: de:66:92:69:03:8c/DeviceInformation/FirmwareRevisionString = 5baefa6
2021-02-01 20:44:14.047338 (BLE2MQTT-AAB8.lan): I (23751) BLE2MQTT: Publishing: de:66:92:69:03:8c/DeviceInformation/SoftwareRevisionString = v2.2.3
2021-02-01 20:44:14.048336 (BLE2MQTT-AAB8.lan): I (23871) BLE2MQTT: Publishing: de:66:92:69:03:8c/BatteryService/BatteryLevel = 66
2021-02-01 20:44:14.048336 (BLE2MQTT-AAB8.lan): I (24191) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001554-b87f-490c-92cb-11ba5ea5167c/00001555-b87f-490c-92cb-11ba5ea5167c = 29,104,24,96
2021-02-01 20:44:14.342958 (BLE2MQTT-AAB8.lan): I (24691) BLE2MQTT: Discovered BLE device: 1c:40:31:7d:d6:96 
(RSSI: -87), not connecting
2021-02-01 20:44:14.449847 (BLE2MQTT-AAB8.lan): I (24751) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001525-b87f-490c-92cb-11ba5ea5167c = 100,1,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2021-02-01 20:44:14.870529 (BLE2MQTT-AAB8.lan): I (25071) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001526-b87f-490c-92cb-11ba5ea5167c = 100
2021-02-01 20:44:14.877077 (BLE2MQTT-AAB8.lan): I (25271) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001527-b87f-490c-92cb-11ba5ea5167c = 51,1,0,55,55,55,55,55,55,55,55,55,55,55,55,55,55
2021-02-01 20:44:15.218825 (BLE2MQTT-AAB8.lan): I (25391) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001528-b87f-490c-92cb-11ba5ea5167c = 48,51,1,0,64,56,0,0,127,100,129,0,0,0,0,50,0,0
2021-02-01 20:44:15.350292 (BLE2MQTT-AAB8.lan): I (25711) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001529-b87f-490c-92cb-11ba5ea5167c = 169
2021-02-01 20:44:16.134915 (BLE2MQTT-AAB8.lan): I (25991) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001530-b87f-490c-92cb-11ba5ea5167c = 0
2021-02-01 20:44:16.135466 (BLE2MQTT-AAB8.lan): I (26111) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001531-b87f-490c-92cb-11ba5ea5167c = 0
2021-02-01 20:44:16.135972 (BLE2MQTT-AAB8.lan): I (26311) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/00001533-b87f-490c-92cb-11ba5ea5167c = 0
2021-02-01 20:44:16.135972 (BLE2MQTT-AAB8.lan): I (26431) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/0000ba71-b87f-490c-92cb-11ba5ea5167c = 144,1
2021-02-01 20:44:16.585717 (BLE2MQTT-AAB8.lan): I (26711) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001861-b87f-490c-92cb-11ba5ea5167c/0000ba72-b87f-490c-92cb-11ba5ea5167c = 0
2021-02-01 20:44:16.930712 (BLE2MQTT-AAB8.lan): I (27031) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001890-b87f-490c-92cb-11ba5ea5167c/00001891-b87f-490c-92cb-11ba5ea5167c = 177
2021-02-01 20:44:16.935695 (BLE2MQTT-AAB8.lan): I (27271) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001890-b87f-490c-92cb-11ba5ea5167c/00001892-b87f-490c-92cb-11ba5ea5167c = 77,97,115,116,101,114,32,66,101,100,114,111,111,109,48,0
2021-02-01 20:44:17.199531 (BLE2MQTT-AAB8.lan): I (27471) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001890-b87f-490c-92cb-11ba5ea5167c/00001893-b87f-490c-92cb-11ba5ea5167c = 0,0,0,0,0,0,0,0,0,0,0,0,0,0,0,0
2021-02-01 20:44:17.365005 (BLE2MQTT-AAB8.lan): I (27711) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001890-b87f-490c-92cb-11ba5ea5167c/00001894-b87f-490c-92cb-11ba5ea5167c = 0,0,0,0
2021-02-01 20:44:17.825591 (BLE2MQTT-AAB8.lan): I (28071) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001890-b87f-490c-92cb-11ba5ea5167c/00001895-b87f-490c-92cb-11ba5ea5167c = 68,69,45,54,54,45,57,50,45,54,57,45,48,51,45,56,67
2021-02-01 20:44:17.962773 (BLE2MQTT-AAB8.lan): I (28271) BLE2MQTT: Publishing: de:66:92:69:03:8c/00001890-b87f-490c-92cb-11ba5ea5167c/00001896-b87f-490c-92cb-11ba5ea5167c = 4,0,0,0,76,175,22,3,103,62,0,0,0,60,0,0,0,0,0,0
2021-02-01 20:44:18.420791 (BLE2MQTT-AAB8.lan): I (28771) BLE2MQTT: Discovered BLE device: 6a:4a:fa:7a:2f:49 
(RSSI: -99), not connecting
2021-02-01 20:44:23.949993 (BLE2MQTT-AAB8.lan): I (34291) BLE2MQTT: Discovered BLE device: 5d:53:0d:aa:af:63 
(RSSI: -91), not connecting
2021-02-01 20:45:16.891550 (BLE2MQTT-AAB8.lan): I (87251) BLE2MQTT: Discovered BLE device: d3:07:42:2d:15:67 
(RSSI: -70), not connecting
2021-02-01 20:46:00.632061 (BLE2MQTT-AAB8.lan): I (131021) BLE2MQTT: Discovered BLE device: 09:88:72:89:cc:a6 (RSSI: -71), not connecting
2021-02-01 20:46:04.516954 (BLE2MQTT-AAB8.lan): I (134851) BLE2MQTT: Discovered BLE device: 5a:0b:7e:0d:06:ed (RSSI: -70), not connecting
2021-02-01 20:48:00.830524 (BLE2MQTT-AAB8.lan): W (251151) BT_APPL: bta_gattc_conn_cback() - cif=1 connected=0 conn_id=1 reason=0x003b
2021-02-01 20:48:00.830524 (BLE2MQTT-AAB8.lan): I (251161) BLE: Connection closed, reason = 0x3b
2021-02-01 20:48:00.830524 (BLE2MQTT-AAB8.lan): I (251161) BLE2MQTT: Disconnected from device: de:66:92:69:03:8c
2021-02-01 20:48:01.135219 (BLE2MQTT-AAB8.lan): I (251501) BLE2MQTT: Discovered BLE device: de:66:92:69:03:8c (RSSI: -80), connecting
2021-02-01 20:48:01.241934 (BLE2MQTT-AAB8.lan): W (251621) BT_APPL: bta_gattc_conn_cback() - cif=1 connected=0 conn_id=1 reason=0x003e
2021-02-01 20:48:01.241934 (BLE2MQTT-AAB8.lan): E (251621) BLE: Open failed, status = 0x85
2021-02-01 20:48:01.258888 (BLE2MQTT-AAB8.lan): I (251641) BLE2MQTT: Discovered BLE device: de:66:92:69:03:8c (RSSI: -81), connecting
2021-02-01 20:48:03.595035 (BLE2MQTT-AAB8.lan): I (253951) BLE2MQTT: Discovered BLE device: 7b:8e:67:36:e1:7e (RSSI: -85), not connecting
2021-02-01 20:48:06.176960 (BLE2MQTT-AAB8.lan): I (256501) BLE2MQTT: Connected to device: de:66:92:69:03:8c, 
scanning
2021-02-01 20:48:06.884011 (BLE2MQTT-AAB8.lan): I (257221) BLE2MQTT: Publishing: de:66:92:69:03:8c/GenericAccess/DeviceName = S
2021-02-01 20:48:06.975766 (BLE2MQTT-AAB8.lan): I (257341) BLE2MQTT: Publishing: de:66:92:69:03:8c/GenericAccess/Appearance = 0
2021-02-01 20:48:07.121514 (BLE2MQTT-AAB8.lan): I (257501) BLE2MQTT: Publishing: de:66:92:69:03:8c/GenericAccess/PeripheralPreferredConnectionParameters = 16,32,0,80
2021-02-01 20:48:07.283083 (BLE2MQTT-AAB8.lan): E (257631) BT_APPL: service change write ccc failed
2021-02-01 20:48:07.283083 (BLE2MQTT-AAB8.lan): E (257641) BT_GATT: GATTC_Discover GATT_BUSY conn_id = 1
2021-02-01 20:48:07.285077 (BLE2MQTT-AAB8.lan): E (257641) BT_APPL: discovery on server failed
2021-02-01 20:48:07.295051 (BLE2MQTT-AAB8.lan): E (257641) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.295051 (BLE2MQTT-AAB8.lan): E (257641) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.296049 (BLE2MQTT-AAB8.lan): E (257651) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.296049 (BLE2MQTT-AAB8.lan): E (257661) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.296049 (BLE2MQTT-AAB8.lan): E (257661) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.296049 (BLE2MQTT-AAB8.lan): E (257671) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.297046 (BLE2MQTT-AAB8.lan): E (257671) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.297046 (BLE2MQTT-AAB8.lan): E (257681) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.303029 (BLE2MQTT-AAB8.lan): E (257681) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.306025 (BLE2MQTT-AAB8.lan): E (257691) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.314998 (BLE2MQTT-AAB8.lan): E (257701) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.317990 (BLE2MQTT-AAB8.lan): E (257701) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1
2021-02-01 20:48:07.323974 (BLE2MQTT-AAB8.lan): E (257711) BT_GATT: GATTC_Read GATT_BUSY conn_id = 1

This log starts after one of the restarts I mentioned. If I look at the log entries immediately above this I see the same pattern. So I believe it’s the same problem each time only some of the time it’s able to recover by itself and some of the time it isn’t.

For reference, this is my config:

{
  "wifi": {
    "ssid": "MySSID",
    "password": "MyPassword"
  },
  "mqtt": {
    "server": {
      "host": "MyHost",
      "port": 1883
    },
    "publish": {
      "retain": true
    }
  },
  "ble": {
    "whitelist": ["de:66:92:69:03:8c"]
  },
  "log": {
    "host": "MyOtherHost",
    "port": 5000
  }
}

Built using ESP IDF 4.1.1.

Any input would be appreciated.

About this issue

  • Original URL
  • State: open
  • Created 3 years ago
  • Comments: 17 (7 by maintainers)

Most upvoted comments

Hi,

Sorry for taking so long to get back to this issue. I will now be actively working on this for at least a while so I updated the SDK to the latest (ESP-IDF v4.3.1) and got the latest version of this project as well. I have whitelisted only one Shade and it still seems to fail exactly like before.

My application will actually require the ESP to only open the BLE connection intermittently every time a read is requested. So at some point I will have to fork and modify this code a lot to do exactly what I need. But for now I think I can also work on this issue with no changes to the code. I can see this crash happen pretty much randomly and it always seems to happen when doing the initial read of all the characteristics. I haven’t seen this happen when I call the reads one by one later. I have a feeling that once I drop the initial read of all values and stop keeping the connection open this issue will disappear for me but the underlying problem will most likely remain in the code.

crash_1.log

+1
ratsept on Oct 11, 2021
Read more comments on GitHub
← zipline-trader: ERROR: Command errored out with exit status 1
BitVision: No information in UI is shown after installation and start, VERSION is not defined error →