shmuelzon / esp32-ble2mqtt

A BLE to MQTT bridge running on an ESP32
MIT License
669 stars 108 forks source link

BT_GATT: ATT - Ignore wrong response. Receives (13) #74

Open davidkipstar opened 4 years ago

davidkipstar commented 4 years ago

Hello,

I have problems setting up my notification bridge for a scale I want to use in another project. I used nRF to find out which descriptor I have to write to enable notifications. It works on my smartphone.

In your Readme you say it will automatically detect notifications and publish them but I did not have success with error "BT_GATT: ATT - Ignore wrong response. Receives (13) ". If I change config file I don't get any other results. Do I have to write specific functions for that? This would be a contradiction to Readme.
I don't understand this error and don't know how to continue. So how can I write to my subscriptor and receive notifications? I appreciate every help :)

Debug Log from my connection.

I (8600) BLE2MQTT: Discovered BLE device: 03:b3:ec:8d:ef:16 (RSSI: -81), connecting
I (8610) BT_GATT: GATT_Connect gatt_if=1
I (8610) BT_GATT: GATT_GetConnIdIfConnected status=0

I (9120) BT_GATT: GATT_SetIdleTimeout idle_tout=65535 status=1(1-OK 0-not performed)
I (9130) BT_GATT: GATT_GetConnectionInfor conn_id=1
I (9130) BT_GATT: GATTC_Discover conn_id=1 disc_type=1
I (9310) BT_GATT: GATTC_Discover conn_id=1 disc_type=3
I (9360) BT_GATT: GATTC_Discover conn_id=1 disc_type=4
I (9500) BT_GATT: GATTC_Discover conn_id=1 disc_type=3
I (9560) BT_GATT: GATTC_Discover conn_id=1 disc_type=4
I (9660) BT_GATT: GATTC_Discover conn_id=1 disc_type=5
I (9720) BT_GATT: GATTC_Discover conn_id=1 disc_type=3
I (9800) BT_GATT: GATTC_Discover conn_id=1 disc_type=4
I (9910) BT_GATT: GATTC_Discover conn_id=1 disc_type=5
I (9930) BT_GATT: GATTC_Discover conn_id=1 disc_type=3
I (10000) BT_GATT: GATTC_Discover conn_id=1 disc_type=4
I (10210) BT_GATT: GATTC_Discover conn_id=1 disc_type=5
I (10240) BT_GATT: GATTC_Discover conn_id=1 disc_type=5
I (10310) BT_GATT: GATTC_Discover conn_id=1 disc_type=5
I (10350) BT_GATT: GATTC_ConfigureMTU conn_id=1 mtu=200
I (10410) BLE2MQTT: Connected to device: 03:b3:ec:8d:ef:16, scanning
I (10950) BT_GATT: GATTC_Read conn_id=1 type=2
I (11020) BT_GATT: GATTC_Read conn_id=1 type=2
I (11020) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/DeviceName = SWAN
I (11050) BT_GATT: GATTC_Read conn_id=1 type=2
I (11050) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/Appearance = 0
I (11110) BT_GATT: GATTC_Read conn_id=1 type=2
I (11110) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPrivacyFlag = false
I (11140) BT_GATT: GATTC_Read conn_id=1 type=2
I (11140) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPreferredConnectionParameters = 8,16,0,100
I (11160) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAttribute/ServiceChanged = 1,65535
I (11170) BT_GATT: GATTC_Read conn_id=1 type=2
W (11240) BT_GATT: ATT - Ignore wrong response. Receives (13)                                 Request(0b) Ignored
W (11240) BT_GATT: ATT - Ignore wrong response. Receives (13)                                 Request(0c) Ignored
W (11250) BT_GATT: ATT - Ignore wrong response. Receives (0b)                                 Request(0d) Ignored

and here is my config

{
  "wifi": {
    "ssid": "aodjpoad",
    "password": "pw",
  },
  "mqtt": {
    "server": {
      "host": "192.168.178.86",
      "port": 1883
    },
    "publish": {
      "retain": true
    }
  },
  "ble": {
    "whitelist" : [
            "03:B3:EC:8D:F0:F1",
            "03:B3:EC:8D:EF:16"
    ],
    "characteristics" : {
            "definitions" : {
                   "0000ffb2-0000-1000-8000-00805f9b34fb" : {
                            "name" : "Weight"
                    }
            }
          }
 }
}
shmuelzon commented 4 years ago

Hey,

It seems that the GATT discovery didn't complete, otherwise I would have expected to see more characteristics. The flow is usually to read all of the characteristics and for each one, read (is that's available), subscribe to an MQTT topic for writing (if that's available) and subscribe for indications/notifications (if that's available). The BLE operations (reading and registering for notifications) are queued in side the application and sent one after the other to the BLE stack. I've never seen the "Ignore wrong response" error. If, due to this error, the application isn't notified that the previous operation completed it won't dequeue the next operation and would seem to be stuck.

Just to be sure, which ESP-IDF version are you using and which version/commit of this application? Can you please also enable the debug log level in make menuconfig and post the output? It should contain more information as to which events are sent and received by the BLE stack.

Thanks!

davidkipstar commented 4 years ago

Thanks for your fast reply!

My esp-idf is v3.2.2 with commit 055943e29346e77c50589c61a8a26101a8b35d7b

What log level do you mean? I ve set Component Config -> Bluetooth -> Bluedroid -> DEBUG LOG LEVEL -> GATT to Debug

The output is monitor2.log but I can't understand it

kind regards

shmuelzon commented 4 years ago

Hey,

I was actually referring to Component config -> Log output -> Default log verbosity -> Debug. In the logs I see a stack overflow from the BLE task but, according to espressif/esp-idf#2503, it's due to increasing the Bluetooth log level. I'll need the logs with the configuration above to better understand what's going on.

Thanks

davidkipstar commented 4 years ago

Hello,

I reflashed and could generate this log file: error.log I copied the part from starting the connection until disconnection occured.

Kind regards :)

shmuelzon commented 4 years ago

Hey,

Could you please try to apply the following patch and check if it helps?

diff --git a/main/ble.c b/main/ble.c
index fd9b919..0d0c707 100644
--- a/main/ble.c
+++ b/main/ble.c
@@ -153,7 +153,7 @@ static inline void ble_operation_perform(ble_operation_t *operation)
         esp_ble_gattc_write_char_descr(g_gattc_if, operation->device->conn_id,
             operation->characteristic->client_config_handle, operation->len,
             operation->value,
-            ESP_GATT_WRITE_TYPE_NO_RSP, ESP_GATT_AUTH_REQ_NONE);
+            ESP_GATT_WRITE_TYPE, ESP_GATT_AUTH_REQ_NONE);
         break;
     }
 }

Let me know how it works out.

Thanks!

davidkipstar commented 4 years ago

Hello,

It helped! Now it is showing

D (114759) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)

without disconnecting.

I used ESP_GATT_WRITE_TYPE_RSP instead since "_RSP" was missing. On the weekend I will check if it is working smoothly.

Thank you very much :)

shmuelzon commented 4 years ago

Glad to hear it helped! Please let me know, after the weekend, if everything is as expected and I'll commit the change.

I used ESP_GATT_WRITE_TYPE_RSP instead since "_RSP" was missing.

Right, missed that. Thanks

davidkipstar commented 4 years ago

Hey,

Before the first publications i can see the characteristics i want to subscribe to "0000ffb2-0000-1000-8000-00805f9b34fb"

I (17639) BLE2MQTT: Connected to device: 03:b3:ec:8d:ef:16, scanning
D (17649) MQTT: Subscribing to 03:b3:ec:8d:ef:16/Connected
D (17649) MQTT_CLIENT: mqtt_enqueue id: 43989, type=8 successful
D (17659) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/Connected, id: 32881, type=8 successful
D (17669) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (17669) BLE: GATTC event 7 wasn't handled
D (17679) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (17689) BLE: GATTC event 7 wasn't handled
D (17689) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (17699) BLE: GATTC event 7 wasn't handled
D (17699) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (17709) BLE: GATTC event 7 wasn't handled
D (17709) BLE: Received GATTC event 6 (ESP_GATTC_SEARCH_CMPL_EVT), gattc_if 1
D (17719) BLE2MQTT: Queuing event BLE_DEVICE_SERVICES_DISCOVERED (03:b3:ec:8d:ef:16)
D (17719) MQTT_CLIENT: msg_type=9, msg_id=32881
D (17729) MQTT_CLIENT: msg_type=9, msg_id=32881
D (17729) BLE2MQTT: Services discovered on device: 03:b3:ec:8d:ef:16
D (17739) MQTT_CLIENT: pending_id=32881, pending_msg_count = 1
D (17749) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a00-0000-1000-8000-00805f9b34fb, properties: 0x2
D (17749) MQTT_CLIENT: Subscribe successful
D (17769) MQTT: Subscribing to 03:b3:ec:8d:ef:16/GenericAccess/DeviceName/Get
D (17779) MQTT_CLIENT: mqtt_enqueue id: 32881, type=8 successful
D (17779) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/GenericAccess/DeviceName/Get, id: 48828, type=8 successful
D (17789) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (17799) MQTT_CLIENT: msg_type=3, msg_id=0
D (17809) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a01-0000-1000-8000-00805f9b34fb, properties: 0x2
D (17809) MQTT_CLIENT: msg_type=3, msg_id=0
D (17829) MQTT: Subscribing to 03:b3:ec:8d:ef:16/GenericAccess/Appearance/Get
D (17829) MQTT_CLIENT: deliver_publish, message_length_read=35, message_length=35
D (17829) MQTT_CLIENT: mqtt_enqueue id: 48828, type=8 successful
D (17839) MQTT_CLIENT: Get data len= 4, topic len=27
D (17849) MQTT: Received: 03:b3:ec:8d:ef:16/Connected => true (4)

D (17859) OUTBOX: ENQUEUE msgid=48828, msg_type=8, len=53, size=53
D (17869) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/GenericAccess/Appearance/Get, id: 21542, type=8 successful
D (17879) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (17879) MQTT_CLIENT: msg_type=9, msg_id=48828
D (17889) MQTT_CLIENT: msg_type=9, msg_id=48828
D (17889) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (17899) MQTT_CLIENT: pending_id=21542, pending_msg_count = 2
D (17899) BLE2MQTT: Queuing event BLE_DEVICE_DISCOVERED (68:af:6e:e4:16:6b, -86)
D (17899) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a02-0000-1000-8000-00805f9b34fb, properties: 0xa
D (17909) OUTBOX: DELETED msgid=48828, msg_type=8, remain size=0
D (17939) MQTT: Subscribing to 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPrivacyFlag/Get
D (17939) MQTT_CLIENT: Subscribe successful
D (17939) MQTT_CLIENT: mqtt_enqueue id: 21542, type=8 successful
D (17959) OUTBOX: ENQUEUE msgid=21542, msg_type=8, len=53, size=53
D (17959) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/GenericAccess/PeripheralPrivacyFlag/Get, id: 3538, type=8 successful
D (17969) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a02-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (17979) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (17969) MQTT_CLIENT: msg_type=9, msg_id=21542
D (17979) MQTT: Subscribing to 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPrivacyFlag/Set
D (17989) MQTT_CLIENT: msg_type=9, msg_id=21542
D (17999) MQTT_CLIENT: mqtt_enqueue id: 3538, type=8 successful
D (18009) MQTT_CLIENT: pending_id=3538, pending_msg_count = 2
D (18019) OUTBOX: ENQUEUE msgid=3538, msg_type=8, len=64, size=117
D (18019) OUTBOX: DELETED msgid=21542, msg_type=8, remain size=64
D (18029) MQTT_CLIENT: Subscribe successful
D (18039) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/GenericAccess/PeripheralPrivacyFlag/Set, id: 8578, type=8 successful
D (18049) MQTT_CLIENT: msg_type=9, msg_id=3538
D (18049) MQTT_CLIENT: msg_type=9, msg_id=3538
D (18059) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a04-0000-1000-8000-00805f9b34fb, properties: 0x2
D (18059) MQTT_CLIENT: pending_id=8578, pending_msg_count = 2
D (18079) MQTT: Subscribing to 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPreferredConnectionParameters/Get
D (18079) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (18079) OUTBOX: DELETED msgid=3538, msg_type=8, remain size=0
D (18089) MQTT_CLIENT: mqtt_enqueue id: 8578, type=8 successful
D (18099) MQTT_CLIENT: Subscribe successful
D (18109) OUTBOX: ENQUEUE msgid=8578, msg_type=8, len=64, size=64
D (18119) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/GenericAccess/PeripheralPreferredConnectionParameters/Get, id: 25778, type=8 successful
D (18119) MQTT_CLIENT: msg_type=9, msg_id=8578
D (18129) MQTT_CLIENT: msg_type=9, msg_id=8578
D (18139) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (18139) MQTT_CLIENT: pending_id=25778, pending_msg_count = 2
D (18149) OUTBOX: DELETED msgid=8578, msg_type=8, remain size=0
D (18149) BLE2MQTT: Found new characteristic: service: 00001801-0000-1000-8000-00805f9b34fb, characteristic: 00002a05-0000-1000-8000-00805f9b34fb, properties: 0x22
D (18159) MQTT_CLIENT: Subscribe successful
D (18179) MQTT: Subscribing to 03:b3:ec:8d:ef:16/GenericAttribute/ServiceChanged/Get
D (18189) MQTT_CLIENT: mqtt_enqueue id: 25778, type=8 successful
D (18189) OUTBOX: ENQUEUE msgid=25778, msg_type=8, len=82, size=82
D (18199) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/GenericAttribute/ServiceChanged/Get, id: 64200, type=8 successful
D (18209) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (18209) MQTT_CLIENT: msg_type=9, msg_id=25778
D (18229) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (18229) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:ef:16, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffdfff4
D (18229) MQTT_CLIENT: msg_type=9, msg_id=25778
D (18249) MQTT_CLIENT: pending_id=64200, pending_msg_count = 2
D (18249) BLE2MQTT: Found new characteristic: service: d618d000-6000-1000-8000-000000000000, characteristic: d618d001-6000-1000-8000-000000000000, properties: 0x8
D (18259) OUTBOX: DELETED msgid=25778, msg_type=8, remain size=0
D (18279) MQTT: Subscribing to 03:b3:ec:8d:ef:16/d618d000-6000-1000-8000-000000000000/d618d001-6000-1000-8000-000000000000/Set
D (18279) MQTT_CLIENT: Subscribe successful
D (18289) MQTT_CLIENT: mqtt_enqueue id: 64200, type=8 successful
D (18299) MQTT_CLIENT: msg_type=9, msg_id=64200
D (18299) MQTT_CLIENT: msg_type=9, msg_id=64200
D (18309) OUTBOX: ENQUEUE msgid=64200, msg_type=8, len=60, size=60
D (18309) MQTT_CLIENT: pending_id=64200, pending_msg_count = 1
D (18319) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/d618d000-6000-1000-8000-000000000000/d618d001-6000-1000-8000-000000000000/Set, id: 29727, type=8 successful
D (18319) OUTBOX: DELETED msgid=64200, msg_type=8, remain size=0
D (18339) MQTT_CLIENT: Subscribe successful
D (18349) BLE2MQTT: Found new characteristic: service: d618d000-6000-1000-8000-000000000000, characteristic: d618d002-6000-1000-8000-000000000000, properties: 0x14
D (18349) MQTT_CLIENT: msg_type=9, msg_id=29727
D (18369) MQTT_CLIENT: msg_type=9, msg_id=29727
D (18369) MQTT: Subscribing to 03:b3:ec:8d:ef:16/d618d000-6000-1000-8000-000000000000/d618d002-6000-1000-8000-000000000000/Set
D (18369) MQTT_CLIENT: pending_id=29727, pending_msg_count = 1
D (18379) MQTT_CLIENT: mqtt_enqueue id: 29727, type=8 successful
D (18389) MQTT_CLIENT: Subscribe successful
D (18399) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/d618d000-6000-1000-8000-000000000000/d618d002-6000-1000-8000-000000000000/Set, id: 64637, type=8 successful
D (18409) MQTT_CLIENT: msg_type=9, msg_id=64637
D (18419) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (18419) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:ef:16, char: d618d002-6000-1000-8000-000000000000, len: 2, val: 0x3ffec39c
D (18419) MQTT_CLIENT: msg_type=9, msg_id=64637
D (18439) MQTT_CLIENT: pending_id=64637, pending_msg_count = 1
D (18439) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb2-0000-1000-8000-00805f9b34fb, properties: 0x10
D (18449) MQTT_CLIENT: Subscribe successful
D (18469) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:ef:16, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffec8e4
D (18469) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (18479) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb1-0000-1000-8000-00805f9b34fb, properties: 0x4
D (18499) MQTT: Subscribing to 03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb1-0000-1000-8000-00805f9b34fb/Set
D (18509) MQTT_CLIENT: mqtt_enqueue id: 64637, type=8 successful
D (18519) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb1-0000-1000-8000-00805f9b34fb/Set, id: 7115, type=8 successful
D (18529) MQTT_CLIENT: msg_type=9, msg_id=7115
D (18539) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb3-0000-1000-8000-00805f9b34fb, properties: 0x16
D (18539) MQTT_CLIENT: msg_type=9, msg_id=7115
D (18559) MQTT_CLIENT: pending_id=7115, pending_msg_count = 1
D (18559) MQTT: Subscribing to 03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb3-0000-1000-8000-00805f9b34fb/Get
D (18559) MQTT_CLIENT: Subscribe successful
D (18569) MQTT_CLIENT: mqtt_enqueue id: 7115, type=8 successful
D (18589) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb3-0000-1000-8000-00805f9b34fb/Get, id: 53587, type=8 successful
D (18599) MQTT_CLIENT: msg_type=9, msg_id=53587
D (18599) MQTT_CLIENT: msg_type=9, msg_id=53587
D (18609) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:ef:16, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (18609) MQTT_CLIENT: pending_id=53587, pending_msg_count = 1
D (18619) MQTT_CLIENT: Subscribe successful
D (18629) MQTT: Subscribing to 03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb3-0000-1000-8000-00805f9b34fb/Set
D (18639) MQTT_CLIENT: mqtt_enqueue id: 53587, type=8 successful
D (18649) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb3-0000-1000-8000-00805f9b34fb/Set, id: 35996, type=8 successful
D (18659) MQTT_CLIENT: msg_type=9, msg_id=35996
D (18669) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (18669) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:ef:16, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffecc08
D (18669) MQTT_CLIENT: msg_type=9, msg_id=35996
D (18689) MQTT_CLIENT: pending_id=35996, pending_msg_count = 1
I (18699) BLE2MQTT: Discovered BLE device: 68:af:6e:e4:16:6b (RSSI: -86), not connecting
D (18699) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (18699) MQTT_CLIENT: Subscribe successful
D (18899) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (19129) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (19189) BLE: Queue timer expired
D (19189) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (19209) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (19209) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:ef:16, 00002a00-0000-1000-8000-00805f9b34fb, 0x3ffec3f0, 4)
D (19219) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0

And then I can see the following in MQTT

true
BLE2MQTT-2519
SWAN
0
false
8,16,0,100
1,65535
1

Which is coming from:

I (19219) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/DeviceName = SWAN
D (19289) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (19289) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:ef:16, 00002a01-0000-1000-8000-00805f9b34fb, 0x3ffec3f0, 2)
D (19289) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a02-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (19289) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/Appearance = 0
D (19329) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (19339) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:ef:16, 00002a02-0000-1000-8000-00805f9b34fb, 0x3ffec3f0, 1)
D (19339) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (19339) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPrivacyFlag = false
D (19419) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (19419) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (19429) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:ef:16, 00002a04-0000-1000-8000-00805f9b34fb, 0x3ffed664, 8)
D (19439) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:ef:16, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (19439) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAccess/PeripheralPreferredConnectionParameters = 8,16,0,100
D (19519) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (19519) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (19529) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:ef:16, 00002a05-0000-1000-8000-00805f9b34fb, 0x3ffec3f0, 4)
D (19539) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:ef:16, char: 00002a05-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffdfff4
I (19539) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/GenericAttribute/ServiceChanged = 1,65535
D (19549) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:ef:16, char: d618d002-6000-1000-8000-000000000000, len: 2, val: 0x3ffec39c
D (19569) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:ef:16, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffec8e4
D (19579) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:ef:16, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (19709) BLE: Received GATTC event 9 (ESP_GATTC_WRITE_DESCR_EVT), gattc_if 1
D (19739) BLE: Received GATTC event 9 (ESP_GATTC_WRITE_DESCR_EVT), gattc_if 1
D (19789) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (19789) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:ef:16, 0000ffb3-0000-1000-8000-00805f9b34fb, 0x3ffec3f0, 1)
D (19789) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:ef:16, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffecc08
I (19799) BLE2MQTT: Publishing: 03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb3-0000-1000-8000-00805f9b34fb = 1
D (19839) BLE: Received GATTC event 9 (ESP_GATTC_WRITE_DESCR_EVT), gattc_if 1
D (20259) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (20339) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (20549) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (20839) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (21079) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (21149) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (22169) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (22269) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)

Then it is stuck at "Receiving GAP event 3" and does not change. Can you see why the values are not published ?

Kind regards

shmuelzon commented 4 years ago

Well, to be honest, I don't see any issue here. These are the characteristics that were found:

00002a00-0000-1000-8000-00805f9b34fb READ -> SWAN
00002a01-0000-1000-8000-00805f9b34fb READ -> 0
00002a02-0000-1000-8000-00805f9b34fb READ WRITE -> false
00002a04-0000-1000-8000-00805f9b34fb READ -> 8,16,0,100
00002a05-0000-1000-8000-00805f9b34fb READ INDICATE -> 1,65535
d618d001-6000-1000-8000-000000000000 WRITE  
d618d002-6000-1000-8000-000000000000 WRITE_NR NOTIFY
0000ffb2-0000-1000-8000-00805f9b34fb NOTIFY
0000ffb1-0000-1000-8000-00805f9b34fb WRITE_NR
0000ffb3-0000-1000-8000-00805f9b34fb READ WRITE_NR NOTIFY -> 1

For each one that is readable, the application tried to read the value and also published it when it was received. Those are the values you saw from MQTT. The characteristics that can be registered on (that support notify or indicate) have been registered on.

In order to get values for the 0000ffb3-0000-1000-8000-00805f9b34fb characteristic, the BLE peripheral needs to publish the data. Specifically for 0000ffb3-0000-1000-8000-00805f9b34fb you can also manually read the value but I'm assuming that's not what you're after.

Do you need to do anything actively on the device to have is publish data on that characteristic?

One thing I can suggest for you to try is blacklisting the 00002a05-0000-1000-8000-00805f9b34fb (ServiceChanged) characteristic. It's been giving me (and others) some issues in the past from devices from a certain manufacturer.

Let me know...

davidkipstar commented 4 years ago

Hey,

to start notifications I need to write value=0x0100 to my "0000ffb1-0000-1000-8000-00805f9b34fb" descriptor. I tried to do it via mosquitto_pub.

mosquitto_pub -t mac/0000ffb1-0000-1000-8000-00805f9b34fb/Set -m 0100

I can fetch the pub message by subscribing to mac/# but notifications don't start. When I do it on my nrf app on android it works fine.

What am I not getting? Sorry if I am not getting something obvious. Thanks for the help!

Kind regards

shmuelzon commented 4 years ago

Hey,

Values aren’t sent in HEX. If you didn’t configure the 0000ffb1-0000-1000-8000-00805f9b34fb characteristic and define its type, the the default is comma-separated bytes, in decimal. So you should try to set 0,1 (it might be the other way around, i.e. 1,0, I’m not sure what endianness you’re using).

Thanks

davidkipstar commented 4 years ago

Hello, I am again struggling but I think I came a step closer. Now I run into the problem of memory overflow. Can this be related to this issue?

I (10124) BLE2MQTT: Connected to device: 03:b3:ec:8d:f0:f1, scanning
D (10134) MQTT: Subscribing to 03:b3:ec:8d:f0:f1/Connected
D (10134) MQTT_CLIENT: mqtt_enqueue id: 56392, type=8 successful
D (10144) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f0:f1/Connected, id: 28618, type=8 successful
D (10154) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (10164) BLE: GATTC event 7 wasn't handled
D (10164) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (10174) BLE: GATTC event 7 wasn't handled
D (10174) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (10184) BLE: GATTC event 7 wasn't handled
D (10184) BLE: Received GATTC event 7 (ESP_GATTC_SEARCH_RES_EVT), gattc_if 1
D (10194) BLE: GATTC event 7 wasn't handled
D (10194) BLE: Received GATTC event 6 (ESP_GATTC_SEARCH_CMPL_EVT), gattc_if 1
D (10204) BLE2MQTT: Queuing event BLE_DEVICE_SERVICES_DISCOVERED (03:b3:ec:8d:f0:f1)
D (10214) BLE2MQTT: Services discovered on device: 03:b3:ec:8d:f0:f1
D (10224) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a00-0000-1000-8000-00805f9b34fb, properties: 0x2
D (10234) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a01-0000-1000-8000-00805f9b34fb, properties: 0x2
D (10244) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a02-0000-1000-8000-00805f9b34fb, properties: 0xa
D (10264) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a04-0000-1000-8000-00805f9b34fb, properties: 0x2
D (10274) BLE2MQTT: Found new characteristic: service: 00001801-0000-1000-8000-00805f9b34fb, characteristic: 00002a05-0000-1000-8000-00805f9b34fb, properties: 0x22
D (10294) BLE2MQTT: Found new characteristic: service: d618d000-6000-1000-8000-000000000000, characteristic: d618d001-6000-1000-8000-000000000000, properties: 0x8
D (10304) BLE2MQTT: Found new characteristic: service: d618d000-6000-1000-8000-000000000000, characteristic: d618d002-6000-1000-8000-000000000000, properties: 0x14
D (10324) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb2-0000-1000-8000-00805f9b34fb, properties: 0x10
D (10334) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:f0:f1, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffdfff4
D (10334) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (10344) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb1-0000-1000-8000-00805f9b34fb, properties: 0x4
D (10364) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (10374) MQTT: Subscribing to 03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set
D (10384) MQTT_CLIENT: mqtt_enqueue id: 28618, type=8 successful
D (10394) OUTBOX: ENQUEUE msgid=28618, msg_type=8, len=41, size=41
D (10394) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set, id: 40139, type=8 successful
D (10414) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb3-0000-1000-8000-00805f9b34fb, properties: 0x16
D (10424) MQTT: Subscribing to 03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Get
D (10434) MQTT_CLIENT: mqtt_enqueue id: 40139, type=8 successful
D (10444) OUTBOX: ENQUEUE msgid=40139, msg_type=8, len=71, size=112
D (10444) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Get, id: 32990, type=8 successful
D (10454) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:f0:f1, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (10474) MQTT: Subscribing to 03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Set
D (10474) MQTT_CLIENT: mqtt_enqueue id: 32990, type=8 successful
D (10484) OUTBOX: ENQUEUE msgid=32990, msg_type=8, len=71, size=183
D (10494) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Set, id: 65458, type=8 successful
D (10504) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:f0:f1, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffecd84
D (10504) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (11014) BLE: Queue timer expired
D (11014) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f0:f1, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffdfff4
D (11014) BLE: Dequeue: type: 0***ERROR*** A stack overflow in task Tmr Svc has been detected.
abort() was called at PC 0x400903a0 on core 0
0x400903a0: vApplicationStackOverflowHook at /home/david/esp/esp-idf/components/esp32/panic.c:707

Backtrace: 0x4009015c:0x3ffbc600 0x40090389:0x3ffbc620 0x400903a0:0x3ffbc640 0x4008d9f0:0x3ffbc660 0x4008f430:0x3ffbc680 0x4008f3e6:0xe1e3747e
0x4009015c: invoke_abort at /home/david/esp/esp-idf/components/esp32/panic.c:707

0x40090389: abort at /home/david/esp/esp-idf/components/esp32/panic.c:707

0x400903a0: vApplicationStackOverflowHook at /home/david/esp/esp-idf/components/esp32/panic.c:707

0x4008d9f0: vTaskSwitchContext at /home/david/esp/esp-idf/components/freertos/tasks.c:3537

0x4008f430: _frxt_dispatch at /home/david/esp/esp-idf/components/freertos/portasm.S:406

0x4008f3e6: _frxt_int_exit at /home/david/esp/esp-idf/components/freertos/portasm.S:206

Rebooting...

My config looks like this now if it helps

  },
  "ble": {
    "whitelist" : [
            "03:B3:EC:8D:F0:F1"
    ],
    "characteristics": {
            "whitelist" : [
                    "0000ffb1-0000-1000-8000-00805f9b34fb",
                    "0000ffb2-0000-1000-8000-00805f9b34fb",
                    "0000ffb3-0000-1000-8000-00805f9b34fb"
            ],
            "defintions" : {
                    "0000ffb1-0000-1000-8000-00805f9b34fb" : {
                            "name" : "PullUp",
                            "types" : ["16bit"]
                    }
            },
            "blacklist" : [
                    "00002a05-0000-1000-8000-00805f9b34fb",
                    "0x2a05"
                    ]
    },
    "services" : {
            "definitions" : {
                    "0000ffb0-0000-1000-8000-00805f9b34fb" : {
                            "name" : "Scale"
                    }
            },
            "blacklist" : [
                    "00002a05-0000-1000-8000-00805f9b34fb",
                    "0x2a05"
            ]
    }

kind regards

shmuelzon commented 4 years ago

Hey, that's a new one :) I think that's it's because of the logs though that are disabled by default. See https://esp32.com/viewtopic.php?t=1459#p6626. If you want to keep them, you might want to try increasing the stack size of the timer task, as described in the link above.

davidkipstar commented 3 years ago

Hello,

I changed logging from verbose to info because increasing timer stack size did not solve the problem. It seems that internally the charactersitics is not getting registered. So I think there is still a overflow. I conclude this since in my MQTT-Broker no regestriation for 000ffb2* characteristic is done

1603888134: New connection from 192.168.178.78 on port 1883.
1603888134: Client ESP32_0f2519 already connected, closing old connection.
1603888134: New client connected from 192.168.178.78 as ESP32_0f2519 (p2, c1, k120).
1603888134: No will message specified.
1603888134: Sending CONNACK to ESP32_0f2519 (0, 0)
1603888134: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/Version', ... (18 bytes))
1603888134: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/ConfigVersion', ... (64 bytes))
1603888134: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/Uptime', ... (1 bytes))
1603888134: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/FreeMemory', ... (5 bytes))
1603888134: Received SUBSCRIBE from ESP32_0f2519
1603888134:     BLE2MQTT-2519/OTA/Firmware (QoS 0)
1603888134: ESP32_0f2519 0 BLE2MQTT-2519/OTA/Firmware
1603888134: Sending SUBACK to ESP32_0f2519
1603888134: Received SUBSCRIBE from ESP32_0f2519
1603888134:     BLE2MQTT/OTA/Firmware (QoS 0)
1603888134: ESP32_0f2519 0 BLE2MQTT/OTA/Firmware
1603888134: Sending SUBACK to ESP32_0f2519
1603888134: Received SUBSCRIBE from ESP32_0f2519
1603888134:     BLE2MQTT-2519/OTA/Config (QoS 0)
1603888134: ESP32_0f2519 0 BLE2MQTT-2519/OTA/Config
1603888134: Sending SUBACK to ESP32_0f2519
1603888134: Received SUBSCRIBE from ESP32_0f2519
1603888134:     BLE2MQTT/OTA/Config (QoS 0)
1603888134: ESP32_0f2519 0 BLE2MQTT/OTA/Config
1603888134: Sending SUBACK to ESP32_0f2519
1603888136: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Connected', ... (4 bytes))
1603888136: Sending PUBLISH to mosq-j2DRlsCHWt1WPQhAY4 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Connected', ... (4 bytes))
1603888136: Received SUBSCRIBE from ESP32_0f2519
1603888136:     03:b3:ec:8d:f0:f1/Connected (QoS 0)
1603888136: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Connected
1603888136: Sending SUBACK to ESP32_0f2519
1603888136: Sending PUBLISH to ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Connected', ... (4 bytes))
1603888136: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Owner', ... (14 bytes))
1603888136: Sending PUBLISH to mosq-j2DRlsCHWt1WPQhAY4 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Owner', ... (14 bytes))
1603888136: Received SUBSCRIBE from ESP32_0f2519
1603888136:     03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set (QoS 0)
1603888136: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set
1603888136: Sending SUBACK to ESP32_0f2519
1603888136: Received SUBSCRIBE from ESP32_0f2519
1603888136:     03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Get (QoS 0)
1603888136: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Get
1603888136: Sending SUBACK to ESP32_0f2519
1603888136: Received SUBSCRIBE from ESP32_0f2519
1603888136:     03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Set (QoS 0)
1603888136: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Set
1603888136: Sending SUBACK to ESP32_0f2519
1603888137: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb', ... (1 bytes))
1603888137: Sending PUBLISH to mosq-j2DRlsCHWt1WPQhAY4 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb', ... (1 bytes))
1603888145: New connection from 192.168.178.78 on port 1883.
1603888145: Client ESP32_0f2519 already connected, closing old connection.
1603888145: New client connected from 192.168.178.78 as ESP32_0f2519 (p2, c1, k120).
1603888145: No will message specified.
1603888145: Sending CONNACK to ESP32_0f2519 (0, 0)
1603888145: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/Version', ... (18 bytes))
1603888145: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/ConfigVersion', ... (64 bytes))
1603888145: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/Uptime', ... (1 bytes))
1603888145: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/FreeMemory', ... (5 bytes))
1603888145: Received SUBSCRIBE from ESP32_0f2519
1603888145:     BLE2MQTT-2519/OTA/Firmware (QoS 0)
1603888145: ESP32_0f2519 0 BLE2MQTT-2519/OTA/Firmware
1603888145: Sending SUBACK to ESP32_0f2519
1603888145: Received SUBSCRIBE from ESP32_0f2519
1603888145:     BLE2MQTT/OTA/Firmware (QoS 0)
1603888145: ESP32_0f2519 0 BLE2MQTT/OTA/Firmware
1603888145: Sending SUBACK to ESP32_0f2519
1603888145: Received SUBSCRIBE from ESP32_0f2519
1603888145:     BLE2MQTT-2519/OTA/Config (QoS 0)
1603888145: ESP32_0f2519 0 BLE2MQTT-2519/OTA/Config
1603888145: Sending SUBACK to ESP32_0f2519
1603888145: Received SUBSCRIBE from ESP32_0f2519
1603888145:     BLE2MQTT/OTA/Config (QoS 0)
1603888145: ESP32_0f2519 0 BLE2MQTT/OTA/Config
1603888145: Sending SUBACK to ESP32_0f2519
1603888147: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/Type', ... (14 bytes))
1603888147: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/RSSI', ... (4 bytes))
1603888147: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/MACAddress', ... (17 bytes))
1603888147: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/MessageCounter', ... (1 bytes))
1603888150: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Connected', ... (4 bytes))
1603888150: Sending PUBLISH to mosq-j2DRlsCHWt1WPQhAY4 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Connected', ... (4 bytes))
1603888150: Received SUBSCRIBE from ESP32_0f2519
1603888150:     03:b3:ec:8d:f0:f1/Connected (QoS 0)
1603888150: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Connected
1603888150: Sending SUBACK to ESP32_0f2519
1603888150: Sending PUBLISH to ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Connected', ... (4 bytes))
1603888150: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Owner', ... (14 bytes))
1603888150: Sending PUBLISH to mosq-j2DRlsCHWt1WPQhAY4 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Owner', ... (14 bytes))
1603888150: Received SUBSCRIBE from ESP32_0f2519
1603888150:     03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set (QoS 0)
1603888150: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set
1603888150: Sending SUBACK to ESP32_0f2519
1603888150: Received SUBSCRIBE from ESP32_0f2519
1603888150:     03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Get (QoS 0)
1603888150: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Get
1603888150: Sending SUBACK to ESP32_0f2519
1603888150: Received SUBSCRIBE from ESP32_0f2519
1603888150:     03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Set (QoS 0)
1603888150: ESP32_0f2519 0 03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb/Set
1603888150: Sending SUBACK to ESP32_0f2519
1603888150: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, '03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb', ... (1 bytes))
1603888150: Sending PUBLISH to mosq-j2DRlsCHWt1WPQhAY4 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/0000ffb3-0000-1000-8000-00805f9b34fb', ... (1 bytes))
1603888162: Received PINGREQ from mosq-j2DRlsCHWt1WPQhAY4
1603888162: Sending PINGRESP to mosq-j2DRlsCHWt1WPQhAY4

What could be another reason for this? 000ffb2 is the characterstic of interest, when I debug it with my phone I get a lot of notifications. Might this be the issue?

shmuelzon commented 3 years ago

Hey,

0000ffb2-0000-1000-8000-00805f9b34fb supports only notifications. That means that it doesn't subscribe to something like 03:b3:ec:8d:f0:f1/Scale/0000ffb2-0000-1000-8000-00805f9b34fb/Set as it's not writeable. If I can't write values to it, there is no reason to listen on write requests. You should see publications on the 03:b3:ec:8d:f0:f1/Scale/0000ffb2-0000-1000-8000-00805f9b34fb topic once the device sends a notification.

You mentioned in the past that you need to write to the 0000ffb1-0000-1000-8000-00805f9b34fb characteristic first before you receive notifications. Have you done that? I don't see any publications on 03:b3:ec:8d:f0:f1/Scale/0000ffb1-0000-1000-8000-00805f9b34fb/Set in the MQTT logs.

Also, just to make sure we don't get stuck for any reason, you could add the following (untested) patch so we know there are no pending BLE operations:

diff --git a/main/ble.c b/main/ble.c
index fd9b919..2e161a2 100644
--- a/main/ble.c
+++ b/main/ble.c
@@ -164,7 +164,10 @@ static void ble_operation_dequeue(ble_operation_t **queue)

     /* Queue is empty, nothing to do */
     if (!operation)
+    {
+        ESP_LOGD(TAG, "Queue is empty, nothing to do");
         return;
+    }

     *queue = operation->next;
     ESP_LOGD(TAG, "Dequeue: type: %d, device: " MAC_FMT ", char: " UUID_FMT ", "

Let me know...

davidkipstar commented 3 years ago

Hello,

I did write to the characteristic but not in the example I pasted here. I still get a "Queue timer expired". I applied your patch and it shows the Queue is empty. As you can see here

D (23604) MQTT_CLIENT: Get data len= 1, topic len=36
D (23604) MQTT: Received: 03:b3:ec:8d:f0:f1/Scale/Activate/Set => 1 (1)

D (23614) BLE2MQTT: Got write request: 03:b3:ec:8d:f0:f1/Scale/Activate/Set, len: 1
D (23624) BLE: Enqueue: type: 2, device: 03:b3:ec:8d:f0:f1, char: 0000ffb1-0000-1000-8000-00805f9b34fb, len: 1, val: 0x3ffbb678
D (23794) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (24084) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)
D (24134) BLE: Queue timer expired
D (24134) BLE: Dequeue: type: 2, device: 03:b3:ec:8d:f0:f1, char: 0000ffb1-0000-1000-8000-00805f9b34fb, len: 1, val: 0x3ffbb678
D (24134) BLE: Received GATTC event 4 (ESP_GATTC_WRITE_CHAR_EVT), gattc_if 1
D (24144) BLE: Queue is empty, nothing to do
D (25114) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)

When I put logging to Info and I now renamed the 0000ffb1 characteristic to Activate and when I publish to it my esp disconnects from the MQTT broker.

1604015290: Sending CONNACK to mosq-DuayjyzniiV2TmIvcw (0, 0)
1604015290: Received PUBLISH from mosq-DuayjyzniiV2TmIvcw (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/Activate/Set', ... (3 bytes))
1604015290: Sending PUBLISH to mosq-9LiQjzzdoPYxdWUxWj (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/Activate/Set', ... (3 bytes))
1604015290: Sending PUBLISH to ESP32_0f2519 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/Activate/Set', ... (3 bytes))
1604015290: Received DISCONNECT from mosq-DuayjyzniiV2TmIvcw
1604015290: Client mosq-DuayjyzniiV2TmIvcw disconnected.
1604015305: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/Type', ... (14 bytes))
1604015305: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/RSSI', ... (3 bytes))
1604015305: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/MACAddress', ... (17 bytes))
1604015305: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/MessageCounter', ... (1 bytes))
1604015305: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/Uptime', ... (3 bytes))
1604015305: Received PUBLISH from ESP32_0f2519 (d0, q0, r1, m0, 'BLE2MQTT-2519/FreeMemory', ... (5 bytes))
1604015338: Received PINGREQ from mosq-9LiQjzzdoPYxdWUxWj
1604015338: Sending PINGRESP to mosq-9LiQjzzdoPYxdWUxWj
1604015344: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/Type', ... (14 bytes))
1604015344: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/RSSI', ... (3 bytes))
1604015344: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/MACAddress', ... (17 bytes))
1604015344: Received PUBLISH from ESP32_0f2519 (d0, q0, r0, m0, 'BLE2MQTT-2519/a4:c1:38:9a:58:70/MessageCounter', ... (1 bytes))
1604015355: New connection from 127.0.0.1 on port 1883.
1604015355: New client connected from 127.0.0.1 as mosq-LexTWd8khGPD3iH32u (p2, c1, k60).
1604015355: No will message specified.
1604015355: Sending CONNACK to mosq-LexTWd8khGPD3iH32u (0, 0)
1604015355: Received PUBLISH from mosq-LexTWd8khGPD3iH32u (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/Activate/Set', ... (1 bytes))
1604015355: Sending PUBLISH to mosq-9LiQjzzdoPYxdWUxWj (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/Activate/Set', ... (1 bytes))
1604015355: Sending PUBLISH to ESP32_0f2519 (d0, q0, r0, m0, '03:b3:ec:8d:f0:f1/Scale/Activate/Set', ... (1 bytes))
1604015355: Received DISCONNECT from mosq-LexTWd8khGPD3iH32u
1604015355: Client mosq-LexTWd8khGPD3iH32u disconnected.

I left the types field empty and write a single 1 in decimal, since the value I write on my phone is 0x01.

mosquitto_pub -t 03:b3:ec:8d:f0:f1/Scale/Activate/Set -m 1

If it helps, the behaviour on my phone looks like this.

19:37:18.492 Writing command to characteristic 0000ffb1-0000-1000-8000-00805f9b34fb
D 19:37:18.492 gatt.writeCharacteristic(0000ffb1-0000-1000-8000-00805f9b34fb, value=0x01)
I 19:37:18.495 Data written to 0000ffb1-0000-1000-8000-00805f9b34fb, value: (0x) 01
A 19:37:18.496 "(0x) 01" sent
I 19:37:18.819 Notification received from 0000ffb2-0000-1000-8000-00805f9b34fb, value: (0x) AC-05-00-00-00-00-CE-CE
A 19:37:18.819 "(0x) AC-05-00-00-00-00-CE-CE" received
I 19:37:19.845 Notification received from 0000ffb2-0000-1000-8000-00805f9b34fb, value: (0x) AC-05-00-00-00-00-CE-CE
A 19:37:19.845 "(0x) AC-05-00-00-00-00-CE-CE" received
I 19:37:20.532 Notification received from 0000ffb2-0000-1000-8000-00805f9b34fb, value: (0x) AC-05-00-00-E4-00-CE-B2
A 19:37:20.533 "(0x) AC-05-00-00-E4-00-CE-B2" received
I 19:37:20.670 Notification received from 0000ffb2-0000-1000-8000-00805f9b34fb, value: (0x) AC-05-00-01-52-00-CE-21

Kind regards and Thanks a lot :)

shmuelzon commented 3 years ago

@davidkipstar, I've updated the project to support the latest ESP-IDF release, v4.1. Could you please try to compile it and see if perhaps it works as expected there?

davidkipstar commented 3 years ago

Hello, Great to hear you made progress.

I could make your version work with the ESP-IDF release 4.1. But on my case I run again into overflow when I enable logging.

entry 0x40080688
I (60) boot: ESP-IDF v4.1 2nd stage bootloader
I (60) boot: compile time 22:39:12
I (60) boot: chip revision: 1
I (63) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (70) boot.esp32: SPI Speed      : 40MHz
I (75) boot.esp32: SPI Mode       : DIO
I (80) boot.esp32: SPI Flash Size : 4MB
I (84) boot: Enabling RNG early entropy source...
I (90) boot: Partition Table:
I (93) boot: ## Label            Usage          Type ST Offset   Length
I (100) boot:  0 nvs              WiFi data        01 02 00009000 00004000
I (108) boot:  1 otadata          OTA data         01 00 0000d000 00002000
I (116) boot:  2 phy_init         RF data          01 01 0000f000 00001000
I (123) boot:  3 ota_0            OTA app          00 10 00010000 00180000
I (131) boot:  4 ota_1            OTA app          00 11 00190000 00180000
I (138) boot:  5 fs_0             Unknown data     01 82 00310000 00040000
I (146) boot:  6 fs_1             Unknown data     01 82 00350000 00040000
I (153) boot: End of partition table
I (158) boot: No factory image, trying OTA 0
I (163) boot_comm: chip revision: 1, min. application chip revision: 0
I (170) esp_image: segment 0: paddr=0x00010020 vaddr=0x3f400020 size=0x53714 (341780) map
I (309) esp_image: segment 1: paddr=0x0006373c vaddr=0x3ffbdb60 size=0x065c8 ( 26056) load
I (320) esp_image: segment 2: paddr=0x00069d0c vaddr=0x40080000 size=0x00404 (  1028) load
0x40080000: _WindowOverflow4 at /home/david/esp/esp-idf/components/freertos/xtensa_vectors.S:1778

I (321) esp_image: segment 3: paddr=0x0006a118 vaddr=0x40080404 size=0x05f00 ( 24320) load
I (337) esp_image: segment 4: paddr=0x00070020 vaddr=0x400d0020 size=0x117830 (1144880) map
0x400d0020: _stext at ??:?

I (773) esp_image: segment 5: paddr=0x00187858 vaddr=0x40086304 size=0x16a30 ( 92720) load
0x40086304: r_lld_evt_restart at ??:?

E (814) esp_image: Image length 1630896 doesn't fit in partition length 1572864
E (814) boot: OTA app partition slot 0 is not bootable
E (817) esp_image: image at 0x190000 has invalid magic byte
W (823) esp_image: image at 0x190000 has invalid SPI mode 19
E (829) boot: OTA app partition slot 1 is not bootable
E (835) boot: No bootable app partitions in the partition table
ets Jun  8 2016 00:22:57

rst:0x3 (SW_RESET),boot:0x13 (SPI_FAST_FLASH_BOOT)
configsip: 0, SPIWP:0xee
clk_drv:0x00,q_drv:0x00,d_drv:0x00,cs0_drv:0x00,hd_drv:0x00,wp_drv:0x00
mode:DIO, clock div:2
load:0x3fff0030,len:4
load:0x3fff0034,len:6928
ho 0 tail 12 room 4
load:0x40078000,len:13072
load:0x40080400,len:3896
0x40080400: _init at ??:?

I applied your fix you gave me earlier

diff --git a/main/ble.c b/main/ble.c
index fd9b919..0d0c707 100644
--- a/main/ble.c
+++ b/main/ble.c
@@ -153,7 +153,7 @@ static inline void ble_operation_perform(ble_operation_t *operation)
         esp_ble_gattc_write_char_descr(g_gattc_if, operation->device->conn_id,
             operation->characteristic->client_config_handle, operation->len,
             operation->value,
-            ESP_GATT_WRITE_TYPE_NO_RSP, ESP_GATT_AUTH_REQ_NONE);
+            ESP_GATT_WRITE_TYPE, ESP_GATT_AUTH_REQ_NONE);
         break;
     }
 }

But it didn't solve the Overflow this time. Now I use idf.py flash -p /dev/ttyUSB0 followed by idf.py monitor

Kind regards

shmuelzon commented 3 years ago

I applied your fix you gave me earlier, but it didn't solve the Overflow this time.

Yes, in your boot logs, it states that the image size is too large, that's why it doesn't boot. Did you try the new image without debug logs?

davidkipstar commented 3 years ago

Hey, I tried it but it still didn't work. Now I used Info logger to see the log for writing values. And no matter what I config in data.json It is always showing val: 0x3ffba760 as value for my 0000ffb1-* charateristic but I need to wrtite a 0x01 to start notifications. Right now I have no types set but before I tried 8 bits and 16bits.

So for

mosquitto_pub -t 03:b3:ec:8d:f1:21/Scale/Activate/Set -m 0x01
mosquitto_pub -t 03:b3:ec:8d:f1:21/Scale/Activate/Set -m 1
mosquitto_pub -t 03:b3:ec:8d:f1:21/Scale/Activate/Set -m 000000000000001
mosquitto_pub -t 03:b3:ec:8d:f1:21/Scale/Activate/Set -m 9
mosquitto_pub -t 03:b3:ec:8d:f1:21/Scale/Activate/Set -m 1

I always get the following output.

I (72575) BLE2MQTT: Discovered BLE device: 5f:f9:2a:4f:a4:77 (RSSI: -90), not connecting
I (73245) BLE2MQTT: Connected to device: 03:b3:ec:8d:f1:21, scanning
I (73785) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (73825) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (73825) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/DeviceName = SWAN
I (73925) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a02-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (73925) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/Appearance = 0
I (74005) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (74005) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPrivacyFlag = false
I (74045) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f1:21, char: d618d002-6000-1000-8000-000000000000, len: 2, val: 0x3ffba760
I (74045) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPreferredConnectionParameters = 8,16,0,100
I (74045) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffe5794
I (74065) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (74315) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffe57b0
I (74315) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/Scale/Unit = 1
I (75775) BLE2MQTT: Discovered BLE device: 51:a5:04:0f:d9:d1 (RSSI: -91), not connecting
I (85535) BLE2MQTT: Discovered BLE device: a4:c1:38:b6:9b:51 (RSSI: -79), not connecting
I (88405) BLE2MQTT: Discovered Mijia Temp+Hum broadcaster
I (88415) BLE2MQTT: Discovered BLE device: a4:c1:38:9a:58:70 (RSSI: -83), not connecting
I (90005) BLE: Dequeue: type: 2, device: 03:b3:ec:8d:f1:21, char: 0000ffb1-0000-1000-8000-00805f9b34fb, len: 1, val: 0x3ffba760

Do you know what is going on? Kind regards :)

shmuelzon commented 3 years ago

Hey,

The 0x3ffba760 that's printed is just a pointer to the memory where the data that will be sent is saved, not the data itself, so that's not a problem. As for activating notifications, if it's a 16bit value and you haven't defined any types in your configuration file, then you should publish either 0,1 or 1,0, I'm not sure which endianness you need here. After that you should see in the logs that when it tries to write to the activation characteristic it will be a length of 2. That, with the fix pushed yesterday, should work.

Let me know how it goes

davidkipstar commented 3 years ago

Hey I checked your last commit. Apparently you suggested me this already here:

Hey,

Could you please try to apply the following patch and check if it helps?

diff --git a/main/ble.c b/main/ble.c
index fd9b919..0d0c707 100644
--- a/main/ble.c
+++ b/main/ble.c
@@ -153,7 +153,7 @@ static inline void ble_operation_perform(ble_operation_t *operation)
         esp_ble_gattc_write_char_descr(g_gattc_if, operation->device->conn_id,
             operation->characteristic->client_config_handle, operation->len,
             operation->value,
-            ESP_GATT_WRITE_TYPE_NO_RSP, ESP_GATT_AUTH_REQ_NONE);
+            ESP_GATT_WRITE_TYPE, ESP_GATT_AUTH_REQ_NONE);
         break;
     }
 }

Let me know how it works out.

Thanks!

I recloned your repo and tried again. So I already tried that out too, so I am still stuck with the same problem :/

shmuelzon commented 3 years ago

Well, at least I'm consistent :) OK, let's start from the top. You have some smart scale which exposes data on the 0000ffb2-0000-1000-8000-00805f9b34fb characteristic. In order to get notifications from it you need to write 0x0100 to the 0000ffb1-0000-1000-8000-00805f9b34fb characteristic. So, when you have this working on the nRF app, you first subscribe to 0000ffb2-0000-1000-8000-00805f9b34fb. Next, you write 0x0100 to the 0000ffb1-0000-1000-8000-00805f9b34fb characteristic and then start receiving notifications?

If so, let's start again, with the application from the master branch (commit 6168e2b), with full debug logs. Open the configuration menu with idf.py menuconfig. Search, using the / key, for the LOG_DEFAULT_LEVEL choice menu and select DEBUG. Next, search for the COMPILER_OPTIMIZATION choice menu and select Size. Build and flash. Once the application has loaded and connected to the scale, run:

mosquitto_pub -t "03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb1-0000-1000-8000-00805f9b34fb/Set" -m "01,00"

If that doesn't work, disconnect and try again with:

mosquitto_pub -t "03:b3:ec:8d:ef:16/0000ffb0-0000-1000-8000-00805f9b34fb/0000ffb1-0000-1000-8000-00805f9b34fb/Set" -m "00,01"

If neither of those work, attach here the full serial log and I'll see if I can see any issue there.

Thanks

davidkipstar commented 3 years ago

Hello,

True, very consistent. I changed your suggested optimization settings and now I can see the logs again. I don't write 0x0100 to my 0000ffb1-0000-1000-8000-00805f9b34f to activate but to the descriptor to enable notifications. But let's start from the nrf-app-log.

I need to do two steps:

  1. enable notifications by writing 0x0100 to 00002902-0000-1000-8000-00805f9b34fb descriptor
  2. write 1 byte as 0x01 to 0000ffb1-0000-1000-8000-00805f9b34fb

Then I receive notifcations on 0000ffb2-0000-1000-8000-00805f9b34fb with value (0x) AC-05-00-00-00-32-CE-00

- Device Name [R] (0x2A00)
- Appearance [R] (0x2A01)
- Peripheral Privacy Flag [R W] (0x2A02)
- Peripheral Preferred Connection Parameters [R] (0x2A04)
Generic Attribute (0x1801)
- Service Changed [I R] (0x2A05)
   Client Characteristic Configuration (0x2902)
Unknown Service (d618d000-6000-1000-8000-000000000000)
- Unknown Characteristic [W] (d618d001-6000-1000-8000-000000000000)
- Unknown Characteristic [N WNR] (d618d002-6000-1000-8000-000000000000)
   Client Characteristic Configuration (0x2902)
Unknown Service (0000ffb0-0000-1000-8000-00805f9b34fb)
- Unknown Characteristic [N] (0000ffb2-0000-1000-8000-00805f9b34fb)
   Client Characteristic Configuration (0x2902)
   Characteristic User Description (0x2901)
- Unknown Characteristic [WNR] (0000ffb1-0000-1000-8000-00805f9b34fb)
   Client Characteristic Configuration (0x2902)
   Characteristic User Description (0x2901)
- Unknown Characteristic [N R WNR] (0000ffb3-0000-1000-8000-00805f9b34fb)
   Client Characteristic Configuration (0x2902)
   Characteristic User Description (0x2901)
D   21:51:09.935    gatt.setCharacteristicNotification(00002a05-0000-1000-8000-00805f9b34fb, true)
D   21:51:09.942    gatt.setCharacteristicNotification(d618d002-6000-1000-8000-000000000000, true)
D   21:51:09.947    gatt.setCharacteristicNotification(0000ffb2-0000-1000-8000-00805f9b34fb, true)
D   21:51:09.949    gatt.setCharacteristicNotification(0000ffb3-0000-1000-8000-00805f9b34fb, true)
I   21:51:09.953    Connection parameters updated (interval: 12.5ms, latency: 0, timeout: 10000ms)
V   21:51:42.256    Enabling notifications for 0000ffb2-0000-1000-8000-00805f9b34fb
D   21:51:42.256    gatt.setCharacteristicNotification(0000ffb2-0000-1000-8000-00805f9b34fb, true)
D   21:51:42.260    gatt.writeDescriptor(00002902-0000-1000-8000-00805f9b34fb, value=0x0100)
I   21:51:42.313    Data written to descr. 00002902-0000-1000-8000-00805f9b34fb, value: (0x) 01-00
A   21:51:42.313    "Notifications enabled" sent
V   21:51:42.335    Notifications enabled for 0000ffb2-0000-1000-8000-00805f9b34fb
V   21:52:05.978    Writing command to characteristic 0000ffb1-0000-1000-8000-00805f9b34fb
D   21:52:05.978    gatt.writeCharacteristic(0000ffb1-0000-1000-8000-00805f9b34fb, value=0x01)
I   21:52:05.984    Data written to 0000ffb1-0000-1000-8000-00805f9b34fb, value: (0x) 01
A   21:52:05.984    "(0x) 01" sent
I   21:52:06.746    Notification received from 0000ffb2-0000-1000-8000-00805f9b34fb, value: (0x) AC-05-00-00-00-32-CE-00

from the logs I can now see

D (256807) MQTT_CLIENT: mqtt_enqueue id: 39127, type=8 successful
D (256807) OUTBOX: ENQUEUE msgid=39127, msg_type=8, len=53, size=106
D (256817) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/GenericAccess/Appearance/Get, id: 39127, type=8 successful
D (256827) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (256837) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (256837) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a02-0000-1000-8000-00805f9b34fb, properties: 0xa
D (256847) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (256867) MQTT: Subscribing to 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPrivacyFlag/Get
D (256867) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (256887) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (256887) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (256897) MQTT_CLIENT: msg_type=9, msg_id=13377
D (256897) MQTT_CLIENT: pending_id=39127, pending_msg_count = 2
D (256907) OUTBOX: DELETED msgid=13377, msg_type=8, remain size=53
D (256917) MQTT_CLIENT: Subscribe successful
D (256917) MQTT_CLIENT: mqtt_enqueue id: 33137, type=8 successful
D (256927) OUTBOX: ENQUEUE msgid=33137, msg_type=8, len=64, size=117
D (256927) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/GenericAccess/PeripheralPrivacyFlag/Get, id: 33137, type=8 successful
D (256937) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a02-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (256947) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (256957) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (256957) MQTT: Subscribing to 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPrivacyFlag/Set
D (256967) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (256987) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (256987) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (256997) MQTT_CLIENT: msg_type=9, msg_id=39127
D (256997) MQTT_CLIENT: pending_id=33137, pending_msg_count = 2
D (257007) OUTBOX: DELETED msgid=39127, msg_type=8, remain size=64
D (257007) MQTT_CLIENT: Subscribe successful
D (257017) MQTT_CLIENT: mqtt_enqueue id: 43789, type=8 successful
D (257017) OUTBOX: ENQUEUE msgid=43789, msg_type=8, len=64, size=128
D (257027) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/GenericAccess/PeripheralPrivacyFlag/Set, id: 43789, type=8 successful
D (257037) BLE2MQTT: Found new characteristic: service: 00001800-0000-1000-8000-00805f9b34fb, characteristic: 00002a04-0000-1000-8000-00805f9b34fb, properties: 0x2
D (257037) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257057) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257067) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257077) MQTT: Subscribing to 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPreferredConnectionParameters/Get
D (257077) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257087) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257097) MQTT_CLIENT: msg_type=9, msg_id=33137
D (257097) MQTT_CLIENT: pending_id=43789, pending_msg_count = 2
D (257107) OUTBOX: DELETED msgid=33137, msg_type=8, remain size=64
D (257117) MQTT_CLIENT: Subscribe successful
D (257117) MQTT_CLIENT: mqtt_enqueue id: 26188, type=8 successful
D (257127) OUTBOX: ENQUEUE msgid=26188, msg_type=8, len=82, size=146
D (257137) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/GenericAccess/PeripheralPreferredConnectionParameters/Get, id: 26188, type=8 successful
D (257147) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (257147) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257157) BLE2MQTT: Found new characteristic: service: 00001801-0000-1000-8000-00805f9b34fb, characteristic: 00002a05-0000-1000-8000-00805f9b34fb, properties: 0x22
D (257167) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257187) BLE2MQTT: Found new characteristic: service: d618d000-6000-1000-8000-000000000000, characteristic: d618d001-6000-1000-8000-000000000000, properties: 0x8
D (257187) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257207) MQTT: Subscribing to 03:b3:ec:8d:f1:21/d618d000-6000-1000-8000-000000000000/d618d001-6000-1000-8000-000000000000/Set
D (257207) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257227) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257227) MQTT_CLIENT: msg_type=9, msg_id=43789
D (257237) MQTT_CLIENT: pending_id=26188, pending_msg_count = 2
D (257237) OUTBOX: DELETED msgid=43789, msg_type=8, remain size=82
D (257247) MQTT_CLIENT: Subscribe successful
D (257247) MQTT_CLIENT: mqtt_enqueue id: 62521, type=8 successful
D (257257) OUTBOX: ENQUEUE msgid=62521, msg_type=8, len=102, size=184
D (257267) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/d618d000-6000-1000-8000-000000000000/d618d001-6000-1000-8000-000000000000/Set, id: 62521, type=8 successful
D (257277) BLE2MQTT: Found new characteristic: service: d618d000-6000-1000-8000-000000000000, characteristic: d618d002-6000-1000-8000-000000000000, properties: 0x14
D (257277) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257297) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257297) MQTT: Subscribing to 03:b3:ec:8d:f1:21/d618d000-6000-1000-8000-000000000000/d618d002-6000-1000-8000-000000000000/Set
D (257307) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257327) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257327) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257337) MQTT_CLIENT: msg_type=9, msg_id=26188
D (257347) MQTT_CLIENT: pending_id=62521, pending_msg_count = 2
D (257347) OUTBOX: DELETED msgid=26188, msg_type=8, remain size=102
D (257357) MQTT_CLIENT: Subscribe successful
D (257357) MQTT_CLIENT: mqtt_enqueue id: 46220, type=8 successful
D (257367) OUTBOX: ENQUEUE msgid=46220, msg_type=8, len=102, size=204
D (257377) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/d618d000-6000-1000-8000-000000000000/d618d002-6000-1000-8000-000000000000/Set, id: 46220, type=8 successful
D (257387) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:f1:21, char: d618d002-6000-1000-8000-000000000000, len: 2, val: 0x3ffdfdc4
D (257387) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (257387) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257397) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb2-0000-1000-8000-00805f9b34fb, properties: 0x10
D (257417) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257437) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257437) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (257447) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257437) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffe94e8
D (257457) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257477) MQTT_CLIENT: msg_type=9, msg_id=62521
D (257477) MQTT_CLIENT: pending_id=46220, pending_msg_count = 2
D (257487) OUTBOX: DELETED msgid=62521, msg_type=8, remain size=102
D (257487) MQTT_CLIENT: Subscribe successful
D (257497) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb1-0000-1000-8000-00805f9b34fb, properties: 0x4
D (257497) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257517) MQTT: Subscribing to 03:b3:ec:8d:f1:21/Scale/Activate/Set
D (257517) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257527) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257537) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257547) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257547) MQTT_CLIENT: msg_type=9, msg_id=46220
D (257557) MQTT_CLIENT: pending_id=46220, pending_msg_count = 1
D (257557) OUTBOX: DELETED msgid=46220, msg_type=8, remain size=0
D (257567) MQTT_CLIENT: Subscribe successful
D (257567) MQTT_CLIENT: mqtt_enqueue id: 7703, type=8 successful
D (257577) OUTBOX: ENQUEUE msgid=7703, msg_type=8, len=43, size=43
D (257587) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/Scale/Activate/Set, id: 7703, type=8 successful
D (257597) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb3-0000-1000-8000-00805f9b34fb, properties: 0x16
D (257607) MQTT: Subscribing to 03:b3:ec:8d:f1:21/Scale/Unit/Get
D (257617) MQTT_CLIENT: mqtt_enqueue id: 15299, type=8 successful
D (257617) OUTBOX: ENQUEUE msgid=15299, msg_type=8, len=39, size=82
D (257627) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/Scale/Unit/Get, id: 15299, type=8 successful
D (257637) BLE: Enqueue: type: 0, device: 03:b3:ec:8d:f1:21, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (257647) MQTT: Subscribing to 03:b3:ec:8d:f1:21/Scale/Unit/Set
D (257647) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257657) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257667) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257677) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257677) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257687) MQTT_CLIENT: msg_type=9, msg_id=7703
D (257687) MQTT_CLIENT: pending_id=15299, pending_msg_count = 2
D (257697) OUTBOX: DELETED msgid=7703, msg_type=8, remain size=39
D (257707) MQTT_CLIENT: Subscribe successful
D (257707) MQTT_CLIENT: mqtt_enqueue id: 53996, type=8 successful
D (257717) OUTBOX: ENQUEUE msgid=53996, msg_type=8, len=39, size=78
D (257717) MQTT_CLIENT: Sent subscribe topic=03:b3:ec:8d:f1:21/Scale/Unit/Set, id: 53996, type=8 successful
D (257727) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffed650
D (257727) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (257727) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257757) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257757) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257767) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257777) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257777) MQTT_CLIENT: msg_type=9, msg_id=15299
D (257787) MQTT_CLIENT: pending_id=53996, pending_msg_count = 2
D (257797) OUTBOX: DELETED msgid=15299, msg_type=8, remain size=39
D (257797) MQTT_CLIENT: Subscribe successful
D (257807) MQTT_CLIENT: mqtt_message_receive: first byte: 0x90
D (257807) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257817) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257827) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257827) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257837) MQTT_CLIENT: msg_type=9, msg_id=53996
D (257837) MQTT_CLIENT: pending_id=53996, pending_msg_count = 1
D (257847) OUTBOX: DELETED msgid=53996, msg_type=8, remain size=0
D (257857) MQTT_CLIENT: Subscribe successful
D (258237) BLE: Queue timer expired
D (258237) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a00-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (258267) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (258267) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:f1:21, 00002a00-0000-1000-8000-00805f9b34fb, 0x3ffeddc8, 4)
D (258277) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a01-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (258277) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/DeviceName = SWAN
D (258327) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (258327) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:f1:21, 00002a01-0000-1000-8000-00805f9b34fb, 0x3ffeddc8, 2)
D (258337) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a02-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (258337) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/Appearance = 0
D (258437) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (258437) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:f1:21, 00002a02-0000-1000-8000-00805f9b34fb, 0x3ffeddc8, 1)
D (258447) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 00002a04-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
I (258447) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPrivacyFlag = false
D (258557) BLE: Received GATTC event 3 (ESP_GATTC_READ_CHAR_EVT), gattc_if 1
D (258557) BLE2MQTT: Queuing event BLE_DEVICE_CHARACTERISTIC_VALUE (03:b3:ec:8d:f1:21, 00002a04-0000-1000-8000-00805f9b34fb, 0x3ffee114, 8)
D (258557) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f1:21, char: d618d002-6000-1000-8000-000000000000, len: 2, val: 0x3ffdfdc4
I (258567) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPreferredConnectionParameters = 8,16,0,100
D (258577) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffe94e8
D (258597) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (258667) BLE: Received GATTC event 9 (ESP_GATTC_WRITE_DESCR_EVT), gattc_if 1

You have said that notifications are automatically enabled, so there is no need to write to the descriptor. I can see it here

D (257397) BLE2MQTT: Found new characteristic: service: 0000ffb0-0000-1000-8000-00805f9b34fb, characteristic: 0000ffb2-0000-1000-8000-00805f9b34fb, properties: 0x10
D (257417) MQTT_CLIENT: mqtt_message_receive: read "remaining length" byte: 0x3
D (257437) MQTT_CLIENT: mqtt_message_receive: total message length: 5 (already read: 2)
D (257437) BLE: Received GATTC event 38 (ESP_GATTC_REG_FOR_NOTIFY_EVT), gattc_if 1
D (257447) MQTT_CLIENT: mqtt_message_receive: read_len=3
D (257437) BLE: Enqueue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffe94e8
D (257457) MQTT_CLIENT: mqtt_message_receive: transport_read():5 5
D (257477) MQTT_CLIENT: msg_type=9, msg_id=62521
D (257477) MQTT_CLIENT: pending_id=46220, pending_msg_count = 2
D (257487) OUTBOX: DELETED msgid=62521, msg_type=8, remain size=102
D (257487) MQTT_CLIENT: Subscribe successful

so it should be successfull, thus no need to write 0x0100 to the descriptor.

Then I do publish

mosquitto_pub -t 03:b3:ec:8d:f1:21/Scale/Activate/Set -m 1

And on my device it shows

D (283497) MQTT_CLIENT: Get data len= 1, topic len=36, total_data: 1 offset: 0
D (283507) MQTT: Received: 03:b3:ec:8d:f1:21/Scale/Activate/Set => 1 (1)

D (283517) BLE2MQTT: Got write request: 03:b3:ec:8d:f1:21/Scale/Activate/Set, len: 1
D (283527) BLE: Enqueue: type: 2, device: 03:b3:ec:8d:f1:21, char: 0000ffb1-0000-1000-8000-00805f9b34fb, len: 1, val: 0x3ffdfdc4
D (284037) BLE: Queue timer expired
D (284037) BLE: Dequeue: type: 2, device: 03:b3:ec:8d:f1:21, char: 0000ffb1-0000-1000-8000-00805f9b34fb, len: 1, val: 0x3ffdfdc4
D (284047) BLE: Received GATTC event 4 (ESP_GATTC_WRITE_CHAR_EVT), gattc_if 1
D (285237) BLE: Received GAP event 3 (ESP_GAP_BLE_SCAN_RESULT_EVT)

But I do not receive the desired notifications. For complete overview here is my config:

  "ble": {
    "whitelist" : [
            "03:B3:EC:8D:F0:F1",
            "03:B3:EC:8D:F1:21"
    ],
    "characteristics": {
            "definitions" : {
                    "0000ffb1-0000-1000-8000-00805f9b34fb" : {
                            "name" : "Activate"
                    },
                    "0000ffb3-0000-1000-8000-00805f9b34fb" : {
                            "name" : "Unit"
                    }
            },
            "blacklist" : [
                    "00002a05-0000-1000-8000-00805f9b34fb"
                    ]
    },
    "services" : {
            "definitions" : {
                    "0000ffb0-0000-1000-8000-00805f9b34fb" : {
                            "name" : "Scale"
                    }
            },
            "blacklist" : [
                    "00002a05-0000-1000-8000-00805f9b34fb"
            ]
    }
  }

Thanks a lot and kind regards

shmuelzon commented 3 years ago

Could you please try to also blacklist the d618d002-6000-1000-8000-000000000000 characteristic?

Your log ends with

I (258567) BLE2MQTT: Publishing: 03:b3:ec:8d:f1:21/GenericAccess/PeripheralPreferredConnectionParameters = 8,16,0,100
D (258577) BLE: Dequeue: type: 3, device: 03:b3:ec:8d:f1:21, char: 0000ffb2-0000-1000-8000-00805f9b34fb, len: 2, val: 0x3ffe94e8
D (258597) BLE: Dequeue: type: 0, device: 03:b3:ec:8d:f1:21, char: 0000ffb3-0000-1000-8000-00805f9b34fb, len: 0, val: 0x0
D (258667) BLE: Received GATTC event 9 (ESP_GATTC_WRITE_DESCR_EVT), gattc_if 1

I see two attempts to write the characteristic description and one read attempt but only a single ESP_GATTC_WRITE_DESCR_EVT event from the BLE stack confirming the write operation to the characteristic description. I don't know if it's because the log was truncated or if something there simply failed. Either way, the nRF app doesn't write to it so it may help...

davidkipstar commented 3 years ago

Blacklisting didn't change much. I appended the whole log after the device is found. log.txt