Add detailed fingerprint logging and a historical buffer.

This was done for face as part of I5021534069d59158dde4488ebb13ef90d339ee39 and this extends the pattern for fingerprint to enable better debugging of the listening state changes. Bug: 194817979 Test: manual (adb bugreport and verify recent auth attempts in logs) Test: atest KeyguardListenQueueTest Change-Id: Ib782c9e95c12a65496e2d0245f5f8169f478a6ca
2021-08-06 18:33:44 -07:00
parent ccdd40e587
commit 316fbf7672
5 changed files with 337 additions and 90 deletions
--- a/packages/SystemUI/src/com/android/keyguard/KeyguardFaceListenModel.kt
+++ b/packages/SystemUI/src/com/android/keyguard/KeyguardFaceListenModel.kt
@@ -1,28 +0,0 @@
-package com.android.keyguard
-
-import android.annotation.CurrentTimeMillisLong
-
-/**
- * Data class for tracking information associated with [KeyguardUpdateMonitor.shouldListenForFace]
- * method calls.
- */
-data class KeyguardFaceListenModel(
-    @CurrentTimeMillisLong val timeMillis: Long,
-    val userId: Int,
-    val isListeningForFace: Boolean,
-    val isBouncer: Boolean,
-    val isAuthInterruptActive: Boolean,
-    val isOccludingAppRequestingFaceAuth: Boolean,
-    val isKeyguardAwake: Boolean,
-    val isListeningForFaceAssistant: Boolean,
-    val isSwitchingUser: Boolean,
-    val isFaceDisabled: Boolean,
-    val isBecauseCannotSkipBouncer: Boolean,
-    val isKeyguardGoingAway: Boolean,
-    val isBiometricSettingEnabledForUser: Boolean,
-    val isLockIconPressed: Boolean,
-    val isScanningAllowedByStrongAuth: Boolean,
-    val isPrimaryUser: Boolean,
-    val isSecureCameraLaunched: Boolean,
-    val isFaceAuthenticated: Boolean
-)
--- a/packages/SystemUI/src/com/android/keyguard/KeyguardListenModel.kt
+++ b/packages/SystemUI/src/com/android/keyguard/KeyguardListenModel.kt
@@ -0,0 +1,77 @@
+package com.android.keyguard
+
+import android.annotation.CurrentTimeMillisLong
+import android.hardware.biometrics.BiometricAuthenticator.Modality
+import android.hardware.biometrics.BiometricAuthenticator.TYPE_FACE
+import android.hardware.biometrics.BiometricAuthenticator.TYPE_FINGERPRINT
+
+/** Verbose logging for various keyguard listening states. */
+sealed class KeyguardListenModel {
+    /** Timestamp of the state change. */
+    abstract val timeMillis: Long
+    /** Current user */
+    abstract val userId: Int
+    /** If keyguard is listening for the given [modality]. */
+    abstract val listening: Boolean
+    /** Sensor type */
+    @Modality abstract val modality: Int
+}
+
+/**
+ * Verbose debug information associated with [KeyguardUpdateMonitor.shouldListenForFingerprint].
+ */
+data class KeyguardFingerprintListenModel(
+    @CurrentTimeMillisLong override val timeMillis: Long,
+    override val userId: Int,
+    override val listening: Boolean,
+    // keep sorted
+    val biometricEnabledForUser: Boolean,
+    val bouncer: Boolean,
+    val canSkipBouncer: Boolean,
+    val credentialAttempted: Boolean,
+    val deviceInteractive: Boolean,
+    val dreaming: Boolean,
+    val encryptedOrLockdown: Boolean,
+    val fingerprintDisabled: Boolean,
+    val fingerprintLockedOut: Boolean,
+    val goingToSleep: Boolean,
+    val keyguardGoingAway: Boolean,
+    val keyguardIsVisible: Boolean,
+    val keyguardOccluded: Boolean,
+    val occludingAppRequestingFp: Boolean,
+    val primaryUser: Boolean,
+    val shouldListenForFingerprintAssistant: Boolean,
+    val switchingUser: Boolean,
+    val udfps: Boolean,
+    val userDoesNotHaveTrust: Boolean,
+    val userNeedsStrongAuth: Boolean
+) : KeyguardListenModel() {
+    override val modality: Int = TYPE_FACE
+}
+
+/**
+ * Verbose debug information associated with [KeyguardUpdateMonitor.shouldListenForFace].
+ */
+data class KeyguardFaceListenModel(
+    @CurrentTimeMillisLong override val timeMillis: Long,
+    override val userId: Int,
+    override val listening: Boolean,
+    // keep sorted
+    val authInterruptActive: Boolean,
+    val becauseCannotSkipBouncer: Boolean,
+    val biometricSettingEnabledForUser: Boolean,
+    val bouncer: Boolean,
+    val faceAuthenticated: Boolean,
+    val faceDisabled: Boolean,
+    val keyguardAwake: Boolean,
+    val keyguardGoingAway: Boolean,
+    val listeningForFaceAssistant: Boolean,
+    val lockIconPressed: Boolean,
+    val occludingAppRequestingFaceAuth: Boolean,
+    val primaryUser: Boolean,
+    val scanningAllowedByStrongAuth: Boolean,
+    val secureCameraLaunched: Boolean,
+    val switchingUser: Boolean
+) : KeyguardListenModel() {
+    override val modality: Int = TYPE_FINGERPRINT
+}
--- a/packages/SystemUI/src/com/android/keyguard/KeyguardListenQueue.kt
+++ b/packages/SystemUI/src/com/android/keyguard/KeyguardListenQueue.kt
@@ -0,0 +1,67 @@
+/*
+ * Copyright (C) 2021 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.keyguard
+
+import androidx.annotation.VisibleForTesting
+import java.io.PrintWriter
+import java.text.DateFormat
+import java.text.SimpleDateFormat
+import java.util.Date
+import java.util.Locale
+import kotlin.collections.ArrayDeque
+
+private val DEFAULT_FORMATTING = SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS", Locale.US)
+
+/** Queue for verbose logging checks for the listening state. */
+class KeyguardListenQueue(
+    val sizePerModality: Int = 20
+) {
+    private val faceQueue = ArrayDeque<KeyguardFaceListenModel>()
+    private val fingerprintQueue = ArrayDeque<KeyguardFingerprintListenModel>()
+
+    @get:VisibleForTesting val models: List<KeyguardListenModel>
+        get() = faceQueue + fingerprintQueue
+
+    /** Push a [model] to the queue (will be logged until the queue exceeds [sizePerModality]). */
+    fun add(model: KeyguardListenModel) {
+        val queue = when (model) {
+            is KeyguardFaceListenModel -> faceQueue.apply { add(model) }
+            is KeyguardFingerprintListenModel -> fingerprintQueue.apply { add(model) }
+        }
+
+        if (queue.size > sizePerModality) {
+            queue.removeFirstOrNull()
+        }
+    }
+
+    /** Print verbose logs via the [writer]. */
+    @JvmOverloads
+    fun print(writer: PrintWriter, dateFormat: DateFormat = DEFAULT_FORMATTING) {
+        val stringify: (KeyguardListenModel) -> String = { model ->
+            "    ${dateFormat.format(Date(model.timeMillis))} $model"
+        }
+
+        writer.println("  Face listen results (last ${faceQueue.size} calls):")
+        for (model in faceQueue) {
+            writer.println(stringify(model))
+        }
+        writer.println("  Fingerprint listen results (last ${fingerprintQueue.size} calls):")
+        for (model in fingerprintQueue) {
+            writer.println(stringify(model))
+        }
+    }
+}
--- a/packages/SystemUI/src/com/android/keyguard/KeyguardUpdateMonitor.java
+++ b/packages/SystemUI/src/com/android/keyguard/KeyguardUpdateMonitor.java
@@ -118,15 +118,11 @@ import com.google.android.collect.Lists;
 import java.io.FileDescriptor;
 import java.io.PrintWriter;
 import java.lang.ref.WeakReference;
-import java.text.SimpleDateFormat;
-import java.util.ArrayDeque;
 import java.util.ArrayList;
-import java.util.Date;
 import java.util.HashMap;
 import java.util.HashSet;
 import java.util.Iterator;
 import java.util.List;
-import java.util.Locale;
 import java.util.Map;
 import java.util.Map.Entry;
 import java.util.Set;
@@ -148,6 +144,7 @@ public class KeyguardUpdateMonitor implements TrustManager.TrustListener, Dumpab
    private static final boolean DEBUG = KeyguardConstants.DEBUG;
    private static final boolean DEBUG_SIM_STATES = KeyguardConstants.DEBUG_SIM_STATES;
    private static final boolean DEBUG_FACE = Build.IS_DEBUGGABLE;
+    private static final boolean DEBUG_FINGERPRINT = Build.IS_DEBUGGABLE;
    private static final boolean DEBUG_SPEW = false;
    private static final int FINGERPRINT_LOCKOUT_RESET_DELAY_MS = 600;

@@ -422,9 +419,8 @@ public class KeyguardUpdateMonitor implements TrustManager.TrustListener, Dumpab
    @VisibleForTesting
    SparseArray<BiometricAuthenticated> mUserFaceAuthenticated = new SparseArray<>();

-    // Keep track of recent calls to shouldListenForFace() for debugging.
-    private static final int FACE_LISTEN_CALLS_QUEUE_SIZE = 20;
-    private ArrayDeque<KeyguardFaceListenModel> mFaceListenModels;
+    // Keep track of recent calls to shouldListenFor*() for debugging.
+    private final KeyguardListenQueue mListenModels = new KeyguardListenQueue();

    private static int sCurrentUser;
    private Runnable mUpdateBiometricListeningState = this::updateBiometricListeningState;
@@ -2229,37 +2225,75 @@ public class KeyguardUpdateMonitor implements TrustManager.TrustListener, Dumpab

    @VisibleForTesting
    protected boolean shouldListenForFingerprint(boolean isUdfps) {
-        final boolean userDoesNotHaveTrust = !getUserHasTrust(getCurrentUser());
+        final int user = getCurrentUser();
+        final boolean userDoesNotHaveTrust = !getUserHasTrust(user);
+        final boolean shouldListenForFingerprintAssistant = shouldListenForFingerprintAssistant();
        final boolean shouldListenKeyguardState =
                mKeyguardIsVisible
                        || !mDeviceInteractive
                        || (mBouncer && !mKeyguardGoingAway)
                        || mGoingToSleep
-                        || shouldListenForFingerprintAssistant()
+                        || shouldListenForFingerprintAssistant
                        || (mKeyguardOccluded && mIsDreaming)
                        || (mKeyguardOccluded && userDoesNotHaveTrust
                            && (mOccludingAppRequestingFp || isUdfps));

        // Only listen if this KeyguardUpdateMonitor belongs to the primary user. There is an
        // instance of KeyguardUpdateMonitor for each user but KeyguardUpdateMonitor is user-aware.
+        final boolean biometricEnabledForUser = mBiometricEnabledForUser.get(user);
+        final boolean userCanSkipBouncer = getUserCanSkipBouncer(user);
+        final boolean fingerprintDisabledForUser = isFingerprintDisabled(user);
        final boolean shouldListenUserState =
                !mSwitchingUser
-                        && !isFingerprintDisabled(getCurrentUser())
+                        && !fingerprintDisabledForUser
                        && (!mKeyguardGoingAway || !mDeviceInteractive)
                        && mIsPrimaryUser
-                        && mBiometricEnabledForUser.get(getCurrentUser());
+                        && biometricEnabledForUser;

        final boolean shouldListenBouncerState =
                !(mFingerprintLockedOut && mBouncer && mCredentialAttempted);

+        final boolean isEncryptedOrLockdownForUser = isEncryptedOrLockdown(user);
+        final boolean userNeedsStrongAuth = userNeedsStrongAuth();
        final boolean shouldListenUdfpsState = !isUdfps
-                || (!getUserCanSkipBouncer(getCurrentUser())
-                    && !isEncryptedOrLockdown(getCurrentUser())
-                    && !userNeedsStrongAuth()
+                || (!userCanSkipBouncer
+                    && !isEncryptedOrLockdownForUser
+                    && !userNeedsStrongAuth
                    && userDoesNotHaveTrust
                    && !mFingerprintLockedOut);
-        return shouldListenKeyguardState && shouldListenUserState && shouldListenBouncerState
-                && shouldListenUdfpsState;
+
+        final boolean shouldListen = shouldListenKeyguardState && shouldListenUserState
+                && shouldListenBouncerState && shouldListenUdfpsState;
+
+        if (DEBUG_FINGERPRINT || DEBUG_SPEW) {
+            maybeLogListenerModelData(
+                    new KeyguardFingerprintListenModel(
+                        System.currentTimeMillis(),
+                        user,
+                        shouldListen,
+                        biometricEnabledForUser,
+                        mBouncer,
+                        userCanSkipBouncer,
+                        mCredentialAttempted,
+                        mDeviceInteractive,
+                        mIsDreaming,
+                        isEncryptedOrLockdownForUser,
+                        fingerprintDisabledForUser,
+                        mFingerprintLockedOut,
+                        mGoingToSleep,
+                        mKeyguardGoingAway,
+                        mKeyguardIsVisible,
+                        mKeyguardOccluded,
+                        mOccludingAppRequestingFp,
+                        mIsPrimaryUser,
+                        shouldListenForFingerprintAssistant,
+                        mSwitchingUser,
+                        isUdfps,
+                        userDoesNotHaveTrust,
+                        userNeedsStrongAuth));
+        }
+
+        return shouldListen;
    }

    /**
@@ -2283,12 +2317,12 @@ public class KeyguardUpdateMonitor implements TrustManager.TrustListener, Dumpab
                containsFlag(strongAuth, STRONG_AUTH_REQUIRED_AFTER_BOOT)
                        || containsFlag(strongAuth, STRONG_AUTH_REQUIRED_AFTER_TIMEOUT);

-        boolean canBypass = mKeyguardBypassController != null
+        final boolean canBypass = mKeyguardBypassController != null
                && mKeyguardBypassController.canBypass();
        // There's no reason to ask the HAL for authentication when the user can dismiss the
        // bouncer, unless we're bypassing and need to auto-dismiss the lock screen even when
        // TrustAgents or biometrics are keeping the device unlocked.
-        boolean becauseCannotSkipBouncer = !getUserCanSkipBouncer(user) || canBypass;
+        final boolean becauseCannotSkipBouncer = !getUserCanSkipBouncer(user) || canBypass;

        // Scan even when encrypted or timeout to show a preemptive bouncer when bypassing.
        // Lock-down mode shouldn't scan, since it is more explicit.
@@ -2296,69 +2330,72 @@ public class KeyguardUpdateMonitor implements TrustManager.TrustListener, Dumpab

        // If the device supports face detection (without authentication), allow it to happen
        // if the device is in lockdown mode. Otherwise, prevent scanning.
-        boolean supportsDetectOnly = !mFaceSensorProperties.isEmpty()
+        final boolean supportsDetectOnly = !mFaceSensorProperties.isEmpty()
                && mFaceSensorProperties.get(0).supportsFaceDetection;
        if (isLockDown && !supportsDetectOnly) {
            strongAuthAllowsScanning = false;
        }

        // If the face has recently been authenticated do not attempt to authenticate again.
-        boolean faceAuthenticated = getIsFaceAuthenticated();
+        final boolean faceAuthenticated = getIsFaceAuthenticated();
+        final boolean faceDisabledForUser = isFaceDisabled(user);
+        final boolean biometricEnabledForUser = mBiometricEnabledForUser.get(user);
+        final boolean shouldListenForFaceAssistant = shouldListenForFaceAssistant();

        // Only listen if this KeyguardUpdateMonitor belongs to the primary user. There is an
        // instance of KeyguardUpdateMonitor for each user but KeyguardUpdateMonitor is user-aware.
        final boolean shouldListen =
                (mBouncer || mAuthInterruptActive || mOccludingAppRequestingFace || awakeKeyguard
-                        || shouldListenForFaceAssistant())
-                && !mSwitchingUser && !isFaceDisabled(user) && becauseCannotSkipBouncer
-                && !mKeyguardGoingAway && mBiometricEnabledForUser.get(user) && !mLockIconPressed
+                        || shouldListenForFaceAssistant)
+                && !mSwitchingUser && !faceDisabledForUser && becauseCannotSkipBouncer
+                && !mKeyguardGoingAway && biometricEnabledForUser && !mLockIconPressed
                && strongAuthAllowsScanning && mIsPrimaryUser
                && (!mSecureCameraLaunched || mOccludingAppRequestingFace)
                && !faceAuthenticated;

        // Aggregate relevant fields for debug logging.
        if (DEBUG_FACE || DEBUG_SPEW) {
-            final KeyguardFaceListenModel model = new KeyguardFaceListenModel(
-                    System.currentTimeMillis(),
-                    user,
-                    shouldListen,
-                    mBouncer,
-                    mAuthInterruptActive,
-                    mOccludingAppRequestingFace,
-                    awakeKeyguard,
-                    shouldListenForFaceAssistant(),
-                    mSwitchingUser,
-                    isFaceDisabled(user),
-                    becauseCannotSkipBouncer,
-                    mKeyguardGoingAway,
-                    mBiometricEnabledForUser.get(user),
-                    mLockIconPressed,
-                    strongAuthAllowsScanning,
-                    mIsPrimaryUser,
-                    mSecureCameraLaunched,
-                    faceAuthenticated);
-            maybeLogFaceListenerModelData(model);
+            maybeLogListenerModelData(
+                    new KeyguardFaceListenModel(
+                        System.currentTimeMillis(),
+                        user,
+                        shouldListen,
+                        mAuthInterruptActive,
+                        becauseCannotSkipBouncer,
+                        biometricEnabledForUser,
+                        mBouncer,
+                        faceAuthenticated,
+                        faceDisabledForUser,
+                        awakeKeyguard,
+                        mKeyguardGoingAway,
+                        shouldListenForFaceAssistant,
+                        mLockIconPressed,
+                        mOccludingAppRequestingFace,
+                        mIsPrimaryUser,
+                        strongAuthAllowsScanning,
+                        mSecureCameraLaunched,
+                        mSwitchingUser));
        }

        return shouldListen;
    }

-    private void maybeLogFaceListenerModelData(KeyguardFaceListenModel model) {
+    private void maybeLogListenerModelData(KeyguardListenModel model) {
        // Too chatty, but very useful when debugging issues.
        if (DEBUG_SPEW) {
            Log.v(TAG, model.toString());
        }

        // Add model data to the historical buffer.
-        if (DEBUG_FACE && mFaceRunningState != BIOMETRIC_STATE_RUNNING
-                && model.isListeningForFace()) {
-            if (mFaceListenModels == null) {
-                mFaceListenModels = new ArrayDeque<>(FACE_LISTEN_CALLS_QUEUE_SIZE);
-            }
-            if (mFaceListenModels.size() >= FACE_LISTEN_CALLS_QUEUE_SIZE) {
-                mFaceListenModels.remove();
-            }
-            mFaceListenModels.add(model);
+        final boolean notYetRunning =
+                (DEBUG_FACE
+                    && model instanceof KeyguardFaceListenModel
+                    && mFaceRunningState != BIOMETRIC_STATE_RUNNING)
+                || (DEBUG_FINGERPRINT
+                    && model instanceof KeyguardFingerprintListenModel
+                    && mFingerprintRunningState != BIOMETRIC_STATE_RUNNING);
+        if (notYetRunning && model.getListening()) {
+            mListenModels.add(model);
        }
    }

@@ -3437,15 +3474,8 @@ public class KeyguardUpdateMonitor implements TrustManager.TrustListener, Dumpab
            pw.println("    enabledByUser=" + mBiometricEnabledForUser.get(userId));
            pw.println("    mSecureCameraLaunched=" + mSecureCameraLaunched);
        }
-        if (mFaceListenModels != null && !mFaceListenModels.isEmpty()) {
-            final SimpleDateFormat dateFormat =
-                    new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS", Locale.US);
-            pw.println("  Face listen results (last " + FACE_LISTEN_CALLS_QUEUE_SIZE + " calls):");
-            for (final KeyguardFaceListenModel model : mFaceListenModels) {
-                final String time = dateFormat.format(new Date(model.getTimeMillis()));
-                pw.println("    " + time + " " + model.toString());
-            }
-        }
+        mListenModels.print(pw);
+
        if (mIsAutomotive) {
            pw.println("  Running on Automotive build");
        }
--- a/packages/SystemUI/tests/src/com/android/keyguard/KeyguardListenQueueTest.kt
+++ b/packages/SystemUI/tests/src/com/android/keyguard/KeyguardListenQueueTest.kt
@@ -0,0 +1,101 @@
+/*
+ * Copyright (C) 2021 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package com.android.keyguard
+
+import android.testing.AndroidTestingRunner
+import androidx.test.filters.SmallTest
+import com.android.systemui.SysuiTestCase
+import com.google.common.truth.Truth.assertThat
+import org.junit.Test
+import org.junit.runner.RunWith
+
+@RunWith(AndroidTestingRunner::class)
+@SmallTest
+class KeyguardListenQueueTest : SysuiTestCase() {
+
+    @Test
+    fun testQueueIsBounded() {
+        val size = 5
+        val queue = KeyguardListenQueue(sizePerModality = size)
+
+        val fingerprints = List(100) { fingerprintModel(it) }
+        fingerprints.forEach { queue.add(it) }
+
+        assertThat(queue.models).containsExactlyElementsIn(fingerprints.takeLast(size))
+
+        val faces = List(100) { faceModel(it) }
+        faces.forEach { queue.add(it) }
+
+        assertThat(queue.models).containsExactlyElementsIn(
+            faces.takeLast(size) + fingerprints.takeLast(5)
+        )
+
+        repeat(100) {
+            queue.add(faceModel(-1))
+            queue.add(fingerprintModel(-1))
+        }
+        assertThat(queue.models).hasSize(2 * size)
+        assertThat(queue.models.count { it.userId == -1 }).isEqualTo(2 * size)
+    }
+}
+
+private fun fingerprintModel(user: Int) = KeyguardFingerprintListenModel(
+    timeMillis = System.currentTimeMillis(),
+    userId = user,
+    listening = false,
+    biometricEnabledForUser = false,
+    bouncer = false,
+    canSkipBouncer = false,
+    credentialAttempted = false,
+    deviceInteractive = false,
+    dreaming = false,
+    encryptedOrLockdown = false,
+    fingerprintDisabled = false,
+    fingerprintLockedOut = false,
+    goingToSleep = false,
+    keyguardGoingAway = false,
+    keyguardIsVisible = false,
+    keyguardOccluded = false,
+    occludingAppRequestingFp = false,
+    primaryUser = false,
+    shouldListenForFingerprintAssistant = false,
+    switchingUser = false,
+    udfps = false,
+    userDoesNotHaveTrust = false,
+    userNeedsStrongAuth = false
+)
+
+private fun faceModel(user: Int) = KeyguardFaceListenModel(
+    timeMillis = System.currentTimeMillis(),
+    userId = user,
+    listening = false,
+    authInterruptActive = false,
+    becauseCannotSkipBouncer = false,
+    biometricSettingEnabledForUser = false,
+    bouncer = false,
+    faceAuthenticated = false,
+    faceDisabled = false,
+    keyguardAwake = false,
+    keyguardGoingAway = false,
+    listeningForFaceAssistant = false,
+    lockIconPressed = false,
+    occludingAppRequestingFaceAuth = false,
+    primaryUser = false,
+    scanningAllowedByStrongAuth = false,
+    secureCameraLaunched = false,
+    switchingUser = false
+)