Switchbot meter broadcasters

rlarranaga commented 2 years ago

Question How do i get the Switchbot meter device to get discovered properly by esp32-ble-mqtt?

Additional context I have 3 switchbot meter devices. These devices are broadcasters that report temperature and Humidity. They get discovered by esp32-ble-mqtt:

 (7188) BLE2MQTT: Discovered BLE device: df:06:40:1a:4d:fe (RSSI: -79), connecting
lld_pdu_get_tx_flush_nb HCI packet count mismatch (0, 1)
W (11278) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
I (22048) BLE2MQTT: Discovered BLE device: 5a:0a:3b:3a:c4:ca (RSSI: -89), not connecting
I (22248) BLE2MQTT: Connected to device: df:06:40:1a:4d:fe, scanning
I (22908) BLE2MQTT: Publishing: df:06:40:1a:4d:fe/GenericAccess/DeviceName = WoSensorTH
I (22958) BLE2MQTT: Publishing: df:06:40:1a:4d:fe/GenericAccess/Appearance = 768
I (23008) BLE2MQTT: Publishing: df:06:40:1a:4d:fe/GenericAccess/PeripheralPreferredConnectionParameters = 0,0,0,0
I (23058) BLE2MQTT: Publishing: df:06:40:1a:4d:fe/GenericAccess/CentralAddressResolution = 0

However, they are being discovered with no services.

If i scan and connect to the devices through nrfconnect, i see the following:

Shouldn't service cba20d00-224d-11e6-9fb8-0002a5d5c51b and its characteristics be automatically discovered?

If there is any technical information that needs to be provided for this device to be detected properly, i would be happy to get some captures. Additionally, I believe there is information about these devices in the theengs github project, specifically here:

https://github.com/theengs/decoder/blob/development/src/devices/SBMT_json.h

Thanks!

shmuelzon commented 2 years ago

Hey, all the services and characteristics should be detected and published when connecting to the device and I agree the list above seems a bit short. Just to be sure, are you sure the missing ones are "regular" GATT services and not something that's broadcasted without a connection? Have you whitelisted or blacklisted any services and/or characteristics in your configuration file? Can you post it here (after removing any sensitive information)? Perhaps we discover the services but, for some reason, don't get the values for them when trying to read them? Can you enable debug logs and try again? Maybe we'll see something of interest there. Thanks

rlarranaga commented 2 years ago

Hello @shmuelzon , answers below:

Just to be sure, are you sure the missing ones are "regular" GATT services and not something that's broadcasted without a connection?

They look like regular GATT services to me, but i am not sure. How can i check?

Have you whitelisted or blacklisted any services and/or characteristics in your configuration file? Can you post it here (after removing any sensitive information)?

No, only devices, see full config below:

{
  "network": {
    "wifi": {
      "ssid": "XXX",
      "password": "XXX"
    }
  },
  "mqtt": {
    "server": {
      "host": "XXX",
      "username": "XXX",
      "password": "XXX",
      "port": 1883
    },
    "publish": {
      "retain": true
    }
  },
  "ble": {
    "whitelist": ["xx:xx:xx:xx:xx:xx","xx:xx:xx:xx:xx:xx","xx:xx:xx:xx:xx:xx","df:06:40:1a:4d:fe","xx:xx:xx:xx:xx:xx"]
  },
  "log": {
    "host": "XXX",
    "port": 5000
  }
}

Can you enable debug logs and try again? Maybe we'll see something of interest there.

I have enabled debug logs, but i encountered I run into a stack overflow issue when enabled, and the device resets. In any case, here an extract of the logs, from the moment one of the devices is detected to the moment the device overflows.

I (36280) BLE2MQTT: Discovered BLE device: df:06:40:1a:4d:fe (RSSI: -80), connecting
D (36290) BLE: Enqueue: type: 0, device: df:06:40:1a:4d:fe, char: 00000000-0000-0000-0000-000000000000, len: 0, val: 0x0
D (36600) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (36800) BLE: Queue timer expired
D (36800) BLE: Dequeue: type: 0, device: df:06:40:1a:4d:fe, char: 00000000-0000-0000-0000-000000000000, len: 0, val: 0x0
D (36810) BLE: Received GAP event 18 (ESP_GAP_BLE_SCAN_STOP_COMPLETE_EVT)
D (42350) BLE: Received GATTC event 40 (ESP_GATTC_CONNECT_EVT), gattc_if 1
D (42350) BLE: GATTC event 40 wasn't handled
D (42360) BLE: Received GATTC event 2 (ESP_GATTC_OPEN_EVT), gattc_if 1
D (42370) BLE: Received GAP event 7 (ESP_GAP_BLE_SCAN_START_COMPLETE_EVT)
D (43210) BLE: Received GATTC event 46 (Invalid GATTC event), gattc_if 1
D (43220) BLE: GATTC event 46 wasn't handled
D (43260) BLE: Received GATTC event 18 (ESP_GATTC_CFG_MTU_EVT), gattc_if 1
D (43260) BLE2MQTT: Queuing event BLE_DEVICE_CONNECTED (df:06:40:1a:4d:fe)
I (43260) BLE2MQTT: Connected to device: df:06:40:1a:4d:fe, scanning
D (43280) MQTT: Subscribing to df:06:40:1a:4d:fe/Connected
D (43280) MQTT_CLIENT: mqtt_enqueue id: 63993, type=8 successful
D (43280) OUTBOX: ENQUEUE msgid=63993, msg_type=8, len=34, size=34
D (43290) MQTT_CLIENT: Sent subscribe topic=df:06:40:1a:4d:fe/Connected, id: 63993, type=8 successful
D (43300) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (43310) BLE: GATTC event 7 wasn't handled
D (43310) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (43320) BLE: GATTC event 7 wasn't handled
D (43320) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (43330) BLE: GATTC event 7 wasn't handled
D (43330) BLE: Received GATTC event 6 (ESP_GATTC_SEARCH_CMPL_EVT), gattc_if 1
D (43340) BLE2MQTT: Queuing event BLE_DEVICE_SERVICES_DISCOVERED (df:06:40:1a:4d:fe)
D (43350) BLE2MQTT: Services discovered on device: df:06:40:1a:4d:fe
D (43360) BLE2MQTT: Found new characteristic: service: 00001801-0000-1000-8000-00805f9b34fb, characteristic: 00002a05-0000-1000-8000-00805f9b34fb, properties: 0x20
D (43370) BLE: Enqueue: type: 4, device: df:06:40:1a:4d:fe, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3fff07a4
D (43370) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (43380) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a00-0000-1000-8000-00805f9b34fb, properties: 0x2
D (43400) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (43400) MQTT: Subscribing to df:06:40:1a:4d:fe/GenericAccess/DeviceName/Get
D (43410) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (43420) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (43430) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (43440) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (43440) MQTT_CLIENT: msg_type=9, msg_id=63993
D (43450) MQTT_CLIENT: pending_id=63993, pending_msg_count = 1
D (43450) OUTBOX: DELETED msgid=63993, msg_type=8, remain size=0
D (43460) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (43470) MQTT_CLIENT: mqtt_enqueue id: 30120, type=8 successful
D (43470) OUTBOX: ENQUEUE msgid=30120, msg_type=8, len=53, size=53
D (43480) MQTT_CLIENT: Sent subscribe topic=df:06:40:1a:4d:fe/GenericAccess/DeviceName/Get, id: 30120, type=8 successful
D (43490) BLE: Enqueue: type: 1, device: df:06:40:1a:4d:fe, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (43490) MQTT_CLIENT: mqtt_message_receive: first byte: 0x31
D (43500) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a01-0000-1000-8000-00805f9b34fb, properties: 0x2
D (43510) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x21
D (43530) MQTT: Subscribing to df:06:40:1a:4d:fe/GenericAccess/Appearance/Get
D (43530) MQTT_CLIENT: mqtt_message_receive: total message length: 35 (already read: 2)
D (43550) MQTT_CLIENT: mqtt_message_receive: read_len=33
D (43550) MQTT_CLIENT: mqtt_message_receive: transport_read():35 35
D (43560) MQTT_CLIENT: msg_type=3, msg_id=0
D (43560) MQTT_CLIENT: deliver_publish, message_length_read=35, message_length=35
D (43570) MQTT_CLIENT: deliver_publish: msg_topic_len=27
D (43570) MQTT_CLIENT: Get data len= 4, topic len=27, total_data: 4 offset: 0
D (43580) MQTT: Received: df:06:40:1a:4d:fe/Connected => true (4)
D (43590) BLE2MQTT: Queuing event MQTT message 14 (df:06:40:1a:4d:fe/Connected, 0x3ffed0f7, 4, 0x3fff0c18)
D (43600) MQTT_CLIENT: mqtt_enqueue id: 2349, type=8 successful
D (43600) OUTBOX: ENQUEUE msgid=2349, msg_type=8, len=53, size=106
D (43610) MQTT_CLIENT: Sent subscribe topic=df:06:40:1a:4d:fe/GenericAccess/Appearance/Get, id: 2349, type=8 successful
D (43620) BLE: Enqueue: type: 1, device: df:06:40:1a:4d:fe, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (43620) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (43630) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a04-0000-1000-8000-00805f9b34fb, properties: 0x2
D (43640) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (43660) MQTT: Subscribing to df:06:40:1a:4d:fe/GenericAccess/PeripheralPreferredConnectionParameters/Get
D (43660) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (43660) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (43690) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (43690) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (43690) MQTT_CLIENT: msg_type=9, msg_id=30120
D (43700) MQTT_CLIENT: pending_id=2349, pending_msg_count = 2
D (43700) OUTBOX: DELETED msgid=30120, msg_type=8, remain size=53
D (43710) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (43720) MQTT_CLIENT: mqtt_enqueue id: 57937, type=8 successful
D (43720) OUTBOX: ENQUEUE msgid=57937, msg_type=8, len=82, size=135
D (43730) MQTT_CLIENT: Sent subscribe topic=df:06:40:1a:4d:fe/GenericAccess/PeripheralPreferredConnectionParameters/Get, id: 57937, type=8 successful
D (43740) BLE: Enqueue: type: 1, device: df:06:40:1a:4d:fe, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (43750) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (43750) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002aa6-0000-1000-8000-00805f9b34fb, properties: 0x2
D (43760) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (43780) MQTT: Subscribing to df:06:40:1a:4d:fe/GenericAccess/CentralAddressResolution/Get
D (43780) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (43800) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (43800) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (43810) MQTT_CLIENT: msg_type=9, msg_id=2349
D (43810) MQTT_CLIENT: pending_id=57937, pending_msg_count = 2
D (43820) OUTBOX: DELETED msgid=2349, msg_type=8, remain size=82
D (43830) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (43830) MQTT_CLIENT: mqtt_enqueue id: 30200, type=8 successful
D (43840) OUTBOX: ENQUEUE msgid=30200, msg_type=8, len=67, size=149
D (43850) MQTT_CLIENT: Sent subscribe topic=df:06:40:1a:4d:fe/GenericAccess/CentralAddressResolution/Get, id: 30200, type=8 successful
D (43860) BLE: Enqueue: type: 1, device: df:06:40:1a:4d:fe, char: 00002aa6-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (43870) BLE2MQTT: Found new characteristic: service: cba20d00-224d-11e6-9fb8-0002a5d5c51b, characteristic: cba20002-224d-11e6-9fb8-0002a5d5c51b, properties: 0xc
D (43880) MQTT: Subscribing to df:06:40:1a:4d:fe/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set
D (43890) MQTT_CLIENT: mqtt_enqueue id: 12615, type=8 successful
D (43900) OUTBOX: ENQUEUE msgid=12615, msg_type=8, len=102, size=251
D (43910) MQTT_CLIENT: Sent subscribe topic=df:06:40:1a:4d:fe/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set, id: 12615, type=8 successful
D (43920) BLE2MQTT: Found new characteristic: service: cba20d00-224d-11e6-9fb8-0002a5d5c51b, characteristic: cba20003-224d-11e6-9fb8-0002a5d5c51b, properties: 0x10
D (43920) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (43940) BLE: Enqueue: type: 4, device: df:06:40:1a:4d:fe, char: cba20003-224d-11e6-9fb8-0002a5d5c51b, len: 2, val: 0x3fff0e60
D (43940) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (43960) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (43960) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (43970) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (43990) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (43990) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (43990) MQTT_CLIENT: msg_type=9, msg_id=57937
D (44000) MQTT_CLIENT: pending_id=12615, pending_msg_count = 3
D (44010) OUTBOX: DELETED msgid=57937, msg_type=8, remain size=169
D (44010) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (44020) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (44030) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (44030) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (44040) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (44050) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (44050) MQTT_CLIENT: msg_type=9, msg_id=30200
D (44060) MQTT_CLIENT: pending_id=12615, pending_msg_count = 2
D (44060) OUTBOX: DELETED msgid=30200, msg_type=8, remain size=102
D (44070) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (44080) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (44080) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (44090) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (44100) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (44100) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (44110) MQTT_CLIENT: msg_type=9, msg_id=12615
D (44110) MQTT_CLIENT: pending_id=12615, pending_msg_count = 1
D (44120) OUTBOX: DELETED msgid=12615, msg_type=8, remain size=0
D (44120) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (44380) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (44380) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (44450) BLE: Queue timer expired
D (44450) BLE: Dequeue: type: 4, device: df:06:40:1a:4d:fe, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3fff07a4
D (44460) BLE: Dequeue: type: 1, device: df:06:40:1a:4d:fe, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
***ERROR*** A stack overflow in task Tmr Svc has been detected.
Backtrace:0x40081bfa:0x3ffcf7500x4009051d:0x3ffcf770 0x40093b06:0x3ffcf790 0x4009200d:0x3ffcf810 0x40090618:0x3ffcf840 0x400905ca:0x3f40ebc8  |<-CORRUPTED
0x40081bfa: panic_abort at /home/ricardol/esp/esp-idf/components/esp_system/panic.c:402
0x4009051d: esp_system_abort at /home/ricardol/esp/esp-idf/components/esp_system/esp_system.c:128
0x40093b06: vApplicationStackOverflowHook at /home/ricardol/esp/esp-idf/components/freertos/port/xtensa/port.c:394
0x4009200d: vTaskSwitchContext at /home/ricardol/esp/esp-idf/components/freertos/tasks.c:3505
0x40090618: _frxt_dispatch at /home/ricardol/esp/esp-idf/components/freertos/port/xtensa/portasm.S:436
0x400905ca: _frxt_int_exit at /home/ricardol/esp/esp-idf/components/freertos/port/xtensa/portasm.S:231

Thanks

rlarranaga commented 2 years ago

I actually managed to overcome the stack overflow issue by disabling remote logging. I can see the characteristics being detected by esp32-ble-mqtt below (Device is e4:65:06:ad:a1:ab) I do not see the characteristics in mqtt explorer though....

D (8470) MQTT_CLIENT: Sending MQTT CONNECT message, type: 1, id: 0000
D (8510) MQTT_CLIENT: mqtt_message_receive: first byte: 0x20
D (8510) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (8510) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (8520) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (8530) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (8530) MQTT_CLIENT: Connected
I (8530) MQTT: MQTT client connected
D (8540) BLE2MQTT: Queuing event MQTT_CONNECTED
I (8540) BLE2MQTT: Connected to MQTT, scanning for BLE devices
D (8560) MQTT: Subscribing to BLE2MQTT-B790/OTA/Firmware
D (8560) MQTT_CLIENT: mqtt_enqueue id: 58086, type=8 successful
D (8560) OUTBOX: ENQUEUE msgid=58086, msg_type=8, len=33, size=33
D (8570) MQTT_CLIENT: Sent subscribe topic=BLE2MQTT-B790/OTA/Firmware, id: 58086, type=8 successful
D (8580) MQTT: Subscribing to BLE2MQTT/OTA/Firmware
D (8580) MQTT_CLIENT: mqtt_enqueue id: 64186, type=8 successful
D (8590) OUTBOX: ENQUEUE msgid=64186, msg_type=8, len=28, size=61
D (8590) MQTT_CLIENT: Sent subscribe topic=BLE2MQTT/OTA/Firmware, id: 64186, type=8 successful
D (8600) MQTT: Subscribing to BLE2MQTT-B790/OTA/Config
D (8610) MQTT_CLIENT: mqtt_enqueue id: 47191, type=8 successful
D (8610) OUTBOX: ENQUEUE msgid=47191, msg_type=8, len=31, size=92
D (8620) MQTT_CLIENT: Sent subscribe topic=BLE2MQTT-B790/OTA/Config, id: 47191, type=8 successful
D (8630) MQTT: Subscribing to BLE2MQTT/OTA/Config
D (8630) MQTT_CLIENT: mqtt_enqueue id: 7788, type=8 successful
D (8640) OUTBOX: ENQUEUE msgid=7788, msg_type=8, len=26, size=118
D (8650) MQTT_CLIENT: Sent subscribe topic=BLE2MQTT/OTA/Config, id: 7788, type=8 successful
D (8650) MQTT: Subscribing to BLE2MQTT-B790/Restart
D (8660) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (8670) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (8670) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (8680) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (8680) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (8690) MQTT_CLIENT: msg_type=9, msg_id=58086
D (8700) MQTT_CLIENT: pending_id=7788, pending_msg_count = 4
D (8700) OUTBOX: DELETED msgid=58086, msg_type=8, remain size=85
D (8710) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (8710) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffd3354
D (8720) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (8730) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (8730) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (8740) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (8750) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (8750) MQTT_CLIENT: msg_type=9, msg_id=64186
D (8760) MQTT_CLIENT: pending_id=7788, pending_msg_count = 3
D (8760) OUTBOX: DELETED msgid=64186, msg_type=8, remain size=57
D (8770) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (8780) MQTT_CLIENT: mqtt_enqueue id: 22564, type=8 successful
D (8780) OUTBOX: ENQUEUE msgid=22564, msg_type=8, len=28, size=85
D (8790) MQTT_CLIENT: Sent subscribe topic=BLE2MQTT-B790/Restart, id: 22564, type=8 successful
D (8800) MQTT: Subscribing to BLE2MQTT/Restart
D (8800) MQTT_CLIENT: mqtt_enqueue id: 195, type=8 successful
D (8810) OUTBOX: ENQUEUE msgid=195, msg_type=8, len=23, size=108
D (8820) MQTT_CLIENT: Sent subscribe topic=BLE2MQTT/Restart, id: 195, type=8 successful
D (8820) BLE: Starting BLE scan
D (8830) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (8830) BLE: Received GAP event 7 (ESP_GAP_BLE_SCAN_START_COMPLETE_EVT)
D (8830) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (8840) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (8850) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (8860) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (8860) MQTT_CLIENT: msg_type=9, msg_id=47191
D (8870) MQTT_CLIENT: pending_id=195, pending_msg_count = 4
D (8870) OUTBOX: DELETED msgid=47191, msg_type=8, remain size=77
D (8880) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (8890) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (8890) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (8900) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (8910) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (8910) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (8920) MQTT_CLIENT: msg_type=9, msg_id=7788
D (8920) MQTT_CLIENT: pending_id=195, pending_msg_count = 3
D (8930) OUTBOX: DELETED msgid=7788, msg_type=8, remain size=51
D (8940) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (8940) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (8950) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (8960) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (8960) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (8970) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (8970) MQTT_CLIENT: msg_type=9, msg_id=22564
D (8980) MQTT_CLIENT: pending_id=195, pending_msg_count = 2
D (8990) OUTBOX: DELETED msgid=22564, msg_type=8, remain size=23
D (8990) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (9000) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (9000) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (9010) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (9020) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffd3354
D (9020) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (9030) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (9040) MQTT_CLIENT: msg_type=9, msg_id=195
D (9040) MQTT_CLIENT: pending_id=195, pending_msg_count = 1
D (9050) OUTBOX: DELETED msgid=195, msg_type=8, remain size=0
D (9050) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (9310) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffd3354
D (9610) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffd3354
D (9640) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (9650) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (2d:a1:82:51:4a:a7, -49)
I (9650) BLE2MQTT: Discovered BLE device: 2d:a1:82:51:4a:a7 (RSSI: -49), not connecting
D (10370) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (10710) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffd3354
D (11080) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (11800) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (11810) esp_netif_lwip: esp_netif_get_ip_info esp_netif:0x3ffd3354
D (12520) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (12850) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (14360) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (15080) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (16200) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (17820) wifi:bcn_timout,ap_probe_send_start
D (17820) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (17830) WiFi: Unhandled WiFi event (21)
D (17830) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (18360) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (18370) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (18370) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (60:5a:95:24:9e:ad, -91)
I (18380) BLE2MQTT: Discovered BLE device: 60:5a:95:24:9e:ad (RSSI: -91), not connecting
D (19080) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (20200) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (20920) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (21640) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (22040) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (22440) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (23880) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (24600) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (25320) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (25720) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (26120) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (26120) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (79:6d:65:17:05:e0, -87)
I (26120) BLE2MQTT: Discovered BLE device: 79:6d:65:17:05:e0 (RSSI: -87), not connecting
D (26840) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (26860) wifi:bcn_timout,ap_probe_send_start
D (26860) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (26860) WiFi: Unhandled WiFi event (21)
D (26860) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (27570) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (29000) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (29720) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (31880) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (32600) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (33000) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (33720) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (34040) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (34440) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (35160) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (35560) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (35970) wifi:bcn_timout,ap_probe_send_start
D (35970) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (35970) WiFi: Unhandled WiFi event (21)
D (35970) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (36290) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (36600) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (37000) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (37400) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (37720) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (39240) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (39570) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (39640) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (40680) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (41490) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (44760) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (44980) wifi:bcn_timout,ap_probe_send_start
D (44980) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (44980) WiFi: Unhandled WiFi event (21)
D (44990) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (45480) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (45890) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (46840) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (46840) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (e4:65:06:ad:a1:ab, -63)
I (46840) BLE2MQTT: Discovered BLE device: e4:65:06:ad:a1:ab (RSSI: -63), connecting
D (46850) BLE: Enqueue: type: 0, device: e4:65:06:ad:a1:ab, char: 00000000-0000-0000-0000-000000000000, len: 0, val: 0x0
D (47240) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (47240) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (47360) BLE: Queue timer expired
D (47360) BLE: Dequeue: type: 0, device: e4:65:06:ad:a1:ab, char: 00000000-0000-0000-0000-000000000000, len: 0, val: 0x0
D (47370) BLE: Received GAP event 18 (ESP_GAP_BLE_SCAN_STOP_COMPLETE_EVT)
lld_pdu_get_tx_flush_nb HCI packet count mismatch (0, 1)
W (48920) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x3e
D (52960) BLE: Received GATTC event 40 (ESP_GATTC_CONNECT_EVT), gattc_if 1
D (52960) BLE: GATTC event 40 wasn't handled
D (52960) BLE: Received GATTC event 2 (ESP_GATTC_OPEN_EVT), gattc_if 1
D (52970) BLE: Received GAP event 7 (ESP_GAP_BLE_SCAN_START_COMPLETE_EVT)
D (53890) BLE: Received GATTC event 46 (Invalid GATTC event), gattc_if 1
D (53890) BLE: GATTC event 46 wasn't handled
D (53950) BLE: Received GATTC event 18 (ESP_GATTC_CFG_MTU_EVT), gattc_if 1
D (53950) BLE2MQTT: Queuing event BLE_DEVICE_CONNECTED (e4:65:06:ad:a1:ab)
I (53950) BLE2MQTT: Connected to device: e4:65:06:ad:a1:ab, scanning
D (53960) MQTT: Subscribing to e4:65:06:ad:a1:ab/Connected
D (53960) MQTT_CLIENT: mqtt_enqueue id: 29336, type=8 successful
D (53970) OUTBOX: ENQUEUE msgid=29336, msg_type=8, len=34, size=34
D (53980) MQTT_CLIENT: Sent subscribe topic=e4:65:06:ad:a1:ab/Connected, id: 29336, type=8 successful
D (53990) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (53990) BLE: GATTC event 7 wasn't handled
D (54000) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (54000) BLE: GATTC event 7 wasn't handled
D (54010) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (54010) BLE: GATTC event 7 wasn't handled
D (54020) BLE: Received GATTC event 6 (ESP_GATTC_SEARCH_CMPL_EVT), gattc_if 1
D (54020) BLE2MQTT: Queuing event BLE_DEVICE_SERVICES_DISCOVERED (e4:65:06:ad:a1:ab)
D (54030) BLE2MQTT: Services discovered on device: e4:65:06:ad:a1:ab
D (54040) BLE2MQTT: Found new characteristic: service: 00001801-0000-1000-8000-00805f9b34fb, characteristic: 00002a05-0000-1000-8000-00805f9b34fb, properties: 0x20
D (54060) BLE: Enqueue: type: 4, device: e4:65:06:ad:a1:ab, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffbbad8
D (54060) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (54070) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a00-0000-1000-8000-00805f9b34fb, properties: 0x2
D (54060) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (54090) MQTT: Subscribing to e4:65:06:ad:a1:ab/GenericAccess/DeviceName/Get
D (54090) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (54110) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (54120) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (54120) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (54130) MQTT_CLIENT: msg_type=9, msg_id=29336
D (54130) MQTT_CLIENT: pending_id=29336, pending_msg_count = 1
D (54140) OUTBOX: DELETED msgid=29336, msg_type=8, remain size=0
D (54140) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (54150) MQTT_CLIENT: mqtt_enqueue id: 3841, type=8 successful
D (54160) OUTBOX: ENQUEUE msgid=3841, msg_type=8, len=53, size=53
D (54170) MQTT_CLIENT: Sent subscribe topic=e4:65:06:ad:a1:ab/GenericAccess/DeviceName/Get, id: 3841, type=8 successful
D (54170) BLE: Enqueue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (54190) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a01-0000-1000-8000-00805f9b34fb, properties: 0x2
D (54200) MQTT: Subscribing to e4:65:06:ad:a1:ab/GenericAccess/Appearance/Get
D (54210) MQTT_CLIENT: mqtt_enqueue id: 56613, type=8 successful
D (54210) OUTBOX: ENQUEUE msgid=56613, msg_type=8, len=53, size=106
D (54220) MQTT_CLIENT: Sent subscribe topic=e4:65:06:ad:a1:ab/GenericAccess/Appearance/Get, id: 56613, type=8 successful
D (54230) BLE: Enqueue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (54230) MQTT_CLIENT: mqtt_message_receive: first byte: 0x31
D (54240) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a04-0000-1000-8000-00805f9b34fb, properties: 0x2
D (54250) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x21
D (54270) MQTT: Subscribing to e4:65:06:ad:a1:ab/GenericAccess/PeripheralPreferredConnectionParameters/Get
D (54270) MQTT_CLIENT: mqtt_message_receive: total message length: 35 (already read: 2)
D (54290) MQTT_CLIENT: mqtt_message_receive: read_len=33
D (54290) MQTT_CLIENT: mqtt_message_receive: transport_read():35 35
D (54300) MQTT_CLIENT: msg_type=3, msg_id=0
D (54300) MQTT_CLIENT: deliver_publish, message_length_read=35, message_length=35
D (54310) MQTT_CLIENT: deliver_publish: msg_topic_len=27
D (54320) MQTT_CLIENT: Get data len= 4, topic len=27, total_data: 4 offset: 0
D (54320) MQTT: Received: e4:65:06:ad:a1:ab/Connected => true (4)

D (54330) BLE2MQTT: Queuing event MQTT message 14 (e4:65:06:ad:a1:ab/Connected, 0x3ffecc23, 4, 0x3fff00e8)
D (54340) MQTT_CLIENT: mqtt_enqueue id: 18851, type=8 successful
D (54350) OUTBOX: ENQUEUE msgid=18851, msg_type=8, len=82, size=188
D (54350) MQTT_CLIENT: Sent subscribe topic=e4:65:06:ad:a1:ab/GenericAccess/PeripheralPreferredConnectionParameters/Get, id: 18851, type=8 successful
D (54360) BLE: Enqueue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (54370) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (54380) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002aa6-0000-1000-8000-00805f9b34fb, properties: 0x2
D (54380) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (54400) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (54410) MQTT: Subscribing to e4:65:06:ad:a1:ab/GenericAccess/CentralAddressResolution/Get
D (54410) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (54430) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (54430) MQTT_CLIENT: msg_type=9, msg_id=3841
D (54440) MQTT_CLIENT: pending_id=18851, pending_msg_count = 3
D (54440) OUTBOX: DELETED msgid=3841, msg_type=8, remain size=135
D (54450) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (54460) MQTT_CLIENT: mqtt_enqueue id: 19154, type=8 successful
D (54460) OUTBOX: ENQUEUE msgid=19154, msg_type=8, len=67, size=202
D (54470) MQTT_CLIENT: Sent subscribe topic=e4:65:06:ad:a1:ab/GenericAccess/CentralAddressResolution/Get, id: 19154, type=8 successful
D (54480) BLE: Enqueue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002aa6-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (54490) BLE2MQTT: Found new characteristic: service: cba20d00-224d-11e6-9fb8-0002a5d5c51b, characteristic: cba20002-224d-11e6-9fb8-0002a5d5c51b, properties: 0xc
D (54480) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (54510) MQTT: Subscribing to e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set
D (54510) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (54530) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (54540) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (54540) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (54550) MQTT_CLIENT: msg_type=9, msg_id=56613
D (54550) MQTT_CLIENT: pending_id=19154, pending_msg_count = 3
D (54560) OUTBOX: DELETED msgid=56613, msg_type=8, remain size=149
D (54570) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (54570) MQTT_CLIENT: mqtt_enqueue id: 33523, type=8 successful
D (54580) OUTBOX: ENQUEUE msgid=33523, msg_type=8, len=102, size=251
D (54590) MQTT_CLIENT: Sent subscribe topic=e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set, id: 33523, type=8 successful
D (54600) BLE2MQTT: Found new characteristic: service: cba20d00-224d-11e6-9fb8-0002a5d5c51b, characteristic: cba20003-224d-11e6-9fb8-0002a5d5c51b, properties: 0x10
D (54600) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (54620) BLE: Enqueue: type: 4, device: e4:65:06:ad:a1:ab, char: cba20003-224d-11e6-9fb8-0002a5d5c51b, len: 2, val: 0x3fff01cc
D (54620) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (54630) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (54650) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (54660) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (54660) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (54670) MQTT_CLIENT: msg_type=9, msg_id=18851
D (54670) MQTT_CLIENT: pending_id=33523, pending_msg_count = 3
D (54680) OUTBOX: DELETED msgid=18851, msg_type=8, remain size=169
D (54680) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (54690) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (54700) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (54700) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (54710) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (54720) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (54720) MQTT_CLIENT: msg_type=9, msg_id=19154
D (54730) MQTT_CLIENT: pending_id=33523, pending_msg_count = 2
D (54730) OUTBOX: DELETED msgid=19154, msg_type=8, remain size=102
D (54740) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (54750) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (54750) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (54760) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (54770) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (54770) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (54780) MQTT_CLIENT: msg_type=9, msg_id=33523
D (54790) MQTT_CLIENT: pending_id=33523, pending_msg_count = 1
D (54790) OUTBOX: DELETED msgid=33523, msg_type=8, remain size=0
D (54800) MQTT_CLIENT: deliver_suback, message_length_read=5, message_length=5
D (55130) BLE: Queue timer expired
D (55130) BLE: Dequeue: type: 4, device: e4:65:06:ad:a1:ab, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffbbad8
D (55130) BLE: Dequeue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (55230) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (55240) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (e4:65:06:ad:a1:ab, 00002a00-0000-1000-8000-00805f9b34fb, 0x3ffbbac0, 11)
D (55240) BLE: Dequeue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (55240) BLE2MQTT: Publishing: e4:65:06:ad:a1:ab/GenericAccess/DeviceName = WoSensorTH
D (55320) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (55330) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (e4:65:06:ad:a1:ab, 00002a01-0000-1000-8000-00805f9b34fb, 0x3ffbbac0, 2)
D (55330) BLE: Dequeue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (55330) BLE2MQTT: Publishing: e4:65:06:ad:a1:ab/GenericAccess/Appearance = 768
D (55420) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (55420) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (e4:65:06:ad:a1:ab, 00002a04-0000-1000-8000-00805f9b34fb, 0x3ffbbac0, 8)
D (55430) BLE: Dequeue: type: 1, device: e4:65:06:ad:a1:ab, char: 00002aa6-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (55430) BLE2MQTT: Publishing: e4:65:06:ad:a1:ab/GenericAccess/PeripheralPreferredConnectionParameters = 0,0,0,0
D (55490) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (55490) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (e4:65:06:ad:a1:ab, 00002aa6-0000-1000-8000-00805f9b34fb, 0x3ffbbac0, 1)
D (55500) BLE: Dequeue: type: 4, device: e4:65:06:ad:a1:ab, char: cba20003-224d-11e6-9fb8-0002a5d5c51b, len: 2, val: 0x3fff01cc
I (55500) BLE2MQTT: Publishing: e4:65:06:ad:a1:ab/GenericAccess/CentralAddressResolution = 0
D (55580) BLE: Received GATTC event 9 (ESP_GATTC_WRITE_DESCR_EVT), gattc_if 1
D (56750) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (56750) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (58110) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (59620) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (59620) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (61790) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (61790) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (50:a1:9b:ad:75:e4, -100)
I (61790) BLE2MQTT: Discovered BLE device: 50:a1:9b:ad:75:e4 (RSSI: -100), not connecting
D (62190) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (62900) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (62900) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (62990) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (63790) BLE2MQTT: Queuing event HEARTBEAT_TIMER
D (66260) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (66260) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (68430) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (69540) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (70590) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (72030) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (72840) wifi:bcn_timout,ap_probe_send_start
D (72850) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (72850) WiFi: Unhandled WiFi event (21)
D (72850) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (73470) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (74190) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (74990) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (74990) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (75300) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (75710) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (76430) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (77150) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (77150) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (77460) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (77460) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (77870) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (78270) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (79380) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (79380) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (80100) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (80830) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (81950) wifi:bcn_timout,ap_probe_send_start
D (81950) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (81950) WiFi: Unhandled WiFi event (21)
D (81950) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (82260) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (83390) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84110) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84420) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84430) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84430) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (df:06:40:1a:4d:fe, -90)
D (84430) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (84440) BLE2MQTT: Discovered BLE device: df:06:40:1a:4d:fe (RSSI: -90), connecting
D (84450) BLE: Enqueue: type: 0, device: df:06:40:1a:4d:fe, char: 00000000-0000-0000-0000-000000000000, len: 0, val: 0x0
D (84830) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84900) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84900) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (84960) BLE: Queue timer expired
D (84960) BLE: Dequeue: type: 0, device: df:06:40:1a:4d:fe, char: 00000000-0000-0000-0000-000000000000, len: 0, val: 0x0
D (84960) BLE: Received GAP event 18 (ESP_GAP_BLE_SCAN_STOP_COMPLETE_EVT)
I (90960) wifi:bcn_timout,ap_probe_send_start
D (90960) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (90960) WiFi: Unhandled WiFi event (21)
D (90970) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

I (99970) wifi:bcn_timout,ap_probe_send_start
D (99970) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (99970) WiFi: Unhandled WiFi event (21)
D (99980) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

I (109490) wifi:bcn_timout,ap_probe_send_start
D (109500) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (109500) WiFi: Unhandled WiFi event (21)
D (109500) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

W (114970) BT_APPL: gattc_conn_cb: if=1 st=0 id=257 rsn=0x100
D (114980) BLE: Received GATTC event 41 (ESP_GATTC_DISCONNECT_EVT), gattc_if 1
D (114980) BLE: GATTC event 41 wasn't handled
D (114980) BLE: Received GATTC event 2 (ESP_GATTC_OPEN_EVT), gattc_if 1
E (114990) BLE: Open failed, status = 0x85
D (115000) BLE: Received GAP event 7 (ESP_GAP_BLE_SCAN_START_COMPLETE_EVT)
D (115320) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (115320) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (44:e0:9c:2f:67:07, -85)
D (115330) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (115330) BLE2MQTT: Discovered BLE device: 44:e0:9c:2f:67:07 (RSSI: -85), not connecting
D (116050) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (116050) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (f0:b4:38:ff:24:9f, -74)
I (116050) BLE2MQTT: Discovered BLE device: f0:b4:38:ff:24:9f (RSSI: -74), not connecting
I (118610) wifi:bcn_timout,ap_probe_send_start
D (118610) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (118610) WiFi: Unhandled WiFi event (21)
D (118620) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (122210) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (122210) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (123010) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (123010) BLE2MQTT: Queuing event BLE_BROADCASTER_DISCOVERED (54:20:78:61:66:fd, 0x3fff0a10, 27, -71)
I (123010) BLE2MQTT: Discovered iBeacon broadcaster
D (123010) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (54:20:78:61:66:fd, -71)
I (123030) BLE2MQTT: Discovered BLE device: 54:20:78:61:66:fd (RSSI: -71), not connecting
D (123790) BLE2MQTT: Queuing event HEARTBEAT_TIMER
D (126600) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (126600) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (129170) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (129570) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (130690) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (130690) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (130690) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (131010) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (131010) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (131090) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (132050) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (132790) wifi:bcn_timout,ap_probe_send_start
D (132800) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (132800) WiFi: Unhandled WiFi event (21)
D (132800) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (133650) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (133650) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (c6:1d:9f:e4:c5:6d, -56)
I (133650) BLE2MQTT: Discovered BLE device: c6:1d:9f:e4:c5:6d (RSSI: -56), not connecting
D (134290) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (134290) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (56:67:15:8c:6c:73, -99)
I (134290) BLE2MQTT: Discovered BLE device: 56:67:15:8c:6c:73 (RSSI: -99), not connecting
D (135080) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (135410) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (135410) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (135410) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (136130) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (136530) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (138370) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (139090) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (139810) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (139810) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (140130) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (140130) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (d2:7c:b7:fd:46:99, -93)
I (140130) BLE2MQTT: Discovered BLE device: d2:7c:b7:fd:46:99 (RSSI: -93), not connecting
D (140130) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (140210) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (141560) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (141850) wifi:bcn_timout,ap_probe_send_start
D (141850) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (141860) WiFi: Unhandled WiFi event (21)
D (141860) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (143490) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (144530) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (145250) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (145650) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (146450) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (146770) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (147170) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (147810) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (148610) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (149730) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (150860) wifi:bcn_timout,ap_probe_send_start
D (150870) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (150870) WiFi: Unhandled WiFi event (21)
D (150870) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (151170) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (151880) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (151890) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (154130) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (155490) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (155970) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (157330) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (159490) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (159490) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (e2:a4:04:0b:44:41, -72)
D (159490) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (159490) BLE2MQTT: Discovered BLE device: e2:a4:04:0b:44:41 (RSSI: -72), not connecting
I (159870) wifi:bcn_timout,ap_probe_send_start
D (159880) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (159880) WiFi: Unhandled WiFi event (21)
D (159880) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (163970) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (163970) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (165800) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (167250) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (168690) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (168990) wifi:bcn_timout,ap_probe_send_start
D (168990) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (168990) WiFi: Unhandled WiFi event (21)
D (169000) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

D (169090) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (169090) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (169090) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (169730) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (169730) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (170530) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (172770) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
I (178100) wifi:bcn_timout,ap_probe_send_start
D (178110) event: running post WIFI_EVENT:21 with handler 0x400dc5b0 and context 0x3ffda6e8 on loop 0x3ffd2428
0x400dc5b0: event_handler at /home/ricardol/esp32-ble2mqtt/main/wifi.c:45

D (178110) WiFi: Unhandled WiFi event (21)
D (178110) event: running post WIFI_EVENT:21 with handler 0x40131480 and context 0x3ffda8f0 on loop 0x3ffd2428
0x40131480: event_handler at /home/ricardol/esp/esp-idf/components/mdns/mdns.c:4759

W (178930) BT_HCI: hcif disc complete: hdl 0x0, rsn 0x13
W (178930) BT_APPL: gattc_conn_cb: if=1 st=0 id=1 rsn=0x13
D (178930) BLE: Received GATTC event 41 (ESP_GATTC_DISCONNECT_EVT), gattc_if 1
D (178940) BLE: GATTC event 41 wasn't handled
D (178940) BLE: Received GATTC event 5 (ESP_GATTC_CLOSE_EVT), gattc_if 1
I (178950) BLE: Connection closed, reason = 0x13
D (178950) BLE2MQTT: Queuing event BLE_DEVICE_DISCONNECTED (e4:65:06:ad:a1:ab)
I (178960) BLE2MQTT: Disconnected from device: e4:65:06:ad:a1:ab
D (178970) MQTT: Unsubscribing from e4:65:06:ad:a1:ab/Connected
D (178970) MQTT_CLIENT: unsubscribe, topic"e4:65:06:ad:a1:ab/Connected", id: 34502
D (178980) MQTT_CLIENT: mqtt_enqueue id: 34502, type=10 successful
D (178990) OUTBOX: ENQUEUE msgid=34502, msg_type=10, len=33, size=33
D (179000) MQTT_CLIENT: Sent Unsubscribe topic=e4:65:06:ad:a1:ab/Connected, id: 34502, successful
D (179000) MQTT: Unsubscribing topics with e4:65:06:ad:a1:ab/ prefix
D (179010) MQTT: Unsubscribing from e4:65:06:ad:a1:ab/GenericAccess/DeviceName/Get
D (179020) MQTT_CLIENT: unsubscribe, topic"e4:65:06:ad:a1:ab/GenericAccess/DeviceName/Get", id: 39432
D (179030) MQTT_CLIENT: mqtt_enqueue id: 39432, type=10 successful
D (179030) OUTBOX: ENQUEUE msgid=39432, msg_type=10, len=52, size=85
D (179040) MQTT_CLIENT: Sent Unsubscribe topic=e4:65:06:ad:a1:ab/GenericAccess/DeviceName/Get, id: 39432, successful
D (179050) MQTT: Unsubscribing from e4:65:06:ad:a1:ab/GenericAccess/Appearance/Get
D (179050) MQTT_CLIENT: mqtt_message_receive: first byte: 0xb0
D (179060) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (179070) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (179080) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (179080) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (179090) MQTT_CLIENT: msg_type=11, msg_id=34502
D (179090) MQTT_CLIENT: pending_id=39432, pending_msg_count = 2
D (179100) OUTBOX: DELETED msgid=34502, msg_type=10, remain size=52
D (179110) MQTT_CLIENT: UnSubscribe successful
D (179110) MQTT_CLIENT: unsubscribe, topic"e4:65:06:ad:a1:ab/GenericAccess/Appearance/Get", id: 65018
D (179120) MQTT_CLIENT: mqtt_enqueue id: 65018, type=10 successful
D (179130) OUTBOX: ENQUEUE msgid=65018, msg_type=10, len=52, size=104
D (179140) MQTT_CLIENT: Sent Unsubscribe topic=e4:65:06:ad:a1:ab/GenericAccess/Appearance/Get, id: 65018, successful
D (179140) MQTT: Unsubscribing from e4:65:06:ad:a1:ab/GenericAccess/PeripheralPreferredConnectionParameters/Get
D (179150) MQTT_CLIENT: mqtt_message_receive: first byte: 0xb0
D (179160) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (179170) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (179180) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (179180) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (179190) MQTT_CLIENT: msg_type=11, msg_id=39432
D (179190) MQTT_CLIENT: pending_id=65018, pending_msg_count = 2
D (179200) OUTBOX: DELETED msgid=39432, msg_type=10, remain size=52
D (179200) MQTT_CLIENT: UnSubscribe successful
D (179210) MQTT_CLIENT: unsubscribe, topic"e4:65:06:ad:a1:ab/GenericAccess/PeripheralPreferredConnectionParameters/Get", id: 62359
D (179220) MQTT_CLIENT: mqtt_enqueue id: 62359, type=10 successful
D (179230) OUTBOX: ENQUEUE msgid=62359, msg_type=10, len=81, size=133
D (179240) MQTT_CLIENT: Sent Unsubscribe topic=e4:65:06:ad:a1:ab/GenericAccess/PeripheralPreferredConnectionParameters/Get, id: 62359, successful
D (179250) MQTT: Unsubscribing from e4:65:06:ad:a1:ab/GenericAccess/CentralAddressResolution/Get
D (179250) MQTT_CLIENT: mqtt_message_receive: first byte: 0xb0
D (179260) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (179270) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (179280) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (179280) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (179290) MQTT_CLIENT: msg_type=11, msg_id=65018
D (179290) MQTT_CLIENT: pending_id=62359, pending_msg_count = 2
D (179300) OUTBOX: DELETED msgid=65018, msg_type=10, remain size=81
D (179310) MQTT_CLIENT: UnSubscribe successful
D (179310) MQTT_CLIENT: unsubscribe, topic"e4:65:06:ad:a1:ab/GenericAccess/CentralAddressResolution/Get", id: 56438
D (179320) MQTT_CLIENT: mqtt_enqueue id: 56438, type=10 successful
D (179330) OUTBOX: ENQUEUE msgid=56438, msg_type=10, len=66, size=147
D (179340) MQTT_CLIENT: Sent Unsubscribe topic=e4:65:06:ad:a1:ab/GenericAccess/CentralAddressResolution/Get, id: 56438, successful
D (179350) MQTT: Unsubscribing from e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set
D (179360) MQTT_CLIENT: mqtt_message_receive: first byte: 0xb0
D (179360) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (179370) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (179380) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (179380) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (179390) MQTT_CLIENT: msg_type=11, msg_id=62359
D (179390) MQTT_CLIENT: pending_id=56438, pending_msg_count = 2
D (179400) OUTBOX: DELETED msgid=62359, msg_type=10, remain size=66
D (179410) MQTT_CLIENT: UnSubscribe successful
D (179410) MQTT_CLIENT: unsubscribe, topic"e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set", id: 30562
D (179430) MQTT_CLIENT: mqtt_enqueue id: 30562, type=10 successful
D (179430) OUTBOX: ENQUEUE msgid=30562, msg_type=10, len=101, size=167
D (179440) MQTT_CLIENT: Sent Unsubscribe topic=e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set, id: 30562, successful
D (179460) MQTT_CLIENT: mqtt_message_receive: first byte: 0xb0
D (179460) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (179470) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (179480) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (179480) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (179490) MQTT_CLIENT: msg_type=11, msg_id=56438
D (179490) MQTT_CLIENT: pending_id=30562, pending_msg_count = 2
D (179500) OUTBOX: DELETED msgid=56438, msg_type=10, remain size=101
D (179500) MQTT_CLIENT: UnSubscribe successful
D (179510) MQTT_CLIENT: mqtt_message_receive: first byte: 0xb0
D (179510) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x2
D (179520) MQTT_CLIENT: mqtt_message_receive: total message length: 4 (already read: 2)
D (179530) MQTT_CLIENT: mqtt_message_receive: read_len=2
D (179530) MQTT_CLIENT: mqtt_message_receive: transport_read():4 4
D (179540) MQTT_CLIENT: msg_type=11, msg_id=30562
D (179550) MQTT_CLIENT: pending_id=30562, pending_msg_count = 1
D (179550) OUTBOX: DELETED msgid=30562, msg_type=10, remain size=0
D (179560) MQTT_CLIENT: UnSubscribe successful

shmuelzon commented 2 years ago

Hey, in the logs (and actually also in your screenshots after looking again), the 4 topics you're seeing on the MQTT bus are the only 4 that are readable. So this application reads them and publishes the values. The two characteristics specific to the Switchbot are cba20002-224d-11e6-9fb8-0002a5d5c51b which is write only, so there's nothing to read here, and cba20003-224d-11e6-9fb8-0002a5d5c51b which is notify only so we can't request to read it but we do register for notifications, at which point, we need the Switchbot to notify us when something changes.

Perhaps you need to write something to the cba20002-224d-11e6-9fb8-0002a5d5c51b characteristic before it will publish anything. Looking at this, you might need to write 0x570F31 first. So, after your device is connected, try publishing 87,15,49 to e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set and see if that makes any difference.

rlarranaga commented 2 years ago

will do, thanks for the help!

On Wed, Nov 9, 2022, 2:35 AM Assaf Inbal @.***> wrote:

Hey, in the logs (and actually also in your screenshots after looking again), the 4 topics you're seeing on the MQTT bus are the only 4 that are readable. So this application reads them and publishes the values. The two characteristics specific to the Switchbot are cba20002-224d-11e6-9fb8-0002a5d5c51b which is write only, so there's nothing to read here, and cba20003-224d-11e6-9fb8-0002a5d5c51b which is notify only so we can't request to read it but we do register for notifications, at which point, we need the Switchbot to notify us when something changes.

Perhaps you need to write something to the cba20002-224d-11e6-9fb8-0002a5d5c51b characteristic before it will publish anything. Looking at this https://github.com/OpenWonderLabs/python-host/blob/master/switchbot.py, you might need to write 0x570F31 first. So, after your device is connected, try publishing 87,15,49 to e4:65:06:ad:a1:ab/cba20d00-224d-11e6-9fb8-0002a5d5c51b/cba20002-224d-11e6-9fb8-0002a5d5c51b/Set and see if that makes any difference.

— Reply to this email directly, view it on GitHub https://github.com/shmuelzon/esp32-ble2mqtt/issues/169#issuecomment-1308278898, or unsubscribe https://github.com/notifications/unsubscribe-auth/ABW5CX7TOU26LZRHHMINTJDWHNA3RANCNFSM6AAAAAARYWCBXM . You are receiving this because you authored the thread.Message ID: @.***>

rlarranaga commented 2 years ago

Hello @shmuelzon , This appears to be working, thanks a lot for your help!

I have one more question before closing the issue. When BLE devices are discovered, there is usually an entry in BLE2MQTT-XXXX with the device mac, RSSI and distance. Once devices are connected, this information appears to be lost. It does not show up anymore in BLE2MQTT-XXXX , and it is not under the device values.

Is there any way to still receive this information?

Thanks again

shmuelzon commented 2 years ago

Hey, that information is usually broadcasted by the BLE device. Some device aren't connectable at all, like the Eddystone beacon, iBeacon or other sensors and they only periodically publish information to whoever's in range. It appears that your device, while it isn't connected, publishes that information and stops while it is connected, so I don't think there's anything I can do to have that information show up. Unless your device also publishes the sensor data and then you can avoid connecting to altogether.

rlarranaga commented 2 years ago

Hello @shmuelzon , If that is the case, and the device stops advertising signal strength when connected then why do i still receive the following messages in the logs:

2022-11-13 11:05:12.445442 (BLE2MQTT-B790.lan): I (9788345) BLE2MQTT: Discovered BLE device: ee:ca:79:d7:d4:27 (RSSI: -54), connecting 2022-11-13 11:06:10.408474 (BLE2MQTT-B790.lan): I (9846335) BLE2MQTT: Discovered BLE device: e4:65:06:ad:a1:ab (RSSI: -57), connecting 2022-11-13 11:06:32.110368 (BLE2MQTT-B790.lan): I (9868005) BLE2MQTT: Discovered BLE device: df:06:40:1a:4d:fe (RSSI: -42), connecting 2022-11-13 11:08:26.597390 (BLE2MQTT-B790.lan): I (9982495) BLE2MQTT: Discovered BLE device: e4:65:06:ad:a1:ab (RSSI: -62), connecting

I would have expected that since the device RSSI is still showing up in the logs, then it would still be available over mqtt.

Thanks

shmuelzon commented 2 years ago

Since it's a different MAC address every time, I'm guessing it's just different BLE devices in your area and not the one you're interested in

rlarranaga commented 2 years ago

No, all these 3 devices are the switchbot meter devices i am getting data from. They are whitelisted in my comfiguration, and i am definetely getting the temperature, humidity and battery values. But i do not get RSSI and distance. Thanks

shmuelzon commented 2 years ago

Those log messages are only printed when a device is discovered for the first time after which we either connect or ignore them. In your logs I can see we connect to them so you shouldn't see those messages until we disconnect from them, for whatever reason. The MQTT topic for distance is only published for iBeacons and Eddystone beacons (which I guess the sensor mimics) and I don't believe those will be published when the sensor is connected.

shmuelzon commented 2 years ago

If you have a BLE capture or something like that, we can try to verify the above...

rlarranaga commented 2 years ago

Hey @shmuelzon , thanks for the reply,

Yes, the behavior you describe aligns with what i am experiencing. These devices are broadcasters, so esp32-ble-mqtt connects to them for a short period, to receive new data.

It would be great if the rssi (and other values from the broadcast message) would not get ignored after discovery, and could either be kept under BLE2MQQT-XXXX or even better, under the device topic (Maybe a flag that enables or disables this behavior in the configuration?).

Signal level values are great for troubleshooting, even when the devices do as installed in a fixed location. Sometimes things in the environment change that make the signal worse, and being able to log the signal information can greatly help troubleshooting.

Thanks Again!

shmuelzon commented 2 years ago

Hey,

It would be great if the rssi (and other values from the broadcast message) would not get ignored after discovery

I don't think they're ignored, they're simply not broadcasted anymore since they're used for discovery. Once the peripheral was discovered and connected to, it has no reason to continue publishing itself.

Signal level values are great for troubleshooting, even when the devices do as installed in a fixed location.

I'm not sure I have that information from the ESP-IDF APIs, I'll need to look into it.

rlarranaga commented 2 years ago

I don't think they're ignored, they're simply not broadcaster anymore since they're used for discovery. Once the peripheral was discovered and connected to, it has no reason to continue publishing itself.

I am trying to understand if i got the flow wrong. Once i get a topic for a device that is not part of the BLE2MQTT topic, i consider that device discovered, and connected to (At least once).

Now, if after that happens, i still see Discovered BLE device: e4:65:06:ad:a1:ab (RSSI: -62), connecting messages (which i do), i would think that the rssi is still being broadcasted My point is, since i still get those messages in the logs, it should be possible to just publish them in the same connection topic the discovered device already has.

Thanks

shmuelzon / esp32-ble2mqtt

Switchbot meter broadcasters #169