diff --git a/TODO.md b/TODO.md index d9d521a55..b06166bb6 100644 --- a/TODO.md +++ b/TODO.md @@ -1,5 +1,38 @@ # Remaining tasks before declaring 1.0 +- turning off Bluetooth on oneplus causes a harmless exception - devwork is null + + +06-29 08:47:10.007 29788-29812/com.geeksville.mesh D/BluetoothGatt: configureMTU() - device: 24:62:AB:F8:40:9A mtu: 512 +06-29 08:47:10.007 29788-31466/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth: Starting failsafe timer 5000 +06-29 08:47:10.014 29788-29812/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth: work reconnect is completed, resuming status=0, res=kotlin.Unit +06-29 08:47:10.016 29788-31466/com.geeksville.mesh I/com.geeksville.mesh.service.BluetoothInterface: Connected to radio! +06-29 08:47:10.016 29788-31466/com.geeksville.mesh D/BluetoothGatt: refresh() - device: 24:62:AB:F8:40:9A +06-29 08:47:10.220 29788-31466/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth: Enqueuing work: reqMtu +06-29 08:47:15.009 29788-31466/com.geeksville.mesh E/com.geeksville.mesh.service.SafeBluetooth: Failsafe BLE timer expired! (exception none +06-29 08:47:15.011 29788-29859/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth: Starting failsafe timer 5000 +06-29 08:47:15.015 29788-31466/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth$BluetoothContinuation: Starting work: reqMtu +06-29 08:47:15.016 29788-31466/com.geeksville.mesh D/BluetoothGatt: configureMTU() - device: 24:62:AB:F8:40:9A mtu: 512 +06-29 08:47:15.028 29788-31466/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth: work reqMtu is completed, resuming status=4404, res=kotlin.Unit +06-29 08:47:15.029 29788-31466/com.geeksville.mesh W/com.geeksville.mesh.service.BluetoothInterface: Scheduling reconnect because Giving up on setting MTUs, forcing disconnect com.geeksville.mesh.service.SafeBluetooth$BLEStatusException: Bluetooth status=4404 while doing reqMtu +06-29 08:47:15.034 29788-30155/com.geeksville.mesh W/com.geeksville.mesh.service.BluetoothInterface: Forcing disconnect and hopefully device will comeback (disabling forced refresh) +06-29 08:47:15.034 29788-30155/com.geeksville.mesh I/com.geeksville.mesh.service.SafeBluetooth: Closing our GATT connection +06-29 08:47:15.035 29788-30155/com.geeksville.mesh D/BluetoothGatt: cancelOpen() - device: 24:62:AB:F8:40:9A +06-29 08:47:15.036 29788-30155/com.geeksville.mesh D/BluetoothGatt: close() +06-29 08:47:15.037 29788-30155/com.geeksville.mesh D/BluetoothGatt: unregisterApp() - mClientIf=5 +06-29 08:47:15.037 29788-29813/com.geeksville.mesh D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=24:62:AB:F8:40:9A +06-29 08:47:15.037 29788-29813/com.geeksville.mesh W/BluetoothGatt: Unhandled exception in callback + java.lang.NullPointerException: Attempt to invoke virtual method 'void android.bluetooth.BluetoothGattCallback.onConnectionStateChange(android.bluetooth.BluetoothGatt, int, int)' on a null object reference + at android.bluetooth.BluetoothGatt$1.onClientConnectionState(BluetoothGatt.java:182) + at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:70) + at android.os.Binder.execTransact(Binder.java:446) +06-29 08:47:16.040 29788-31466/com.geeksville.mesh W/com.geeksville.mesh.service.BluetoothInterface: Attempting reconnect +06-29 08:47:16.041 29788-31466/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth: Enqueuing work: connect +06-29 08:47:16.041 29788-31466/com.geeksville.mesh D/com.geeksville.mesh.service.SafeBluetooth$BluetoothContinuation: Starting work: connect +06-29 08:47:16.043 29788-31466/com.geeksville.mesh D/BluetoothGatt: connect() - device: 24:62:AB:F8:40:9A, auto: false +06-29 08:47:16.043 29788-31466/com.geeksville.mesh D/BluetoothGatt: registerApp() + +- soyes sx ble problems (again) - Android frontend should refetch the android messages from backend service on Resume - disable software update button after update finishes - first message sent is still doubled for some people diff --git a/app/build.gradle b/app/build.gradle index 01fc34618..e9010b104 100644 --- a/app/build.gradle +++ b/app/build.gradle @@ -17,8 +17,8 @@ android { applicationId "com.geeksville.mesh" minSdkVersion 21 // The oldest emulator image I have tried is 22 (though 21 probably works) targetSdkVersion 29 - versionCode 10781 // format is Mmmss (where M is 1+the numeric major number - versionName "0.7.81" + versionCode 10782 // format is Mmmss (where M is 1+the numeric major number + versionName "0.7.82" testInstrumentationRunner "androidx.test.runner.AndroidJUnitRunner" } buildTypes { diff --git a/app/src/main/java/com/geeksville/mesh/service/BluetoothInterface.kt b/app/src/main/java/com/geeksville/mesh/service/BluetoothInterface.kt index 3ec512a2e..6560919c4 100644 --- a/app/src/main/java/com/geeksville/mesh/service/BluetoothInterface.kt +++ b/app/src/main/java/com/geeksville/mesh/service/BluetoothInterface.kt @@ -285,10 +285,11 @@ class BluetoothInterface(val service: RadioInterfaceService, val address: String */ private fun forceServiceRefresh() { exceptionReporter { - // BluetoothGatt gatt - val gatt = safe!!.gatt!! - val refresh: Method = gatt.javaClass.getMethod("refresh") - refresh.invoke(gatt) + // If the gatt has been destroyed, skip the refresh attempt + safe?.gatt?.let { gatt -> + val refresh: Method = gatt.javaClass.getMethod("refresh") + refresh.invoke(gatt) + } } } diff --git a/app/src/main/java/com/geeksville/mesh/service/SafeBluetooth.kt b/app/src/main/java/com/geeksville/mesh/service/SafeBluetooth.kt index 02ae7d193..008fb0f99 100644 --- a/app/src/main/java/com/geeksville/mesh/service/SafeBluetooth.kt +++ b/app/src/main/java/com/geeksville/mesh/service/SafeBluetooth.kt @@ -10,7 +10,6 @@ import com.geeksville.android.Logging import com.geeksville.concurrent.CallbackContinuation import com.geeksville.concurrent.Continuation import com.geeksville.concurrent.SyncContinuation -import com.geeksville.util.Exceptions import com.geeksville.util.exceptionReporter import com.geeksville.util.ignoreException import kotlinx.coroutines.* @@ -60,27 +59,6 @@ class SafeBluetooth(private val context: Context, private val device: BluetoothD private val serviceScope = CoroutineScope(Dispatchers.IO) - /// When we see the BT stack getting disabled we handle that as a disconnect event - /* - private val btStateReceiver = BluetoothStateReceiver { enabled -> - // Sometimes we might not have a gatt object, while that is true, we don't care about BLE state changes - gatt?.let { g -> - if (!enabled) { - if (state == BluetoothProfile.STATE_CONNECTED) - gattCallback.onConnectionStateChange( - g, - 0, - BluetoothProfile.STATE_DISCONNECTED - ) - else { - debug("we are not connected, but BLE was disabled so shutdown everything") - closeConnection() - } - } - } - } - */ - /** * A BLE status code based error */ @@ -90,10 +68,6 @@ class SafeBluetooth(private val context: Context, private val device: BluetoothD private val configurationDescriptorUUID = longBLEUUID("2902") - init { - //context.registerReceiver( btStateReceiver, btStateReceiver.intent ) - } - /** * a schedulable bit of bluetooth work, includes both the closure to call to start the operation * and the completion (either async or sync) to call when it completes @@ -171,7 +145,10 @@ class SafeBluetooth(private val context: Context, private val device: BluetoothD } BluetoothProfile.STATE_DISCONNECTED -> { if (gatt == null) { - info("No gatt: ignoring connection state $newState, status $status") // Probably just shutting down + errormsg("No gatt: ignoring connection state $newState, status $status") + } else if (isClosing) { + info("Got disconnect because we are shutting down, closing gatt") + gatt = null g.close() // Finish closing our gatt here } else { // cancel any queued ops if we were already connected @@ -661,19 +638,53 @@ class SafeBluetooth(private val context: Context, private val device: BluetoothD cb: (Result) -> Unit ) = queueWriteDescriptor(c, CallbackContinuation(cb)) + /** + * Some old androids have a bug where calling disconnect doesn't guarantee that the onConnectionStateChange callback gets called + * but the only safe way to call gatt.close is from that callback. So we set a flag once we start closing and then poll + * until we see the callback has set gatt to null (indicating the CALLBACK has close the gatt). If the timeout expires we assume the bug + * has occurred, and we manually close the gatt here. + * + * Log of typical failure + * 06-29 08:47:15.035 29788-30155/com.geeksville.mesh D/BluetoothGatt: cancelOpen() - device: 24:62:AB:F8:40:9A + 06-29 08:47:15.036 29788-30155/com.geeksville.mesh D/BluetoothGatt: close() + 06-29 08:47:15.037 29788-30155/com.geeksville.mesh D/BluetoothGatt: unregisterApp() - mClientIf=5 + 06-29 08:47:15.037 29788-29813/com.geeksville.mesh D/BluetoothGatt: onClientConnectionState() - status=0 clientIf=5 device=24:62:AB:F8:40:9A + 06-29 08:47:15.037 29788-29813/com.geeksville.mesh W/BluetoothGatt: Unhandled exception in callback + java.lang.NullPointerException: Attempt to invoke virtual method 'void android.bluetooth.BluetoothGattCallback.onConnectionStateChange(android.bluetooth.BluetoothGatt, int, int)' on a null object reference + at android.bluetooth.BluetoothGatt$1.onClientConnectionState(BluetoothGatt.java:182) + at android.bluetooth.IBluetoothGattCallback$Stub.onTransact(IBluetoothGattCallback.java:70) + at android.os.Binder.execTransact(Binder.java:446) + * + * per https://github.com/don/cordova-plugin-ble-central/issues/473#issuecomment-367687575 + */ + @Volatile + private var isClosing = false /** Close just the GATT device but keep our pending callbacks active */ fun closeGatt() { gatt?.let { g -> info("Closing our GATT connection") - gatt = - null // Clear this first so the onConnectionChange callback can ignore while we are shutting down + isClosing = true try { g.disconnect() - g.close() // movedinto the onDisconnect callback? + + // Wait for our callback to run and handle hte disconnect + var msecsLeft = 1000 + while (gatt != null && msecsLeft >= 0) { + Thread.sleep(100) + msecsLeft -= 100 + } + + if (gatt != null) { + warn("Android onConnectionStateChange did not run, manually closing") + gatt?.close() + gatt = null + } } catch (ex: DeadObjectException) { - Exceptions.report(ex, "Dead object while closing GATT") + warn("Ignoring dead object exception, probably bluetooth was just disabled") + } finally { + isClosing = false } } } diff --git a/app/src/main/java/com/geeksville/mesh/ui/SettingsFragment.kt b/app/src/main/java/com/geeksville/mesh/ui/SettingsFragment.kt index 9f1eadf5b..956ec7bde 100644 --- a/app/src/main/java/com/geeksville/mesh/ui/SettingsFragment.kt +++ b/app/src/main/java/com/geeksville/mesh/ui/SettingsFragment.kt @@ -174,6 +174,7 @@ class BTScanModel(app: Application) : AndroidViewModel(app), Logging { private val scanCallback = object : ScanCallback() { override fun onScanFailed(errorCode: Int) { val msg = "Unexpected bluetooth scan failure: $errorCode" + errormsg(msg) // error code2 seeems to be indicate hung bluetooth stack errorText.value = msg } diff --git a/geeksville-androidlib b/geeksville-androidlib index b2871e409..b2d359e2e 160000 --- a/geeksville-androidlib +++ b/geeksville-androidlib @@ -1 +1 @@ -Subproject commit b2871e409cc3b24b00a26231f4efeb7e2dc170bb +Subproject commit b2d359e2e1c9ed0a931eb6f2d909355b2fd93cff