search

weliem / bluez_inc

A C library for Bluez (BLE) that hides all DBus communication. It doesn't get easier than this. This library can also be used in C++.
MIT License
83 stars 19 forks source link

Timout error #49

Closed GrubbyHalo closed 1 month ago

GrubbyHalo commented 1 month ago

I have an app that registers a characteristic. Nothing unusual at all. It works flawlessly on one of my devices but on the other it times out. specifically after running the app a second time. I am using the nRF Connect app as a client. I can't seem to figure out what the problem could be. If i run the bluetoothd with the -d and -n flags, this is the output on the second attempt (the one that fails). Any idea's would be appreciated.

bluetoothd[185674]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
bluetoothd[185674]: src/device.c:device_attach_att() Elevating security level since LTK is available
bluetoothd[185674]: attrib/gattrib.c:g_attrib_ref() 0x63c87160db70: g_attrib_ref=1 
bluetoothd[185674]: src/device.c:device_accept_gatt_profiles() initiator false
bluetoothd[185674]: profiles/gap/gas.c:gap_accept() GAP profile accept (DC:C4:9C:D1:7C:F2)
bluetoothd[185674]: src/service.c:change_state() 0x63c871609050: device DC:C4:9C:D1:7C:F2 profile gap-profile state changed: disconnected -> connected (0)
bluetoothd[185674]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
bluetoothd[185674]: src/gatt-database.c:send_notification_to_device() GATT server sending indication
bluetoothd[185674]: src/advertising.c:unregister_advertisement() UnregisterAdvertisement
bluetoothd[185674]: src/shared/mgmt.c:send_request() [0x0000] command 0x003f
bluetoothd[185674]: src/shared/mgmt.c:can_read_data() [0x0000] command 0x003f complete: 0x00
bluetoothd[185674]: src/shared/att.c:can_read_data() (chan 0x63c87160fe70) ATT PDU received: 0x10
bluetoothd[185674]: src/shared/gatt-server.c:read_by_grp_type_cb() Read By Grp Type - start: 0x0001 end: 0xffff
bluetoothd[185674]: src/shared/att.c:timeout_cb() (chan 0x63c87160fe70) Operation timed out: 0x02
bluetoothd[185674]: [0x63c8715fbf70] src/shared/gatt-client.c:exchange_mtu_cb() MTU Exchange failed. ATT ECODE: 0x00
bluetoothd[185674]: src/device.c:gatt_client_ready_cb() status: failed, error: 0
bluetoothd[185674]: src/device.c:device_svc_resolved() /org/bluez/hci0/dev_DC_C4_9C_D1_7C_F2 err -5
bluetoothd[185674]: src/shared/att.c:timeout_cb() (chan 0x63c87160fe70) Operation timed out: 0x1d
bluetoothd[185674]: src/gatt-database.c:service_changed_conf() 
bluetoothd[185674]: GLib: Invalid file descriptor.
bluetoothd[185674]: src/shared/att.c:disconnect_cb() (chan 0x63c87160fe70) Failed to obtain disconnect error: Bad file descriptor
bluetoothd[185674]: src/shared/att.c:disconnect_cb() Channel 0x63c87160fe70 disconnected: Success
bluetoothd[185674]: src/device.c:att_disconnected_cb() 
bluetoothd[185674]: src/device.c:att_disconnected_cb() Success (0)
bluetoothd[185674]: src/service.c:change_state() 0x63c871609050: device DC:C4:9C:D1:7C:F2 profile gap-profile state changed: connected -> disconnecting (0)
bluetoothd[185674]: src/service.c:change_state() 0x63c871609050: device DC:C4:9C:D1:7C:F2 profile gap-profile state changed: disconnecting -> disconnected (0)
bluetoothd[185674]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
bluetoothd[185674]: src/device.c:att_disconnected_cb() Automatic connection disabled
bluetoothd[185674]: src/gatt-database.c:btd_gatt_database_att_disconnected() 
bluetoothd[185674]: src/gatt-database.c:att_disconnected() 
bluetoothd[185674]: attrib/gattrib.c:g_attrib_unref() 0x63c87160db70: g_attrib_unref=0 
bluetoothd[185674]: src/shared/mgmt.c:can_read_data() [0x0000] event 0x000c
bluetoothd[185674]: src/adapter.c:dev_disconnected() Device DC:C4:9C:D1:7C:F2 disconnected, reason 2
bluetoothd[185674]: src/adapter.c:adapter_remove_connection() 
bluetoothd[185674]: plugins/policy.c:disconnect_cb() reason 2
bluetoothd[185674]: src/adapter.c:bonding_attempt_complete() hci0 bdaddr DC:C4:9C:D1:7C:F2 type 1 status 0xe
bluetoothd[185674]: src/device.c:device_bonding_complete() bonding (nil) status 0x0e
bluetoothd[185674]: src/device.c:device_bonding_failed() status 14
bluetoothd[185674]: src/adapter.c:resume_discovery() 
bluetoothd[185674]: src/advertising.c:register_advertisement() RegisterAdvertisement
bluetoothd[185674]: src/advertising.c:client_create() Adding proxy for /org/bluez/bincadvertisement
bluetoothd[185674]: src/advertising.c:register_advertisement() Registered advertisement at path /org/bluez/bincadvertisement
bluetoothd[185674]: src/advertising.c:parse_service_uuids() Adding ServiceUUID: 9bea406b-ede4-4234-b56e-e5beb77f3387
bluetoothd[185674]: src/advertising.c:refresh_extended_adv() Refreshing advertisement parameters: /org/bluez/bincadvertisement
bluetoothd[185674]: src/shared/mgmt.c:send_request() [0x0000] command 0x0054
bluetoothd[185674]: src/shared/mgmt.c:can_read_data() [0x0000] command 0x0054 complete: 0x00
bluetoothd[185674]: src/advertising.c:add_adv_params_callback() Refreshing advertisement data: /org/bluez/bincadvertisement
bluetoothd[185674]: src/shared/mgmt.c:send_request() [0x0000] command 0x0055
bluetoothd[185674]: src/shared/mgmt.c:can_read_data() [0x0000] command 0x0055 complete: 0x00
bluetoothd[185674]: src/advertising.c:add_adv_callback() Advertisement registered: /org/bluez/bincadvertisement

and another but slightly different log output

bluetoothd[185674]: src/gatt-database.c:connect_cb() New incoming LE ATT connection
bluetoothd[185674]: src/device.c:device_attach_att() Elevating security level since LTK is available
bluetoothd[185674]: attrib/gattrib.c:g_attrib_ref() 0x63c87160fe70: g_attrib_ref=1 
bluetoothd[185674]: src/device.c:device_accept_gatt_profiles() initiator false
bluetoothd[185674]: profiles/gap/gas.c:gap_accept() GAP profile accept (DC:C4:9C:D1:7C:F2)
bluetoothd[185674]: src/service.c:change_state() 0x63c871609050: device DC:C4:9C:D1:7C:F2 profile gap-profile state changed: disconnected -> connected (0)
bluetoothd[185674]: src/gatt-client.c:btd_gatt_client_connected() Device connected.
bluetoothd[185674]: src/advertising.c:unregister_advertisement() UnregisterAdvertisement
bluetoothd[185674]: src/shared/mgmt.c:send_request() [0x0000] command 0x003f
bluetoothd[185674]: src/shared/mgmt.c:can_read_data() [0x0000] command 0x003f complete: 0x00
bluetoothd[185674]: src/shared/att.c:disconnect_cb() Channel 0x63c87161b100 disconnected: Connection reset by peer
bluetoothd[185674]: src/device.c:att_disconnected_cb() 
bluetoothd[185674]: src/device.c:att_disconnected_cb() Connection reset by peer (104)
bluetoothd[185674]: src/service.c:change_state() 0x63c871609050: device DC:C4:9C:D1:7C:F2 profile gap-profile state changed: connected -> disconnecting (0)
bluetoothd[185674]: src/service.c:change_state() 0x63c871609050: device DC:C4:9C:D1:7C:F2 profile gap-profile state changed: disconnecting -> disconnected (0)
bluetoothd[185674]: src/gatt-client.c:btd_gatt_client_disconnected() Device disconnected. Cleaning up.
bluetoothd[185674]: src/device.c:att_disconnected_cb() Automatic connection disabled
bluetoothd[185674]: src/gatt-database.c:btd_gatt_database_att_disconnected() 
bluetoothd[185674]: src/gatt-database.c:att_disconnected() 
bluetoothd[185674]: attrib/gattrib.c:g_attrib_unref() 0x63c87160fe70: g_attrib_unref=0
weliem commented 1 month ago

Hard to tell what is going on. Looks like the MTU negotiation fails. You could try not doing that in the nRF app....

GrubbyHalo commented 1 month ago

Yes the MTU negotiation seems to be the issue. I changed it from the default of 23 to the max of 517 and it seems to work