Donate to e Foundation | Murena handsets with /e/OS | Own a part of Murena! Learn more

Commit db75fce6 authored by Joe Bolinger's avatar Joe Bolinger
Browse files

Add modality to latency logs.

Also clean up logs a bit by making enums strings.

Bug: 413712352
Test: manual (adb shell setprop persist.log.tag.BiometricLogger VERBOSE && adb reboot)
Flag: EXEMPT logs only
Change-Id: I4fcca1de0e8ed032116e67bdf1b5348d3fee54e9
parent 624b5643
Loading
Loading
Loading
Loading
+55 −0
Original line number Diff line number Diff line
@@ -321,4 +321,59 @@ public class BiometricFrameworkStatsLogger {
        }
        return BiometricsProtoEnums.FOLD_UNKNOWN;
    }

    static String modalityToString(int modality) {
        if (modality == BiometricsProtoEnums.MODALITY_FACE) {
            return "face";
        }
        if (modality == BiometricsProtoEnums.MODALITY_FINGERPRINT) {
            return "fingerprint";
        }
        if (modality == BiometricsProtoEnums.MODALITY_IRIS) {
            return "iris";
        }
        return "unknown";
    }

    static String clientToString(int client) {
        if (client == BiometricsProtoEnums.CLIENT_KEYGUARD) {
            return "keyguard";
        }
        if (client == BiometricsProtoEnums.CLIENT_BIOMETRIC_PROMPT) {
            return "biometric prompt";
        }
        if (client == BiometricsProtoEnums.CLIENT_FINGERPRINT_MANAGER) {
            return "fingerprint manager";
        }
        return "unknown";
    }

    static String actionToString(int action) {
        if (action == BiometricsProtoEnums.ACTION_AUTHENTICATE) {
            return "authenticate";
        }
        if (action == BiometricsProtoEnums.ACTION_ENROLL) {
            return "enroll";
        }
        if (action == BiometricsProtoEnums.ACTION_ENUMERATE) {
            return "enumerate";
        }
        if (action == BiometricsProtoEnums.ACTION_REMOVE) {
            return "remove";
        }
        return "unknown";
    }

    static String authenticatedStateToString(int state) {
        if (state == FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__REJECTED) {
            return "rejected";
        }
        if (state == FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__PENDING_CONFIRMATION) {
            return "pending confirmation";
        }
        if (state == FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__CONFIRMED) {
            return "confirmed";
        }
        return "unknown";
    }
}
+48 −24
Original line number Diff line number Diff line
@@ -18,6 +18,11 @@ package com.android.server.biometrics.log;

import static android.hardware.biometrics.BiometricFaceConstants.FACE_ACQUIRED_START;

import static com.android.server.biometrics.log.BiometricFrameworkStatsLogger.actionToString;
import static com.android.server.biometrics.log.BiometricFrameworkStatsLogger.authenticatedStateToString;
import static com.android.server.biometrics.log.BiometricFrameworkStatsLogger.clientToString;
import static com.android.server.biometrics.log.BiometricFrameworkStatsLogger.modalityToString;

import android.annotation.NonNull;
import android.annotation.Nullable;
import android.content.Context;
@@ -25,7 +30,9 @@ import android.hardware.SensorManager;
import android.hardware.biometrics.BiometricConstants;
import android.hardware.biometrics.BiometricsProtoEnums;
import android.hardware.fingerprint.FingerprintManager;
import android.os.Build;
import android.os.Handler;
import android.util.Log;
import android.util.Slog;

import com.android.internal.annotations.VisibleForTesting;
@@ -40,8 +47,8 @@ import java.util.Arrays;
 */
public class BiometricLogger {

    public static final String TAG = "BiometricLogger";
    public static final boolean DEBUG = false;
    private static final String TAG = "BiometricLogger";
    private static final boolean VERBOSE = Build.IS_DEBUGGABLE && Log.isLoggable(TAG, Log.VERBOSE);

    private final Handler mHandler;
    private final int mStatsModality;
@@ -159,12 +166,12 @@ public class BiometricLogger {
                mFirstAcquireTimeMs = System.currentTimeMillis();
            }
        }
        if (DEBUG) {
            Slog.v(TAG, "Acquired! Modality: " + mStatsModality
        if (VERBOSE) {
            Slog.v(TAG, "Acquired! Modality: " + modalityAsString()
                    + ", User: " + targetUserId
                    + ", IsCrypto: " + operationContext.isCrypto()
                    + ", Action: " + mStatsAction
                    + ", Client: " + mStatsClient
                    + ", Action: " + actionAsString()
                    + ", Client: " + clientAsString()
                    + ", AcquiredInfo: " + acquiredInfo
                    + ", VendorCode: " + vendorCode);
        }
@@ -189,17 +196,18 @@ public class BiometricLogger {
        final long latency = mFirstAcquireTimeMs != 0
                ? (System.currentTimeMillis() - mFirstAcquireTimeMs) : -1;

        if (DEBUG) {
            Slog.v(TAG, "Error! Modality: " + mStatsModality
        if (VERBOSE) {
            Slog.v(TAG, "Error! Modality: " + modalityAsString()
                    + ", User: " + targetUserId
                    + ", IsCrypto: " + operationContext.isCrypto()
                    + ", Action: " + mStatsAction
                    + ", Client: " + mStatsClient
                    + ", Action: " + actionAsString()
                    + ", Client: " + clientAsString()
                    + ", Error: " + error
                    + ", VendorCode: " + vendorCode
                    + ", Latency: " + latency);
        } else {
            Slog.v(TAG, "Error latency: " + latency);
            Slog.d(TAG, "Error! Modality: " + modalityAsString()
                    + ", latency: " + latency);
        }

        if (shouldSkipLogging()) {
@@ -242,17 +250,18 @@ public class BiometricLogger {
                ? (System.currentTimeMillis() - mFirstAcquireTimeMs)
                : -1;

        if (DEBUG) {
            Slog.v(TAG, "Authenticated! Modality: " + mStatsModality
        if (VERBOSE) {
            Slog.v(TAG, "Authenticated! Modality: " + modalityAsString()
                    + ", User: " + targetUserId
                    + ", IsCrypto: " + operationContext.isCrypto()
                    + ", Client: " + mStatsClient
                    + ", Client: " + clientAsString()
                    + ", RequireConfirmation: " + requireConfirmation
                    + ", State: " + authState
                    + ", State: " + authenticatedStateToString(authState)
                    + ", Latency: " + latency
                    + ", Lux: " + mALSProbe.getMostRecentLux());
        } else {
            Slog.v(TAG, "Authentication latency: " + latency);
            Slog.d(TAG, "Authenticated! Modality: " + modalityAsString()
                    + ", latency: " + latency);
        }

        if (shouldSkipLogging()) {
@@ -272,16 +281,17 @@ public class BiometricLogger {
            return;
        }

        if (DEBUG) {
            Slog.v(TAG, "Enrolled! Modality: " + mStatsModality
        if (VERBOSE) {
            Slog.v(TAG, "Enrolled! Modality: " + modalityAsString()
                    + ", User: " + targetUserId
                    + ", Client: " + mStatsClient
                    + ", Client: " + clientAsString()
                    + ", Latency: " + latency
                    + ", Lux: " + mALSProbe.getMostRecentLux()
                    + ", Success: " + enrollSuccessful
                    + ", TemplateId: " + templateId);
        } else {
            Slog.v(TAG, "Enroll latency: " + latency);
            Slog.d(TAG, "Enrolled! Modality: " + modalityAsString()
                    + ", latency: " + latency);
        }

        if (shouldSkipLogging()) {
@@ -299,11 +309,13 @@ public class BiometricLogger {
            return;
        }

        if (DEBUG) {
            Slog.v(TAG, "UnEnrolled! Modality: " + mStatsModality
        if (VERBOSE) {
            Slog.v(TAG, "UnEnrolled! Modality: " + modalityAsString()
                    + ", User: " + targetUserId
                    + ", reason: " + reason
                    + ", templateId: " + templateId);
        } else {
            Slog.d(TAG, "UnEnrolled! Modality: " + modalityAsString());
        }

        if (shouldSkipLogging()) {
@@ -320,8 +332,8 @@ public class BiometricLogger {
            return;
        }

        if (DEBUG) {
            Slog.v(TAG, "Enumerated! Modality: " + mStatsModality
        if (VERBOSE) {
            Slog.v(TAG, "Enumerated! Modality: " + modalityAsString()
                    + ", User: " + targetUserId
                    + ", result: " + result
                    + ", templateIdsHal: " + Arrays.toString(templateIdsHal)
@@ -377,4 +389,16 @@ public class BiometricLogger {
    public CallbackWithProbe<Probe> getAmbientLightProbe(boolean startWithClient) {
        return new CallbackWithProbe<>(mALSProbe, startWithClient);
    }

    private String modalityAsString() {
        return modalityToString(mStatsModality);
    }

    private String actionAsString() {
        return actionToString(mStatsAction);
    }

    private String clientAsString() {
        return clientToString(mStatsClient);
    }
}
+6 −3
Original line number Diff line number Diff line
@@ -27,6 +27,7 @@ import android.os.SystemClock;
import android.os.VibrationAttributes;
import android.os.VibrationEffect;
import android.os.Vibrator;
import android.util.Log;
import android.util.Slog;

import com.android.server.biometrics.log.BiometricContext;
@@ -40,7 +41,7 @@ import java.util.function.Supplier;
 */
public abstract class AcquisitionClient<T> extends HalClientMonitor<T> implements ErrorConsumer {

    private static final String TAG = "Biometrics/AcquisitionClient";
    private static final String TAG = "AcquisitionClient";

    private static final VibrationAttributes HARDWARE_FEEDBACK_VIBRATION_ATTRIBUTES =
            VibrationAttributes.createForUsage(VibrationAttributes.USAGE_HARDWARE_FEEDBACK);
@@ -167,8 +168,10 @@ public abstract class AcquisitionClient<T> extends HalClientMonitor<T> implement
            boolean shouldSend) {
        getLogger().logOnAcquired(getContext(), getOperationContext(),
                acquiredInfo, vendorCode, getTargetUserId());
        if (DEBUG) {
            Slog.v(TAG, "Acquired: " + acquiredInfo + " " + vendorCode

        if (Log.isLoggable(TAG, Log.VERBOSE)) {
            Slog.v(TAG, "Acquired: " + acquiredInfo
                    + ", vendorCode: " + vendorCode
                    + ", shouldSend: " + shouldSend);
        }

+3 −3
Original line number Diff line number Diff line
@@ -32,6 +32,7 @@ import android.os.IBinder;
import android.os.RemoteException;
import android.security.KeyStoreAuthorization;
import android.util.EventLog;
import android.util.Log;
import android.util.Slog;

import com.android.server.biometrics.BiometricsProto;
@@ -65,7 +66,7 @@ public abstract class AuthenticationClient<T, O extends AuthenticateOptions>
            STATE_STARTED_PAUSED_ATTEMPTED,
            STATE_STOPPED})
    @interface State {}
    private static final String TAG = "Biometrics/AuthenticationClient";
    private static final String TAG = "AuthenticationClient";
    protected final long mOperationId;
    private final boolean mIsStrongBiometric;
    private final boolean mRequireConfirmation;
@@ -180,12 +181,11 @@ public abstract class AuthenticationClient<T, O extends AuthenticateOptions>

        final ClientMonitorCallbackConverter listener = getListener();

        if (DEBUG) {
        if (Log.isLoggable(TAG, Log.VERBOSE)) {
            Slog.v(TAG, "onAuthenticated(" + authenticated + ")"
                    + ", ID:" + identifier.getBiometricId()
                    + ", Owner: " + getOwnerString()
                    + ", isBP: " + isBiometricPrompt()
                    + ", listener: " + listener
                    + ", requireConfirmation: " + mRequireConfirmation
                    + ", user: " + getTargetUserId()
                    + ", clientMonitor: " + this);
+0 −1
Original line number Diff line number Diff line
@@ -41,7 +41,6 @@ import java.util.NoSuchElementException;
public abstract class BaseClientMonitor implements IBinder.DeathRecipient {

    private static final String TAG = "BaseClientMonitor";
    protected static final boolean DEBUG = true;

    // Counter used to distinguish between ClientMonitor instances to help debugging.
    private static int sCount = 0;
Loading