1 /*
2  * Copyright (C) 2020 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.sensors;
18 
19 import android.annotation.NonNull;
20 import android.annotation.Nullable;
21 import android.content.Context;
22 import android.hardware.Sensor;
23 import android.hardware.SensorEvent;
24 import android.hardware.SensorEventListener;
25 import android.hardware.SensorManager;
26 import android.hardware.biometrics.BiometricConstants;
27 import android.hardware.biometrics.BiometricsProtoEnums;
28 import android.hardware.face.FaceManager;
29 import android.hardware.fingerprint.FingerprintManager;
30 import android.util.Slog;
31 
32 import com.android.internal.util.FrameworkStatsLog;
33 import com.android.server.biometrics.Utils;
34 
35 /**
36  * Abstract class that adds logging functionality to the ClientMonitor classes.
37  */
38 public abstract class LoggableMonitor {
39 
40     public static final String TAG = "Biometrics/LoggableMonitor";
41     public static final boolean DEBUG = false;
42 
43     final int mStatsModality;
44     private final int mStatsAction;
45     private final int mStatsClient;
46     @NonNull private final SensorManager mSensorManager;
47     private long mFirstAcquireTimeMs;
48     private boolean mLightSensorEnabled = false;
49     private boolean mShouldLogMetrics = true;
50 
51     /**
52      * Probe for loggable attributes that can be continuously monitored, such as ambient light.
53      *
54      * Disable probes when the sensors are in states that are not interesting for monitoring
55      * purposes to save power.
56      */
57     protected interface Probe {
58         /** Ensure the probe is actively sampling for new data. */
enable()59         void enable();
60         /** Stop sampling data. */
disable()61         void disable();
62     }
63 
64     /**
65      * Client monitor callback that exposes a probe.
66      *
67      * Disables the probe when the operation completes.
68      */
69     protected static class CallbackWithProbe<T extends Probe>
70             implements BaseClientMonitor.Callback {
71         private final boolean mStartWithClient;
72         private final T mProbe;
73 
CallbackWithProbe(@onNull T probe, boolean startWithClient)74         public CallbackWithProbe(@NonNull T probe, boolean startWithClient) {
75             mProbe = probe;
76             mStartWithClient = startWithClient;
77         }
78 
79         @Override
onClientStarted(@onNull BaseClientMonitor clientMonitor)80         public void onClientStarted(@NonNull BaseClientMonitor clientMonitor) {
81             if (mStartWithClient) {
82                 mProbe.enable();
83             }
84         }
85 
86         @Override
onClientFinished(@onNull BaseClientMonitor clientMonitor, boolean success)87         public void onClientFinished(@NonNull BaseClientMonitor clientMonitor, boolean success) {
88             mProbe.disable();
89         }
90 
91         @NonNull
getProbe()92         public T getProbe() {
93             return mProbe;
94         }
95     }
96 
97     private class ALSProbe implements Probe {
98         @Override
enable()99         public void enable() {
100             setLightSensorLoggingEnabled(getAmbientLightSensor(mSensorManager));
101         }
102 
103         @Override
disable()104         public void disable() {
105             setLightSensorLoggingEnabled(null);
106         }
107     }
108 
109     // report only the most recent value
110     // consider com.android.server.display.utils.AmbientFilter or similar if need arises
111     private volatile float mLastAmbientLux = 0;
112 
113     private final SensorEventListener mLightSensorListener = new SensorEventListener() {
114         @Override
115         public void onSensorChanged(SensorEvent event) {
116             mLastAmbientLux = event.values[0];
117         }
118 
119         @Override
120         public void onAccuracyChanged(Sensor sensor, int accuracy) {
121             // Not used.
122         }
123     };
124 
125     /**
126      * @param context system_server context
127      * @param statsModality One of {@link BiometricsProtoEnums} MODALITY_* constants.
128      * @param statsAction One of {@link BiometricsProtoEnums} ACTION_* constants.
129      * @param statsClient One of {@link BiometricsProtoEnums} CLIENT_* constants.
130      */
LoggableMonitor(@onNull Context context, int statsModality, int statsAction, int statsClient)131     public LoggableMonitor(@NonNull Context context, int statsModality, int statsAction,
132             int statsClient) {
133         mStatsModality = statsModality;
134         mStatsAction = statsAction;
135         mStatsClient = statsClient;
136         mSensorManager = context.getSystemService(SensorManager.class);
137     }
138 
139     /**
140      * Only valid for AuthenticationClient.
141      * @return true if the client is authenticating for a crypto operation.
142      */
isCryptoOperation()143     protected boolean isCryptoOperation() {
144         return false;
145     }
146 
setShouldLog(boolean shouldLog)147     protected void setShouldLog(boolean shouldLog) {
148         mShouldLogMetrics = shouldLog;
149     }
150 
getStatsClient()151     public int getStatsClient() {
152         return mStatsClient;
153     }
154 
shouldSkipLogging()155     private boolean shouldSkipLogging() {
156         boolean shouldSkipLogging = (mStatsModality == BiometricsProtoEnums.MODALITY_UNKNOWN
157                 || mStatsAction == BiometricsProtoEnums.ACTION_UNKNOWN);
158 
159         if (mStatsModality == BiometricsProtoEnums.MODALITY_UNKNOWN) {
160             Slog.w(TAG, "Unknown field detected: MODALITY_UNKNOWN, will not report metric");
161         }
162 
163         if (mStatsAction == BiometricsProtoEnums.ACTION_UNKNOWN) {
164             Slog.w(TAG, "Unknown field detected: ACTION_UNKNOWN, will not report metric");
165         }
166 
167         if (mStatsClient == BiometricsProtoEnums.CLIENT_UNKNOWN) {
168             Slog.w(TAG, "Unknown field detected: CLIENT_UNKNOWN");
169         }
170 
171         return shouldSkipLogging;
172     }
173 
logOnAcquired(Context context, int acquiredInfo, int vendorCode, int targetUserId)174     protected final void logOnAcquired(Context context, int acquiredInfo, int vendorCode,
175             int targetUserId) {
176         if (!mShouldLogMetrics) {
177             return;
178         }
179 
180         final boolean isFace = mStatsModality == BiometricsProtoEnums.MODALITY_FACE;
181         final boolean isFingerprint = mStatsModality == BiometricsProtoEnums.MODALITY_FINGERPRINT;
182         if (isFace || isFingerprint) {
183             if ((isFingerprint && acquiredInfo == FingerprintManager.FINGERPRINT_ACQUIRED_START)
184                     || (isFace && acquiredInfo == FaceManager.FACE_ACQUIRED_START)) {
185                 mFirstAcquireTimeMs = System.currentTimeMillis();
186             }
187         } else if (acquiredInfo == BiometricConstants.BIOMETRIC_ACQUIRED_GOOD) {
188             if (mFirstAcquireTimeMs == 0) {
189                 mFirstAcquireTimeMs = System.currentTimeMillis();
190             }
191         }
192         if (DEBUG) {
193             Slog.v(TAG, "Acquired! Modality: " + mStatsModality
194                     + ", User: " + targetUserId
195                     + ", IsCrypto: " + isCryptoOperation()
196                     + ", Action: " + mStatsAction
197                     + ", Client: " + mStatsClient
198                     + ", AcquiredInfo: " + acquiredInfo
199                     + ", VendorCode: " + vendorCode);
200         }
201 
202         if (shouldSkipLogging()) {
203             return;
204         }
205 
206         FrameworkStatsLog.write(FrameworkStatsLog.BIOMETRIC_ACQUIRED,
207                 mStatsModality,
208                 targetUserId,
209                 isCryptoOperation(),
210                 mStatsAction,
211                 mStatsClient,
212                 acquiredInfo,
213                 vendorCode,
214                 Utils.isDebugEnabled(context, targetUserId),
215                 -1 /* sensorId */);
216     }
217 
logOnError(Context context, int error, int vendorCode, int targetUserId)218     protected final void logOnError(Context context, int error, int vendorCode, int targetUserId) {
219         if (!mShouldLogMetrics) {
220             return;
221         }
222 
223         final long latency = mFirstAcquireTimeMs != 0
224                 ? (System.currentTimeMillis() - mFirstAcquireTimeMs) : -1;
225 
226         if (DEBUG) {
227             Slog.v(TAG, "Error! Modality: " + mStatsModality
228                     + ", User: " + targetUserId
229                     + ", IsCrypto: " + isCryptoOperation()
230                     + ", Action: " + mStatsAction
231                     + ", Client: " + mStatsClient
232                     + ", Error: " + error
233                     + ", VendorCode: " + vendorCode
234                     + ", Latency: " + latency);
235         } else {
236             Slog.v(TAG, "Error latency: " + latency);
237         }
238 
239         if (shouldSkipLogging()) {
240             return;
241         }
242 
243         FrameworkStatsLog.write(FrameworkStatsLog.BIOMETRIC_ERROR_OCCURRED,
244                 mStatsModality,
245                 targetUserId,
246                 isCryptoOperation(),
247                 mStatsAction,
248                 mStatsClient,
249                 error,
250                 vendorCode,
251                 Utils.isDebugEnabled(context, targetUserId),
252                 sanitizeLatency(latency),
253                 -1 /* sensorId */);
254     }
255 
logOnAuthenticated(Context context, boolean authenticated, boolean requireConfirmation, int targetUserId, boolean isBiometricPrompt)256     protected final void logOnAuthenticated(Context context, boolean authenticated,
257             boolean requireConfirmation, int targetUserId, boolean isBiometricPrompt) {
258         if (!mShouldLogMetrics) {
259             return;
260         }
261 
262         int authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__UNKNOWN;
263         if (!authenticated) {
264             authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__REJECTED;
265         } else {
266             // Authenticated
267             if (isBiometricPrompt && requireConfirmation) {
268                 authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__PENDING_CONFIRMATION;
269             } else {
270                 authState = FrameworkStatsLog.BIOMETRIC_AUTHENTICATED__STATE__CONFIRMED;
271             }
272         }
273 
274         // Only valid if we have a first acquired time, otherwise set to -1
275         final long latency = mFirstAcquireTimeMs != 0
276                 ? (System.currentTimeMillis() - mFirstAcquireTimeMs)
277                 : -1;
278 
279         if (DEBUG) {
280             Slog.v(TAG, "Authenticated! Modality: " + mStatsModality
281                     + ", User: " + targetUserId
282                     + ", IsCrypto: " + isCryptoOperation()
283                     + ", Client: " + mStatsClient
284                     + ", RequireConfirmation: " + requireConfirmation
285                     + ", State: " + authState
286                     + ", Latency: " + latency
287                     + ", Lux: " + mLastAmbientLux);
288         } else {
289             Slog.v(TAG, "Authentication latency: " + latency);
290         }
291 
292         if (shouldSkipLogging()) {
293             return;
294         }
295 
296         FrameworkStatsLog.write(FrameworkStatsLog.BIOMETRIC_AUTHENTICATED,
297                 mStatsModality,
298                 targetUserId,
299                 isCryptoOperation(),
300                 mStatsClient,
301                 requireConfirmation,
302                 authState,
303                 sanitizeLatency(latency),
304                 Utils.isDebugEnabled(context, targetUserId),
305                 -1 /* sensorId */,
306                 mLastAmbientLux /* ambientLightLux */);
307     }
308 
logOnEnrolled(int targetUserId, long latency, boolean enrollSuccessful)309     protected final void logOnEnrolled(int targetUserId, long latency, boolean enrollSuccessful) {
310         if (!mShouldLogMetrics) {
311             return;
312         }
313 
314         if (DEBUG) {
315             Slog.v(TAG, "Enrolled! Modality: " + mStatsModality
316                     + ", User: " + targetUserId
317                     + ", Client: " + mStatsClient
318                     + ", Latency: " + latency
319                     + ", Lux: " + mLastAmbientLux
320                     + ", Success: " + enrollSuccessful);
321         } else {
322             Slog.v(TAG, "Enroll latency: " + latency);
323         }
324 
325         if (shouldSkipLogging()) {
326             return;
327         }
328 
329         FrameworkStatsLog.write(FrameworkStatsLog.BIOMETRIC_ENROLLED,
330                 mStatsModality,
331                 targetUserId,
332                 sanitizeLatency(latency),
333                 enrollSuccessful,
334                 -1, /* sensorId */
335                 mLastAmbientLux /* ambientLightLux */);
336     }
337 
sanitizeLatency(long latency)338     private long sanitizeLatency(long latency) {
339         if (latency < 0) {
340             Slog.w(TAG, "found a negative latency : " + latency);
341             return -1;
342         }
343         return latency;
344     }
345 
346     /**
347      * Get a callback to start/stop ALS capture when client runs.
348      *
349      * If the probe should not run for the entire operation, do not set startWithClient and
350      * start/stop the problem when needed.
351      *
352      * @param startWithClient if probe should start automatically when the operation starts.
353      */
354     @NonNull
createALSCallback(boolean startWithClient)355     protected CallbackWithProbe<Probe> createALSCallback(boolean startWithClient) {
356         return new CallbackWithProbe<>(new ALSProbe(), startWithClient);
357     }
358 
359     /** The sensor to use for ALS logging. */
360     @Nullable
getAmbientLightSensor(@onNull SensorManager sensorManager)361     protected Sensor getAmbientLightSensor(@NonNull SensorManager sensorManager) {
362         return mShouldLogMetrics ? sensorManager.getDefaultSensor(Sensor.TYPE_LIGHT) : null;
363     }
364 
setLightSensorLoggingEnabled(@ullable Sensor lightSensor)365     private void setLightSensorLoggingEnabled(@Nullable Sensor lightSensor) {
366         if (DEBUG) {
367             Slog.v(TAG, "capturing ambient light using: "
368                     + (lightSensor != null ? lightSensor : "[disabled]"));
369         }
370 
371         if (lightSensor != null) {
372             if (!mLightSensorEnabled) {
373                 mLightSensorEnabled = true;
374                 mLastAmbientLux = 0;
375                 mSensorManager.registerListener(mLightSensorListener, lightSensor,
376                         SensorManager.SENSOR_DELAY_NORMAL);
377             }
378         } else {
379             mLightSensorEnabled = false;
380             mLastAmbientLux = 0;
381             mSensorManager.unregisterListener(mLightSensorListener);
382         }
383     }
384 }
385