"Interrupting cancel all to terminate a pending connection..." hangs

[SaintNicholas]

Summary:

I have a button in my app, which connects to / disconnects from the peripheral depending on if we are connected to the device at the time the button was pressed. When I press this button to cause connect/disconnect sequences to happen very quickly, I can get bluejay to get hung up.

2019-06-24 09:46:54.183 [Bluejay] [main] > Bluejay.Connection added to queue with UUID: 9D6C0668-89E0-4592-972D-25519C9D6BD5. 2019-06-24 09:46:54.184 [Bluejay] [main] > Init Peripheral: <Bluejay.Peripheral: 0x1138adc10>, Optional(<CBPeripheral: 0x10ab306a0, identifier = BC21C4F8-8545-A51A-873F-25A51D8EB13D, name = Peripheral, state = disconnected>) 2019-06-24 09:46:54.184 [Bluejay] [main] > Queue will start Bluejay.Connection... 2019-06-24 09:46:54.185 [Bluejay] [main] > Started connecting to Peripheral. < At this point I pressed the button and our app did a disconnect(immediate: true) > 2019-06-24 09:46:54.362 [Bluejay] [main] > Explicit disconnect called. 2019-06-24 09:46:54.362 [Bluejay] [main] > Cancel everything called with error: Explicit disconnect, shouldDisconnect: true 2019-06-24 09:46:54.363 [Bluejay] [main] > Cancel everything called while still connecting... 2019-06-24 09:46:54.363 [Bluejay] [main] > Should auto-reconnect: false 2019-06-24 09:46:54.363 [Bluejay] [main] > Queue will now cancel all operations with error: Explicit disconnect 2019-06-24 09:46:54.364 [Bluejay] [main] > Cancelling a pending connection to HomeLink Mirror 2019-06-24 09:46:54.364 [Bluejay] [main] > Interrupting cancel all to terminate a pending connection... < At this point I let it sit for several minutes, and the block that I passed to the disconnect(immediate: true) never ran. I think that bluejay got hung up somewhere? >

Steps to Reproduce:

1. Press the connect/disconnect button very quickly, causing fast sequences of connecting and disconnecting.

Actual Result:

Bluejay seemed to get hung up, as shown in the log above.

Expected Result:

The connects/disconnects happen as expected.

Device, Build, OS:

iPhone Xs, Bluejay 0.8.5, iOS 12.3.1

[sakuraehikaru]

Hi @SaintNicholas, thanks for reporting this. I did a quick test using BluejayHeartSensorDemo with some alterations to better match the calls you're using, and I am unable to reproduce to freeze you're seeing.

I tried to toggle connect and disconnect quickly many times and repeatedly, but the queue doesn't seem to get stuck.

I might need a bit more information and details, such as whether your app performs other operations in any of Bluejay's either callbacks, or delegation.

[SaintNicholas]

Hi @JeremyChiang, I removed all of the other things happening in the app, other than the actual connect and disconnect, and was still able to get this to hang.

How were you toggling connect and disconnect? Was it with a button? Can you share the code you were using?

The code I was using was really simple. Do you have any suggestions about how this could better use Bluejay?

{
    let bluejayWasDisconnected = !(bluejay.isConnected || bluejay.isConnecting)

    bluejay.disconnect(immediate: true) { _ in
        // We assume it's ok if this fails, because we are doing a disconnect regardless of if we are currently connected.
        
        // If we were disconnected when the button was pressed, we want to connect to this peripheral.
        if bluejayWasDisconnected {
            bluejay.connect(self.peripheralIdentifier, completion: { _ in
            })
        }
    }
}

[sakuraehikaru]

Hi @SaintNicholas your assumption inside the disconnect block is actually not correct. A disconnection attempt can fail and not complete (thus keeping you connected) in a few cases.

For examples, such as if you call disconnect while a Bluejay background task is executing, or if you call disconnect when there's a queued disconnect. There's a few other cases as well. See the implementation details starting at line 670 in Bluejay.swift for more info.

You should also check whether Bluejay is connected before you call disconnect (in pseudo-code):

if connected {
  disconnect()
}

not

let isConnected = Bluejay.isConnected // This captures the *current* state in another variable, it doesn't actually monitor and follow the changes of "Bluejay.isConnected"
disconnect {
 if isConnected // This will always be what was captured before the disconnect call, even if "Bluejay.isConnected" has changed
}

which doesn't quite make sense to me

The way I tested was simply using the available heart rate sensor demo. The only tweak I made was made the demo's disconnect immediate, so I can quickly toggle connect and disconnect like your test case. The demo uses a queued disconnect by default.

Hope that gives you a bit more to go on, please do let me know if you need more info.

[SaintNicholas]

Thanks @JeremyChiang , I took a look at the heart rate sensor demo.

Our connect/disconnect button is supposed to be set up such that:

• If we are disconnected from a peripheral, pressing the button starts connecting to it (at this point it will try to connect with no timeout - forever).
• If we are connecting, or connected, to a peripheral, then disconnect from the peripheral (if necessary) and make sure that we don't auto-reconnect to that peripheral.

My concern with using queued disconnects is that if we are trying to connect to a peripheral, with no timeout, and something is stopping us from connecting to the peripheral (like being out of range), the Connect event will sit in the queue forever, and the Disconnect event, which is later in the queue, will never be processed. That is why I was using immediate disconnects for this button. Based on this, do you think something more like the following would work better?

if bluejay.isConnecting || bluejay.isConnected {
    bluejay.disconnect(immediate: true)
} else {
    bluejay.connect()
}

[sakuraehikaru]

Yes that sample code looks good to me as well. That's basically how I tweaked the heart rate demo as well, and I couldn't repro a frozen/stuck state when I quickly tap the disconnect and connect buttons in rapid succession. The logs from the demo also seemed normal to me with the queue propagating and processing all events as expected.

If you can reproduce this bug, could you try break pointing through out the fail function in Connection.swift? Looking at the logs you've provided again, it seems like you are not reaching line 116, which should happen if you disconnect in the middle of a pending connection. I think whatever the cause of that is will give us more valuable info!

[SaintNicholas]

Thanks @JeremyChiang, I'll play with this next week and let you know how it goes.

[SaintNicholas]

@JeremyChiang - I played with this some more, using the logic that we had discussed, and I'm still seeing the issue. I stepped through the fail() function, and I do hit line 116. I added some more logging, and what I'm seeing is that in most cases when I see the string "Interrupting cancel all to terminate a pending connection..." in the code, the very next thing that happens is that Bluejay receives the public func centralManager(_ central: CBCentralManager, didDisconnectPeripheral peripheral: CBPeripheral, error: Error?) callback. However, when I see the hang, it seems to be hanging because Bluejay never receives the public func centralManager(_ central: CBCentralManager, didDisconnectPeripheral peripheral: CBPeripheral, error: Error?) callback.

I'm not sure what's going on, but even though Bluejay never received the callback, the peripheral is not connected.

[SaintNicholas]

@JeremyChiang Another piece of information.

I pulled Bluejay in locally and started observing CBPeripheral.state of the peripheral that we were connecting to, to see if that gave me any clues. What I saw was:

In the normal situation, where I see "Interrupting cancel all to terminate a pending connection...", the order of things seems to be:

• A Connection event is started, and Bluejay starts connecting to the peripheral.
• CBPeripheral is changed from .disconnected to .connecting.
• An explicit disconnect is started, which causes "Interrupting cancel all to terminate a pending connection..." to be seen.
• Because of the explicit disconnect, CBPeripheral.state is changed from .connecting to .disconnecting.
• After a short period of time, CBPeripheral.state changes from .disconnecting to .disconnected, and centralManager(_:didDisconnectPeripheral:error:) is called.

In the situation where it hangs when "Interrupting cancel all to terminate a pending connection..." is shown, CBPeripheral.state gets stuck in the .disconnected state, and centralManager(_:didDisconnectPeripheral:error:) is never called.

• A Connection event is started, and Bluejay starts connecting to the peripheral.
• CBPeripheral is changed from .disconnected to .connecting.
• An explicit disconnect is started, which causes "Interrupting cancel all to terminate a pending connection..." to be seen.
• Because of the explicit disconnect, CBPeripheral.state is changed from .connecting to .disconnecting.
• At this point nothing ever changes. The CBPeripheral.state is stuck in the .disconnecting state and centralManager(_:didDisconnectPeripheral:error:) is never called.
• When I turned Bluetooth off, I did see that the CBPeripheral.state changed from .disconnecting to .disconnected.

[sakuraehikaru]

Thank you for your report. This is on my radar, but we do have a few other features and fixes planned. We'll circle back to this as soon as we can.