1 /* 2 * Copyright (C) 2022 The Android Open Source Project 3 * 4 * Licensed under the Apache License, Version 2.0 (the "License"); 5 * you may not use this file except in compliance with the License. 6 * You may obtain a copy of the License at 7 * 8 * http://www.apache.org/licenses/LICENSE-2.0 9 * 10 * Unless required by applicable law or agreed to in writing, software 11 * distributed under the License is distributed on an "AS IS" BASIS, 12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. 13 * See the License for the specific language governing permissions and 14 * limitations under the License. 15 */ 16 17 package com.android.server.biometrics.log; 18 19 import android.annotation.NonNull; 20 import android.content.Context; 21 import android.hardware.SensorManager; 22 import android.hardware.biometrics.BiometricConstants; 23 import android.hardware.biometrics.BiometricsProtoEnums; 24 import android.hardware.biometrics.common.OperationContext; 25 import android.hardware.face.FaceManager; 26 import android.hardware.fingerprint.FingerprintManager; 27 import android.util.Slog; 28 29 import com.android.internal.annotations.VisibleForTesting; 30 import com.android.internal.util.FrameworkStatsLog; 31 import com.android.server.biometrics.Utils; 32 33 /** 34 * Logger for all reported Biometric framework events. 35 */ 36 public class BiometricLogger { 37 38 public static final String TAG = "BiometricLogger"; 39 public static final boolean DEBUG = false; 40 41 private final int mStatsModality; 42 private final int mStatsAction; 43 private final int mStatsClient; 44 private final BiometricFrameworkStatsLogger mSink; 45 @NonNull private final ALSProbe mALSProbe; 46 47 private long mFirstAcquireTimeMs; 48 private boolean mShouldLogMetrics = true; 49 50 /** Get a new logger with all unknown fields (for operations that do not require logs). */ ofUnknown(@onNull Context context)51 public static BiometricLogger ofUnknown(@NonNull Context context) { 52 return new BiometricLogger(context, BiometricsProtoEnums.MODALITY_UNKNOWN, 53 BiometricsProtoEnums.ACTION_UNKNOWN, BiometricsProtoEnums.CLIENT_UNKNOWN); 54 } 55 56 /** 57 * Creates a new logger for an instance of a biometric operation. 58 * 59 * Do not reuse across operations. Instead, create a new one or use 60 * {@link #swapAction(Context, int)}. 61 * 62 * @param context system_server context 63 * @param statsModality One of {@link BiometricsProtoEnums} MODALITY_* constants. 64 * @param statsAction One of {@link BiometricsProtoEnums} ACTION_* constants. 65 * @param statsClient One of {@link BiometricsProtoEnums} CLIENT_* constants. 66 */ BiometricLogger( @onNull Context context, int statsModality, int statsAction, int statsClient)67 public BiometricLogger( 68 @NonNull Context context, int statsModality, int statsAction, int statsClient) { 69 this(statsModality, statsAction, statsClient, 70 BiometricFrameworkStatsLogger.getInstance(), 71 context.getSystemService(SensorManager.class)); 72 } 73 74 @VisibleForTesting BiometricLogger( int statsModality, int statsAction, int statsClient, BiometricFrameworkStatsLogger logSink, SensorManager sensorManager)75 BiometricLogger( 76 int statsModality, int statsAction, int statsClient, 77 BiometricFrameworkStatsLogger logSink, SensorManager sensorManager) { 78 mStatsModality = statsModality; 79 mStatsAction = statsAction; 80 mStatsClient = statsClient; 81 mSink = logSink; 82 mALSProbe = new ALSProbe(sensorManager); 83 } 84 85 /** Creates a new logger with the action replaced with the new action. */ swapAction(@onNull Context context, int statsAction)86 public BiometricLogger swapAction(@NonNull Context context, int statsAction) { 87 return new BiometricLogger(context, mStatsModality, statsAction, mStatsClient); 88 } 89 90 /** Disable logging metrics and only log critical events, such as system health issues. */ disableMetrics()91 public void disableMetrics() { 92 mShouldLogMetrics = false; 93 mALSProbe.destroy(); 94 } 95 96 /** {@link BiometricsProtoEnums} CLIENT_* constants */ getStatsClient()97 public int getStatsClient() { 98 return mStatsClient; 99 } 100 shouldSkipLogging()101 private boolean shouldSkipLogging() { 102 boolean shouldSkipLogging = (mStatsModality == BiometricsProtoEnums.MODALITY_UNKNOWN 103 || mStatsAction == BiometricsProtoEnums.ACTION_UNKNOWN); 104 105 if (mStatsModality == BiometricsProtoEnums.MODALITY_UNKNOWN) { 106 Slog.w(TAG, "Unknown field detected: MODALITY_UNKNOWN, will not report metric"); 107 } 108 109 if (mStatsAction == BiometricsProtoEnums.ACTION_UNKNOWN) { 110 Slog.w(TAG, "Unknown field detected: ACTION_UNKNOWN, will not report metric"); 111 } 112 113 if (mStatsClient == BiometricsProtoEnums.CLIENT_UNKNOWN) { 114 Slog.w(TAG, "Unknown field detected: CLIENT_UNKNOWN"); 115 } 116 117 return shouldSkipLogging; 118 } 119 120 /** Log an acquisition event. */ logOnAcquired(Context context, OperationContext operationContext, int acquiredInfo, int vendorCode, int targetUserId)121 public void logOnAcquired(Context context, OperationContext operationContext, 122 int acquiredInfo, int vendorCode, int targetUserId) { 123 if (!mShouldLogMetrics) { 124 return; 125 } 126 127 final boolean isFace = mStatsModality == BiometricsProtoEnums.MODALITY_FACE; 128 final boolean isFingerprint = mStatsModality == BiometricsProtoEnums.MODALITY_FINGERPRINT; 129 if (isFace || isFingerprint) { 130 if ((isFingerprint && acquiredInfo == FingerprintManager.FINGERPRINT_ACQUIRED_START) 131 || (isFace && acquiredInfo == FaceManager.FACE_ACQUIRED_START)) { 132 mFirstAcquireTimeMs = System.currentTimeMillis(); 133 } 134 } else if (acquiredInfo == BiometricConstants.BIOMETRIC_ACQUIRED_GOOD) { 135 if (mFirstAcquireTimeMs == 0) { 136 mFirstAcquireTimeMs = System.currentTimeMillis(); 137 } 138 } 139 if (DEBUG) { 140 Slog.v(TAG, "Acquired! Modality: " + mStatsModality 141 + ", User: " + targetUserId 142 + ", IsCrypto: " + operationContext.isCrypto 143 + ", Action: " + mStatsAction 144 + ", Client: " + mStatsClient 145 + ", AcquiredInfo: " + acquiredInfo 146 + ", VendorCode: " + vendorCode); 147 } 148 149 if (shouldSkipLogging()) { 150 return; 151 } 152 153 mSink.acquired(operationContext, mStatsModality, mStatsAction, mStatsClient, 154 Utils.isDebugEnabled(context, targetUserId), 155 acquiredInfo, vendorCode, targetUserId); 156 } 157 158 /** Log an error during an operation. */ logOnError(Context context, OperationContext operationContext, int error, int vendorCode, int targetUserId)159 public void logOnError(Context context, OperationContext operationContext, 160 int error, int vendorCode, int targetUserId) { 161 if (!mShouldLogMetrics) { 162 return; 163 } 164 165 final long latency = mFirstAcquireTimeMs != 0 166 ? (System.currentTimeMillis() - mFirstAcquireTimeMs) : -1; 167 168 if (DEBUG) { 169 Slog.v(TAG, "Error! Modality: " + mStatsModality 170 + ", User: " + targetUserId 171 + ", IsCrypto: " + operationContext.isCrypto 172 + ", Action: " + mStatsAction 173 + ", Client: " + mStatsClient 174 + ", Error: " + error 175 + ", VendorCode: " + vendorCode 176 + ", Latency: " + latency); 177 } else { 178 Slog.v(TAG, "Error latency: " + latency); 179 } 180 181 if (shouldSkipLogging()) { 182 return; 183 } 184 185 mSink.error(operationContext, mStatsModality, mStatsAction, mStatsClient, 186 Utils.isDebugEnabled(context, targetUserId), latency, 187 error, vendorCode, targetUserId); 188 } 189 190 /** Log authentication attempt. */ logOnAuthenticated(Context context, OperationContext operationContext, boolean authenticated, boolean requireConfirmation, int targetUserId, boolean isBiometricPrompt)191 public void logOnAuthenticated(Context context, OperationContext operationContext, 192 boolean authenticated, boolean requireConfirmation, 193 int targetUserId, boolean isBiometricPrompt) { 194 if (!mShouldLogMetrics) { 195 return; 196 } 197 198 int authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__UNKNOWN; 199 if (!authenticated) { 200 authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__REJECTED; 201 } else { 202 // Authenticated 203 if (isBiometricPrompt && requireConfirmation) { 204 authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__PENDING_CONFIRMATION; 205 } else { 206 authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__CONFIRMED; 207 } 208 } 209 210 // Only valid if we have a first acquired time, otherwise set to -1 211 final long latency = mFirstAcquireTimeMs != 0 212 ? (System.currentTimeMillis() - mFirstAcquireTimeMs) 213 : -1; 214 215 if (DEBUG) { 216 Slog.v(TAG, "Authenticated! Modality: " + mStatsModality 217 + ", User: " + targetUserId 218 + ", IsCrypto: " + operationContext.isCrypto 219 + ", Client: " + mStatsClient 220 + ", RequireConfirmation: " + requireConfirmation 221 + ", State: " + authState 222 + ", Latency: " + latency 223 + ", Lux: " + mALSProbe.getMostRecentLux()); 224 } else { 225 Slog.v(TAG, "Authentication latency: " + latency); 226 } 227 228 if (shouldSkipLogging()) { 229 return; 230 } 231 232 mSink.authenticate(operationContext, mStatsModality, mStatsAction, mStatsClient, 233 Utils.isDebugEnabled(context, targetUserId), 234 latency, authState, requireConfirmation, targetUserId, mALSProbe); 235 } 236 237 /** Log enrollment outcome. */ logOnEnrolled(int targetUserId, long latency, boolean enrollSuccessful)238 public void logOnEnrolled(int targetUserId, long latency, boolean enrollSuccessful) { 239 if (!mShouldLogMetrics) { 240 return; 241 } 242 243 if (DEBUG) { 244 Slog.v(TAG, "Enrolled! Modality: " + mStatsModality 245 + ", User: " + targetUserId 246 + ", Client: " + mStatsClient 247 + ", Latency: " + latency 248 + ", Lux: " + mALSProbe.getMostRecentLux() 249 + ", Success: " + enrollSuccessful); 250 } else { 251 Slog.v(TAG, "Enroll latency: " + latency); 252 } 253 254 if (shouldSkipLogging()) { 255 return; 256 } 257 258 mSink.enroll(mStatsModality, mStatsAction, mStatsClient, 259 targetUserId, latency, enrollSuccessful, mALSProbe.getMostRecentLux()); 260 } 261 262 /** Report unexpected enrollment reported by the HAL. */ logUnknownEnrollmentInHal()263 public void logUnknownEnrollmentInHal() { 264 if (shouldSkipLogging()) { 265 return; 266 } 267 268 mSink.reportUnknownTemplateEnrolledHal(mStatsModality); 269 } 270 271 /** Report unknown enrollment in framework settings */ logUnknownEnrollmentInFramework()272 public void logUnknownEnrollmentInFramework() { 273 if (shouldSkipLogging()) { 274 return; 275 } 276 277 mSink.reportUnknownTemplateEnrolledFramework(mStatsModality); 278 } 279 280 /** 281 * Get a callback to start/stop ALS capture when the client runs. Do not create 282 * multiple callbacks since there is at most one light sensor (they will all share 283 * a single probe sampling from that sensor). 284 * 285 * If the probe should not run for the entire operation, do not set startWithClient and 286 * start/stop the problem when needed. 287 * 288 * @param startWithClient if probe should start automatically when the operation starts. 289 */ 290 @NonNull getAmbientLightProbe(boolean startWithClient)291 public CallbackWithProbe<Probe> getAmbientLightProbe(boolean startWithClient) { 292 return new CallbackWithProbe<>(mALSProbe, startWithClient); 293 } 294 } 295