h2zero / NimBLE-Arduino

A fork of the NimBLE library structured for compilation with Arduino, for use with ESP32, nRF5x.
https://h2zero.github.io/NimBLE-Arduino/
Apache License 2.0
667 stars 138 forks source link

Rapid and Repeated: E NimBLEClient: Connection failed; status=574 Connection Failed to be Established #662

Closed Panometric closed 2 months ago

Panometric commented 2 months ago

I'm having a difficult time connecting. There are times when I get mostly failures to connect with code 574, occasionally it works. Other times it works the first try. I've turned on all the nimble debugging and no other messages are printed except connect and disconnect. What makes me think this is a bug is that the timing between the failures is sometimes not even a second, or sometimes several seconds, but always on very even 50 mS intervals, which looks like a race condition. It's always much less than the 30 second connection timeout.

My server device is advertising at 300 mS intervals, and on a power monitor. It's advertising behaviour is not changing at all. So it's not even starting attribute discovery. Retrying like was suggested in #140 does not always work. The percentage is just too low.

  1. I've think I've pinned to core 0, which should be the unused one, using this in platformio.ini build_flags = -DCONFIG_BT_NIMBLE_PINNED_TO_CORE=0
  2. Using default connection parameters
  3. Using default connection timeout.
  4. WiFI is disabled

Why wont it connect more reliably, and why is it returning failures so quickly?

Log where Time markers are in seconds, my device is PIXEL:

@   0.871 ScanStart
@   0.876 Found : c0:ca:96:ae:80:bb @ -91 RN4678-5221 - Reject
@   0.951 Found : fe:9e:ce:cf:38:b1 @ -88 N4REQ - Reject
@   0.964 Found : 47:43:7e:cc:07:f1 @ -64  - Reject
@   1.086 Found : 6a:d5:18:61:d5:11 @ -86  - Reject
@   1.1@   1.566 Found : 00:19:01:c0:43:c0 @ -94 YamahaAV - Reject
@   1.731 Found : a4:da:32:64:5e:d2 @ -79  - Reject
@   3.155 Found : 73:33:33:dd:31:84 @ -95  - Reject
@   5.233 Loops 89 last @   0.191 free 263104
@   8.097 Found : 00:a0:50:08:1d:0f @ -80 PIXEL Re - 
@   8.097 ScanStop
@   8.125 Scan completed with 9 results
@   8.625 Connect started.
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  10.232 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  13.332 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  21.532 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  28.532 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  34.932 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  37.132 Failed to connect
@  40.031 OnConnect
@  40.031 Connected to: 00:a0:50:08:1d:0f RSSI:-69
@  42.581 Discover Characteristic
@  43.731 Connect onConnParamsUpdateRequest( 80,160,4,501) 
@  44.031 ConnectToServer Done.
...
@  49.131 OnDisconnected
@  49.197 ScanStart
@  49.225 Found : 47:43:7e:cc:07:f1 @ -58  - Reject
@  49.258 Found : 6a:d5:18:61:d5:11 @ -87  - Reject
@  49.507 Found : c0:ca:96:ae:80:bb @ -92 RN4678-5221 - Reject
@  49.637 Found : 70:5b:99:a4:df:c5 @ -70  - Reject
@  50.638 Found : a4:da:32:64:5e:d2 @ -79  - Reject
@  50.645 Found : 73:33:33:dd:31:84 @ -92  - Reject
@  51.021 Found : 00:19:01:c0:43:c0 @ -94 YamahaAV - Reject
@  52.673 Found : 00:a0:50:08:1d:0f @ -70 PIXEL Re - 
@  52.673 ScanStop
@  52.678 Scan completed with 8 results, restarting.
@  53.178 Connect started.
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  56.982 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  59.732 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  60.632 Failed to connect
E NimBLEClient: Connection failed; status=574 Connection Failed to be Established
@  62.132 Failed to connect

Connection Code:

bool connectToServer()
{
    bool success = false, fresh = false;
    int connectretries = 10;
    static NimBLEClient *pClient; // Reuse the client if it exists.
    if (!pClient)
    {
        pClient = NimBLEDevice::createClient();
    }
    pBLEScan = NimBLEDevice::getScan();
    if (pBLEScan->isScanning()){
        pBLEScan->stop();
        while (pBLEScan->isScanning())
        {
            delay(500);
        };
    }
    delay(500);
    do
    {
        pClient->setClientCallbacks(&clientCB, false);
//      pClient->setConnectionParams(160, 160, 4, 501); // Causes many 574 erros when connecting. 
//      pClient->setConnectTimeout(10); // Seems to cause connection failures?
        Serial.printf("@ %7.3f Connect started.\r\n", millis() / 1000.0);

        // Frequently fails to connect, so retry a few times.
        // workaround per library author (h2zero): https://github.com/h2zero/NimBLE-Arduino/issues/140
        while (!pClient->connect(advDevice) && --connectretries)
        {
            // CRASHES NimBLEDevice::deleteClient(pClient);
            Serial.printf("@ %7.3f Failed to connect\r\n", millis() / 1000.0);
            delay(500);
        }
        if (connectretries<1)
        {
            break;
        }

        NimBLERemoteService *pSvc = nullptr;
        NimBLERemoteCharacteristic *pChr = nullptr;
        Serial.printf("@ %7.3f Connected to: %s RSSI:%d\r\n", millis() / 1000.0,
            pClient->getPeerAddress().toString().c_str(), pClient->getRssi());

        pSvc = pClient->getService(serviceUuid);
...
h2zero commented 2 months ago

Have you tried using a different esp32? some boards have crystals that aren't quite up to spec and get out of sync quickly.

Panometric commented 2 months ago

Thanks for getting back, actually I made some progress. I had these commented out in the scanner, because I did not think they were needed if using scan callbacks:

    //pBLEScan->setInterval(1349); 
    //pBLEScan->setWindow(449);

So I was getting zeros. Turns out if the window is zero, it makes it very difficult to connect. The examples are all over the place, but after tracking it down the default esp-idf value is 16 to get 10 ms. And if you want all the bandwidth used for BLE, the Window should be equal to the interval.

So an improvement might be to default them both to 16, and standardize the examples.