JohanDegraeve / xdripswift

xdrip for iOS, written in Swift
GNU General Public License v3.0
329 stars 328 forks source link

Dexcom connection loops and potential cause for battery drains #494

Open LiroyvH opened 9 months ago

LiroyvH commented 9 months ago

Logging it on GitHub as well so it's tracked and more people could weigh in if they like: several reports have been submitted, notably from the Anubis community - but also from ONE and G6 users, that their transmitters' batteries are drained way faster than expected when using xDrip4iOS. Official transmitters seem to die in about 45-60 days and Anubii with a larger batteries in 90-110 days or earlier. (Note: Anubis with a proper battery typically easily last double that.)

I've spent quite some time looking in to possible causes (including some time spent with Joshua from the Anubis project, whom I'd like to thank for his insights on the Dexcom firmware), and it keeps coming back to a problem I've mentioned on several occasions over the years where the transmitter goes in to a connection loop with xDrip4iOS. (Eg: you see it connect, disconnect, reconnect, disconnect, reconnect, disconnect and so on and on.)

From what I can see, but do correct me if I'm wrong and/or if the log output is deceiving, the problem lies with xDrip4iOS attempting to reconnect to the transmitter without an apparent reason. When xDrip4iOS initiates a disconnect, it also immediately attempts to reconnect. The Dexcom transmitter will still be awake* and responds to our request to connect. However, as xDrip4iOS then blocks the connection because "last connection was less than x seconds ago": the transmitter doesn't get anything from us. The connection times out after 10 seconds, after which the Dexcom disconnects again. However, as soon as that happens: xDrip4iOS once again tries to connect to the transmitter as indicated in the logs ("Trying to reconnect..."). Once again, the Dexcom transmitter allows this connection but subsequently again xDrip4iOS will not actually send anything to the transmitter because the last connection was less than x ago. After a while of this going on and on, the Dexcom transmitter will give up and phones in again at the original timestamp +5 minutes to send its new readings.

The problem is that this cannot always be reproduced. It's unclear to me why xDrip4iOS sometimes tries to reconnect and sometimes doesn't. It might also be the order of the slots in which it's connecting that might make a difference, but either way: xDrip isn't supposed to try to reconnect, especially not when xDrip itself sent the command to disconnect in the first place. I noticed today that during warm-up a similar issue occurs, but that has different log-output that I haven't analyzed yet. Did also send it to Paul.

I think the underlying issue must still lie within the original FireFly implementation where this behavior was noted, but I think was essentially "dirty patched". (Ignoring the transmitter, which inadvertently keeps it awake for 10 seconds until it times out. And then we ask it to connect again. It's like prank calling someone and every time they pick up you don't say anything.)

Here's an excerpt from the logfiles what that looks like:

2023-11-30 11:58:26.4810 4.12.0 4190 BlueToothTransmitter               error: The specified device has disconnected from us.
2023-11-30 11:58:26.4940 4.12.0 4190 BlueToothTransmitter               Will try to reconnect
2023-11-30 12:02:12.5240 4.12.0 4190 BlueToothTransmitter           connected to peripheral with name DexcomTS
2023-11-30 12:02:12.5830 4.12.0 4190 BlueToothTransmitter           didDiscoverServices for peripheral with name DexcomTS

And a longer look of such a cycle (including when it phones in again to update the values and then it goes straight back in to a loop):

2023-11-30 11:52:22.8360 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:52:22.8410 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:52:22.8490 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:52:22.8540 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:52:22.8620 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:52:22.8660 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:52:23.3290 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:52:38.1970 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:52:38.2040 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:52:38.2240 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:52:38.2280 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:52:38.2380 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:52:38.2410 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:52:38.6600 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:52:53.4010 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:52:53.4060 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:52:53.4150 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:52:53.4180 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:52:53.4250 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:52:53.4290 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:52:53.9860 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:53:08.7430 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:53:08.7640 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:53:08.7700 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:53:08.7720 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:53:08.7750 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:53:08.7800 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:53:09.2250 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:53:23.9850 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:53:23.9890 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:53:23.9960 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:53:24.0000 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:53:24.0030 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:53:24.0050 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:53:24.4660 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:53:39.2100 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:53:39.2120 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:53:39.2180 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:53:39.2220 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:53:39.2280 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:53:39.2310 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:53:39.7050 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:53:54.4550 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:53:54.4590 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:53:54.4640 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:53:54.4710 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:53:54.4740 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:53:54.4810 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:53:55.0340 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:54:09.7850 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:54:09.7910 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:54:09.7950 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:54:09.7980 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:54:09.8060 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:54:09.8110 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:54:10.3060 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:54:25.0260 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:54:25.0320 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:54:25.0370 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:54:25.0430 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:54:25.0500 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:54:25.0520 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:54:25.6060 4.12.0 4190 BlueToothTransmitter connected to peripheral with name DexcomTS 2023-11-30 11:54:25.7480 4.12.0 4190 BlueToothTransmitter didDiscoverServices for peripheral with name DexcomTS 2023-11-30 11:54:25.7520 4.12.0 4190 BlueToothTransmitter Call discovercharacteristics for service with uuid F8083532-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:54:25.7560 4.12.0 4190 CGMG5 didDiscoverCharacteristicsFor 2023-11-30 11:54:25.7590 4.12.0 4190 CGMG5 characteristic : Communication 2023-11-30 11:54:25.7610 4.12.0 4190 CGMG5 characteristic UUID unknown : F8083538-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:54:25.7640 4.12.0 4190 CGMG5 characteristic : Write_Control 2023-11-30 11:54:25.7660 4.12.0 4190 CGMG5 characteristic : Receive_Authentication 2023-11-30 11:54:25.7680 4.12.0 4190 CGMG5 calling setNotifyValue true for characteristic Receive_Authentication 2023-11-30 11:54:25.7710 4.12.0 4190 CGMG5 characteristic : Backfill 2023-11-30 11:54:25.7730 4.12.0 4190 CGMG5 characteristic UUID unknown : F8083537-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:54:25.8090 4.12.0 4190 CGMG5 in peripheralDidUpdateNotificationStateFor. characteristic = Receive_Authentication 2023-11-30 11:54:25.8110 4.12.0 4190 CGMG5 characteristic : Receive_Authentication 2023-11-30 11:54:25.8160 4.12.0 4190 CGMG5 sending authMessage with data 01146a7282fd9d4c0f02 2023-11-30 11:54:25.8200 4.12.0 4190 BlueToothTransmitter in writeDataToPeripheral, for peripheral with name DexcomTS, for characteristic F8083535-849E-531C-C594-30F1F86A4EA5, data = 01146a7282fd9d4c0f02 2023-11-30 11:54:25.9280 4.12.0 4190 BlueToothTransmitter in didWriteValueFor. Characteristic F8083535-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:54:26.0640 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:54:26.0670 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:54:26.0690 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:54:26.0710 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:54:26.0780 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:54:26.0810 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:57:11.8910 4.12.0 4190 BlueToothTransmitter connected to peripheral with name DexcomTS 2023-11-30 11:57:11.9840 4.12.0 4190 BlueToothTransmitter didDiscoverServices for peripheral with name DexcomTS 2023-11-30 11:57:11.9880 4.12.0 4190 BlueToothTransmitter Call discovercharacteristics for service with uuid F8083532-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:57:11.9930 4.12.0 4190 CGMG5 didDiscoverCharacteristicsFor 2023-11-30 11:57:11.9960 4.12.0 4190 CGMG5 characteristic : Communication 2023-11-30 11:57:11.9980 4.12.0 4190 CGMG5 characteristic UUID unknown : F8083538-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:57:11.9990 4.12.0 4190 CGMG5 characteristic : Write_Control 2023-11-30 11:57:12.0020 4.12.0 4190 CGMG5 characteristic : Receive_Authentication 2023-11-30 11:57:12.0060 4.12.0 4190 CGMG5 calling setNotifyValue true for characteristic Receive_Authentication 2023-11-30 11:57:12.0100 4.12.0 4190 CGMG5 characteristic : Backfill 2023-11-30 11:57:12.0130 4.12.0 4190 CGMG5 characteristic UUID unknown : F8083537-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:57:12.0700 4.12.0 4190 CGMG5 in peripheralDidUpdateNotificationStateFor. characteristic = Receive_Authentication 2023-11-30 11:57:12.0740 4.12.0 4190 CGMG5 characteristic : Receive_Authentication 2023-11-30 11:57:12.0780 4.12.0 4190 CGMG5 sending authMessage with data 01175c1ab0b20e4a7802 2023-11-30 11:57:12.0810 4.12.0 4190 BlueToothTransmitter in writeDataToPeripheral, for peripheral with name DexcomTS, for characteristic F8083535-849E-531C-C594-30F1F86A4EA5, data = 01175c1ab0b20e4a7802 2023-11-30 11:57:12.1300 4.12.0 4190 BlueToothTransmitter in didWriteValueFor. Characteristic F8083535-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:57:12.1320 4.12.0 4190 BlueToothTransmitter in peripheralDidUpdateValueFor, data = 037b70caf21993d9bd6da888f17ebf29c3 2023-11-30 11:57:12.1340 4.12.0 4190 CGMG5 in peripheralDidUpdateValueFor, characteristic uuid = Receive_Authentication 2023-11-30 11:57:12.1350 4.12.0 4190 CGMG5 opcode = authRequestRx 2023-11-30 11:57:12.1390 4.12.0 4190 CGMG5 sending authChallengeTxMessage with data 048aa9c577423dedca 2023-11-30 11:57:12.1410 4.12.0 4190 BlueToothTransmitter in writeDataToPeripheral, for peripheral with name DexcomTS, for characteristic F8083535-849E-531C-C594-30F1F86A4EA5, data = 048aa9c577423dedca 2023-11-30 11:57:12.1900 4.12.0 4190 BlueToothTransmitter in didWriteValueFor. Characteristic F8083535-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:57:12.1930 4.12.0 4190 BlueToothTransmitter in peripheralDidUpdateValueFor, data = 050101 2023-11-30 11:57:12.1950 4.12.0 4190 CGMG5 in peripheralDidUpdateValueFor, characteristic uuid = Receive_Authentication 2023-11-30 11:57:12.1970 4.12.0 4190 CGMG5 opcode = authChallengeRx 2023-11-30 11:57:12.2000 4.12.0 4190 CGMG5 will set notifyValue for writeControlCharacteristic to true 2023-11-30 11:57:12.2020 4.12.0 4190 BlueToothTransmitter setNotifyValue, for peripheral with name DexcomTS, setting notify for characteristic F8083534-849E-531C-C594-30F1F86A4EA5, to true 2023-11-30 11:57:12.2040 4.12.0 4190 CGMG5 will set notifyValue for backfillCharacteristic to true 2023-11-30 11:57:12.2070 4.12.0 4190 BlueToothTransmitter setNotifyValue, for peripheral with name DexcomTS, setting notify for characteristic F8083536-849E-531C-C594-30F1F86A4EA5, to true 2023-11-30 11:57:12.2500 4.12.0 4190 CGMG5 in peripheralDidUpdateNotificationStateFor. characteristic = Write_Control 2023-11-30 11:57:12.2530 4.12.0 4190 CGMG5 characteristic : Write_Control 2023-11-30 11:57:12.2560 4.12.0 4190 CGMG5 start of firefly flow 2023-11-30 11:57:12.2610 4.12.0 4190 CGMG5 sending glucoseDataTxMessage with data 305336 2023-11-30 11:57:12.2640 4.12.0 4190 BlueToothTransmitter in writeDataToPeripheral, for peripheral with name DexcomTS, for characteristic F8083534-849E-531C-C594-30F1F86A4EA5, data = 305336 2023-11-30 11:57:12.2670 4.12.0 4190 CGMG5 in fireflyMessageFlow, did send glucoseTxMessage, setting glucoseTxSent to true 2023-11-30 11:57:12.3100 4.12.0 4190 CGMG5 in peripheralDidUpdateNotificationStateFor. characteristic = Backfill 2023-11-30 11:57:12.3130 4.12.0 4190 CGMG5 characteristic : Backfill 2023-11-30 11:57:12.3700 4.12.0 4190 BlueToothTransmitter in didWriteValueFor. Characteristic F8083534-849E-531C-C594-30F1F86A4EA5 2023-11-30 11:57:12.3740 4.12.0 4190 BlueToothTransmitter in peripheralDidUpdateValueFor, data = 31005007000050a808009e0006093a2c 2023-11-30 11:57:12.3760 4.12.0 4190 CGMG5 in peripheralDidUpdateValueFor, characteristic uuid = Write_Control 2023-11-30 11:57:12.3790 4.12.0 4190 CGMG5 opcode = glucoseRx 2023-11-30 11:57:12.3830 4.12.0 4190 CGMG5 in processGlucoseDataRxMessage, received glucoseDataRxMessage, value = 158.0, algorithm status = OK / Calibrated, transmitter status = 0 2023-11-30 11:57:12.3890 4.12.0 4190 CGMG5 start of firefly flow 2023-11-30 11:57:12.3910 4.12.0 4190 CGMG5 end of firefly flow 2023-11-30 11:57:12.3930 4.12.0 4190 CGMG5 will disconnect 2023-11-30 11:57:12.3950 4.12.0 4190 BlueToothTransmitter in disconnect, disconnecting, for peripheral with name DexcomTS 2023-11-30 11:57:12.4010 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:57:12.4040 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:57:12.4070 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:57:12.4130 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:57:12.4210 4.12.0 4190 CGMG5 adding glucose data that was received in GlucoseDataRxMessage/DexcomG6GlucoseDataRxMessage, value = 158.0, date = 11:57:12 CET 2023-11-30 11:57:12.4230 4.12.0 4190 CGMG5 calling cgmTransmitterInfoReceived with 1 values 2023-11-30 11:57:12.4270 4.12.0 4190 RootView transmitterBatteryInfo not received 2023-11-30 11:57:12.4290 4.12.0 4190 RootView sensor time in days not received 2023-11-30 11:57:12.4310 4.12.0 4190 RootView glucoseData size = 1 2023-11-30 11:57:12.4360 4.12.0 4190 RootView glucoseData 0, value = 158.0, timestamp = 11:57:12 CET 2023-11-30 11:57:12.4400 4.12.0 4190 RootView calibrator = NoCalibrator 2023-11-30 11:57:12.4690 4.12.0 4190 RootView timeStampToDelete = 11:36:12 CET 2023-11-30 11:57:13.3340 4.12.0 4190 RootView new reading created, timestamp = donderdag 30 november 2023 om 11:57:12 Midden-Europese standaardtijd, calculatedValue = 158,0 2023-11-30 11:57:14.6890 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:57:22.3450 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:57:22.3620 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:57:22.3770 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:57:22.3810 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:57:22.4270 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:57:22.4370 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:57:22.9090 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:57:37.6950 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:57:37.7020 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:57:37.7220 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:57:37.7240 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:57:37.7290 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:57:37.7320 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:57:38.2410 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:57:52.9980 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:57:53.0060 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:57:53.0220 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:57:53.0250 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:57:53.0300 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:57:53.0340 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:57:53.5120 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:58:08.3560 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:58:08.3800 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:58:08.7320 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:58:09.0170 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:58:09.0740 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:58:09.1490 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 11:58:09.6680 4.12.0 4190 CGMG5 connected to peripheral with name DexcomTS, but last reading was less than 2.1 minute ago, will let the connection timeout 2023-11-30 11:58:25.1470 4.12.0 4190 BlueToothTransmitter didDisconnect peripheral with name DexcomTS 2023-11-30 11:58:25.4450 4.12.0 4190 BluetoothPeripheralManager in didDisconnectFrom 2023-11-30 11:58:26.4810 4.12.0 4190 BlueToothTransmitter error: The specified device has disconnected from us. 2023-11-30 11:58:26.4940 4.12.0 4190 BlueToothTransmitter Will try to reconnect 2023-11-30 11:58:26.8530 4.12.0 4190 CGMG5 in sendGlucoseDataToDelegate 2023-11-30 11:58:27.0280 4.12.0 4190 CGMG5 glucoseDataArray has no values 2023-11-30 12:02:12.5240 4.12.0 4190 BlueToothTransmitter connected to peripheral with name DexcomTS 2023-11-30 12:02:12.5830 4.12.0 4190 BlueToothTransmitter didDiscoverServices for peripheral with name DexcomTS etc. etc.

It looks as if we don't yet expect a disconnect or that we do ask for it to disconnect, but another part of the code thinks its by error and tries to reconnect - but is then frustrated by the 2.1 minute thing. Note: in one of the very first implementations, of which I still have the source code laying around here if anyone's interested :P, this problem is continuous.

Anyway, I don't know IF this is the cause of the reported battery drains. But it seems very likely, as such: logging it as issue here. As an extra note: this seems to occur sooner for me when xDrip4iOS is woken up from slumber. (Eg: it got suspended, but transmitter wakes it up. I'll shamelessly plug my request for full implementation of Background Processing/Activity here which could potentially be good for overall stability (also compared to Loop, iAPS and the official Dexcom-app.))

* = The transmitter is still awake, because the Dexcom keeps listening for a brief moment on all 2 (or 3 in case of Anubis) connection slots to see if the second device (reader/pump) wants a connection as well or not. Instead, xDrip4iOS asks to be connected again - and it honors that request.

JohanDegraeve commented 6 months ago

I can confirm that the patch kills updating of BG values running in follower mode from Nightscout with the "Background Keep-alive" mode set to "Disabled". No BG updates happen until set to “Normal”, even with the screen on, while "Normal" mode does work.

the goal is to test in master mode, why did you test in follower mode? In the end this branch will not be merged, because there's another branch with lots of other changes. Goal is that @paulplant copies this minor change here to his branch

bjornoleh commented 6 months ago

I am doing the main testing in master mode on phones connected to Dexcom transmitters. The follower mode testing was just incidental when building to my phone that has only been used in follower mode. So just an FYI that there is a minor regression here for this specific case. Master mode works as expected.

JohanDegraeve commented 6 months ago

ok clear

paulplant commented 6 months ago

I can confirm that the patch kills updating of BG values running in follower mode from Nightscout with the "Background Keep-alive" mode set to "Disabled". No BG updates happen until set to “Normal”, even with the screen on, while "Normal" mode does work.

Yes, as Johan says, this regression was already fixed several weeks ago in the staging branch. The aim will be to finish everything and hopefully merge into develop (and release) latest tomorrow I guess.

bjornoleh commented 6 months ago

Thanks, @paulplant that’s great, I thought the regression was introduced here, I had not previously tested recent dev.

paulplant commented 6 months ago

@bjornoleh , @LiroyvH , @dnzxy probably still waaaaay too early to confirm anything, but please feedback here when you know anything so we can keep this issue open or close it. Cheers.

LiroyvH commented 6 months ago

Looking at what I see in-app (connection state and last connected mismatching last reading from time to time) and what the logs tell me: it's unfortunately still very frequently going in to connection loops with 5.1.4.

bjornoleh commented 6 months ago

Looking at what I see in-app (connection state and last connected mismatching last reading from time to time) and what the logs tell me: it's unfortunately still very frequently going in to connection loops with 5.1.4.

@LiroyvH , please try to reboot your phone if you didn’t already try that. I saw some issues where reconnects happened very frequently after building various other builds. A reboot fixed this, it seems.

LiroyvH commented 6 months ago

@bjornoleh Yep makes no difference. It’ll simply start doing it again at some point. Besides, the issue has been present for a very long time, phone's been rebooted for various reasons copious amounts of time in the meantime :P

Thing is, it shouldn't happen at all; also not after a fresh build. Connect, exchange data, disconnect - sleep until 5 minutes later; that's the flow. But xDrip for some reason often, but not always (especially not when the app is foregrounded (which is odd and one of the reasons why I’m still looking in to the BLE management aspect as other apps do not have these issues)),ends up in a connection loop. This btw doesn’t only drain the transmitter battery, but also causes red loops (failure to wake up or go in a connection loop then (I wonder sometimes if when the app is relaunching/waking up that it fails to work properly on the first connection for some reason and then goes in to a loop because the next attempt we tell ourselves to ignore it)); which has been forcing me to use the official Dexcom app due to reliability issues for months on end now, which really sucks. :(

bjornoleh commented 6 months ago

Ok, yes I am seeing the same now, very frequent reconnects (and reboot made no difference in this case...), I suppose this is what @LiroyvH calls a "connection loop"? It's strange, because sometimes it works well, with only reconnects every five minutes.

@JohanDegraeve: Should we try with a longer delayInSeconds? I have only been testing 2.0 seconds so far.

2024-04-04 10:15:43.3950 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:15:58.6240 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:16:13.8820 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:16:29.1200 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:16:44.3090 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:16:59.5420 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:17:14.9040 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:20:24.1520 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:20:33.9400 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:25:17.0040 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:25:26.9570 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:25:42.3830 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:25:57.6430 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:26:12.8960 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:26:28.1170 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:26:43.4100 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:26:58.7840 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:27:14.2040 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:30:22.7690 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:30:32.4800 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:35:18.7380 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:35:28.6460 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:40:18.6460 5.0.2 4196 BlueToothTransmitter               Will try to reconnect

Edit: adding some more context in the logs, although probably not too useful:

2024-04-04 10:15:43.3950 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:15:43.4040 5.0.2 4196 CGMG5                          connected to peripheral with name DexcomT2, but last reading was less than 2.1 minute ago, will let the connection timeout
2024-04-04 10:15:56.5720 5.0.2 4196 CGMG5                          in sendGlucoseDataToDelegate
2024-04-04 10:15:56.5740 5.0.2 4196 CGMG5                              glucoseDataArray has no values
2024-04-04 10:15:58.6150 5.0.2 4196 BlueToothTransmitter               didDisconnect peripheral with name DexcomT2
2024-04-04 10:15:58.6190 5.0.2 4196 BluetoothPeripheralManager     in didDisconnectFrom
2024-04-04 10:15:58.6220 5.0.2 4196 BlueToothTransmitter               error: The specified device has disconnected from us.
2024-04-04 10:15:58.6240 5.0.2 4196 BlueToothTransmitter               Will try to reconnect
2024-04-04 10:15:58.6280 5.0.2 4196 CGMG5                          connected to peripheral with name DexcomT2, but last reading was less than 2.1 minute ago, will let the connection timeout
2024-04-04 10:16:11.8090 5.0.2 4196 CGMG5                          in sendGlucoseDataToDelegate
2024-04-04 10:16:11.8110 5.0.2 4196 CGMG5                              glucoseDataArray has no values
2024-04-04 10:16:13.8740 5.0.2 4196 BlueToothTransmitter               didDisconnect peripheral with name DexcomT2
2024-04-04 10:16:13.8770 5.0.2 4196 BluetoothPeripheralManager     in didDisconnectFrom
2024-04-04 10:16:13.8800 5.0.2 4196 BlueToothTransmitter               error: The specified device has disconnected from us.
JohanDegraeve commented 6 months ago

@JohanDegraeve: Should we try with a longer delayInSeconds? I have only been testing 2.0 seconds so far.

it's worth trying, but there's a risk that withiin that longer period (like 3 seconds) the app gets suspended and if that happens the app will not reconnect anymore, unless you bring it back to the foreground. Don't try it while you sleep :)

LiroyvH commented 6 months ago

@JohanDegraeve @paulplant Was looking in to this again and noticed something I'm not sure of will make a difference. DisconnectTx (0x09) is defined in the Dexcom opcodes, but as far as I can tell isn't actually called anywhere in the flow - can't find a mention of it anywhere other than the DexcomOpCodes file. xDrip+ does seem to call it at the end of every connection. (https://github.com/NightscoutFoundation/xDrip/blob/master/app/src/main/java/com/eveningoutpost/dexdrip/services/G5CollectionService.java#L989-L998)

I'm not sure if it will make any difference, but on the other hand one could suppose the command isn't there for nothing and above all else: likely can’t hurt. Could we do the same and send the disconnect command to the transmitter at the end of the Dexcom flow (but before any iOS disconnect)? Just to be sure.

JohanDegraeve commented 5 months ago

I'm not sure if it will make any difference, but on the other hand one could suppose the command isn't there for nothing and above all else: likely can’t hurt. Could we do the same and send the disconnect command to the transmitter at the end of the Dexcom flow (but before any iOS disconnect)? Just to be sure.

Possibly. Go ahead and give it a try. I think you could do it here after having processed glucose data, https://github.com/JohanDegraeve/xdripswift/blob/master/xdrip/BluetoothTransmitter/CGM/Dexcom/G5/CGMG5Transmitter.swift#L1349 and https://github.com/JohanDegraeve/xdripswift/blob/master/xdrip/BluetoothTransmitter/CGM/Dexcom/G5/CGMG5Transmitter.swift#L1367

= writeDataToPeripheral(data: Data(for: .disconnectTx), characteristicToWriteTo: writeControlCharacteristic, type: .withResponse) or (I'm not sure if appendingCRC needs to be added i, i thinkn ot) = writeDataToPeripheral(data: Data(for: .disconnectTx).appendingCRC(), characteristicToWriteTo: writeControlCharacteristic, type: .withResponse)

LiroyvH commented 5 months ago

@JohanDegraeve Thanks! Like so? https://github.com/LiroyvH/xdripswift/compare/master...LiroyvH-DisconnectTx I've added that in and will give it a spin. :)

-edit- Adding that in as linked above makes the build fail with a couple of errors on the modified file:

JohanDegraeve commented 5 months ago

ok, this should avoid the error

if let writeControlCharacteristic = writeControlCharacteristic { _ = writeDataToPeripheral(data: Data(for: .disconnectTx), characteristicToWriteTo: writeControlCharacteristic, type: .withResponse) }

LiroyvH commented 5 months ago

@JohanDegraeve Yep, that made it built OK! Built and fingers crossed. :)

LiroyvH commented 5 months ago

@JohanDegraeve Too bad, no difference. :( Very first thing it did was go in to a loop heh! Figured I'd watch it a bit longer, but after 2 no problem readings it fell in to another loop until foregrounded. (Though that's not the universal solution either.) Oh well, it would've been really nice if it was this simple. :D

JohanDegraeve commented 5 months ago

Oh well, it would've been really nice if it was this simple. :D indeed

swright87 commented 2 months ago

Just wondering if any progress has been made on this bug? I quite like to use Anubis direct to xDrip4iOS, since sometimes xD misses a few beats from the Dexcom app every so often. Always much more consistent without using the Dexcom app at all.

LiroyvH commented 1 month ago

@swright87 No progress as far as I'm aware.