Central on Linux: delay before service discovery?

[lxndrd]

Hi, thank you for this amazing project!

Trying out the Linux central example, the client.services_by_uuid(...) doesn't return, unless I add a small delay before it.
It seems like the issue is that the service discovery request gets ignored because of MTU exchange request?
The peripheral is an nRF52 device running nRF SDK 17 based firmware.
Have you seen similar behavior before? Any ideas on how I can get rid of this delay?

--- a/examples/apps/src/ble_bas_central.rs
+++ b/examples/apps/src/ble_bas_central.rs
@@ -50,6 +50,7 @@ where

         let _ = join(client.task(), async {
             info!("Looking for battery service");
+            Timer::after(Duration::from_millis(200)).await;
             let services = client.services_by_uuid(&Uuid::new_short(0x180f)).await.unwrap();
             let service = services.first().unwrap().clone();

HCI log without the delay:

No.     Time            Proto   Length  Info
25      0.000025        HCI_CMD 29      Sent LE Create Connection
26      0.001000        HCI_EVT 7       Rcvd Command Status (LE Create Connection)
27      0.135002        HCI_EVT 34      Rcvd LE Meta (LE Enhanced Connection Complete [v1])
28      0.135199        ATT     12      Sent Exchange MTU Request, Client Rx MTU: 247
29      0.135208        ATT     32      Sent Find By Type Value Request, Primary Service, Handles: 0x0001..0xffff
30      0.178993        HCI_EVT 8       Rcvd Number of Completed Packets
31      0.180580        ATT     12      Rcvd Exchange MTU Request, Client Rx MTU: 247
32      0.180687        ATT     12      Sent Exchange MTU Response, Server Rx MTU: 247
33      0.259990        HCI_EVT 8       Rcvd Number of Completed Packets
34      0.339581        ATT     12      Rcvd Exchange MTU Response, Server Rx MTU: 247
35      0.419985        HCI_EVT 8       Rcvd Number of Completed Packets
36      0.420987        HCI_EVT 14      Rcvd LE Meta (LE Data Length Change)
37      5.307101        HCI_EVT 7       Rcvd Disconnect Complete

HCI log with delay:

No.     Time            Proto   Length  Info
64      0.002002        HCI_EVT 7       Rcvd Command Status (LE Create Connection)
65      0.194990        HCI_EVT 34      Rcvd LE Meta (LE Enhanced Connection Complete [v1])
66      0.195298        ATT     12      Sent Exchange MTU Request, Client Rx MTU: 247
67      0.234000        HCI_EVT 8       Rcvd Number of Completed Packets
68      0.235684        ATT     12      Rcvd Exchange MTU Request, Client Rx MTU: 247
69      0.235885        ATT     12      Sent Exchange MTU Response, Server Rx MTU: 247
70      0.393991        HCI_EVT 8       Rcvd Number of Completed Packets
71      0.395334        ATT     32      Sent Find By Type Value Request, Primary Service, Handles: 0x0001..0xffff
72      0.395697        ATT     12      Rcvd Exchange MTU Response, Server Rx MTU: 247
73      0.474994        HCI_EVT 14      Rcvd LE Meta (LE Data Length Change)
74      0.553985        HCI_EVT 8       Rcvd Number of Completed Packets
75      0.635686        ATT     14      Rcvd Find By Type Value Response
76      0.635872        ATT     16      Sent Read By Type Request, Characteristic, Handles: 0x000b..0xffff
...

[lulf]

Interesting find! Yeah, it seems like it should wait until the mtu exchange response is processed before sending the next command. This needs a change to the gatt outbound processing logic to ensure there's only 1 outbound at a time. The challenge is that the att exchange is a shortcut not going through the gatt code, so it'd need to mark the connection in the connection manager somehow.

I raised #490 to track it.