Merge "Add timeout to all ALS logging." into tm-qpr-dev (15be0582) · Commits · e / os / android_frameworks_base

services/core/java/com/android/server/biometrics/log/ALSProbe.java

0 → 100644

+163 −0

Original line number	Diff line number	Diff line
		/*
		* Copyright (C) 2022 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.server.biometrics.log;

		import android.annotation.DurationMillisLong;
		import android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.hardware.Sensor;
		import android.hardware.SensorEvent;
		import android.hardware.SensorEventListener;
		import android.hardware.SensorManager;
		import android.os.Handler;
		import android.os.Looper;
		import android.util.Slog;

		import com.android.internal.annotations.VisibleForTesting;
		import com.android.server.biometrics.sensors.BaseClientMonitor;

		import java.util.concurrent.TimeUnit;

		/** Probe for ambient light. */
		final class ALSProbe implements Probe {
		private static final String TAG = "ALSProbe";

		@Nullable
		private final SensorManager mSensorManager;
		@Nullable
		private final Sensor mLightSensor;
		@NonNull
		private final Handler mTimer;
		@DurationMillisLong
		private long mMaxSubscriptionTime = -1;

		private boolean mEnabled = false;
		private boolean mDestroyed = false;
		private volatile float mLastAmbientLux = -1;

		private final SensorEventListener mLightSensorListener = new SensorEventListener() {
		@Override
		public void onSensorChanged(SensorEvent event) {
		mLastAmbientLux = event.values[0];
		}

		@Override
		public void onAccuracyChanged(Sensor sensor, int accuracy) {
		// Not used.
		}
		};

		/**
		* Create a probe with a 1-minute max sampling time.
		*
		* @param sensorManager Sensor manager
		*/
		ALSProbe(@NonNull SensorManager sensorManager) {
		this(sensorManager, new Handler(Looper.getMainLooper()),
		TimeUnit.MINUTES.toMillis(1));
		}

		/**
		* Create a probe with a given max sampling time.
		*
		* Note: The max time is a workaround for potential scheduler bugs where
		* {@link BaseClientMonitor#destroy()} is not called due to an abnormal lifecycle. Clients
		* should ensure that {@link #disable()} and {@link #destroy()} are called appropriately and
		* avoid relying on this timeout to unsubscribe from the sensor when it is not needed.
		*
		* @param sensorManager Sensor manager
		* @param handler Timeout handler
		* @param maxTime The max amount of time to subscribe to events. If this time is exceeded
		* {@link #disable()} will be called and no sampling will occur until {@link
		* #enable()} is called again.
		*/
		@VisibleForTesting
		ALSProbe(@Nullable SensorManager sensorManager, @NonNull Handler handler,
		@DurationMillisLong long maxTime) {
		mSensorManager = sensorManager;
		mLightSensor = sensorManager != null
		? sensorManager.getDefaultSensor(Sensor.TYPE_LIGHT) : null;
		mTimer = handler;
		mMaxSubscriptionTime = maxTime;

		if (mSensorManager == null \|\| mLightSensor == null) {
		Slog.w(TAG, "No sensor - probe disabled");
		mDestroyed = true;
		}
		}

		@Override
		public synchronized void enable() {
		if (!mDestroyed) {
		enableLightSensorLoggingLocked();
		}
		}

		@Override
		public synchronized void disable() {
		if (!mDestroyed) {
		disableLightSensorLoggingLocked();
		}
		}

		@Override
		public synchronized void destroy() {
		disable();
		mDestroyed = true;
		}

		/** The most recent lux reading. */
		public float getCurrentLux() {
		return mLastAmbientLux;
		}

		private void enableLightSensorLoggingLocked() {
		if (!mEnabled) {
		mEnabled = true;
		mLastAmbientLux = -1;
		mSensorManager.registerListener(mLightSensorListener, mLightSensor,
		SensorManager.SENSOR_DELAY_NORMAL);
		Slog.v(TAG, "Enable ALS: " + mLightSensorListener.hashCode());
		}

		resetTimerLocked(true /* start */);
		}

		private void disableLightSensorLoggingLocked() {
		resetTimerLocked(false /* start */);

		if (mEnabled) {
		mEnabled = false;
		mLastAmbientLux = -1;
		mSensorManager.unregisterListener(mLightSensorListener);
		Slog.v(TAG, "Disable ALS: " + mLightSensorListener.hashCode());
		}
		}

		private void resetTimerLocked(boolean start) {
		mTimer.removeCallbacksAndMessages(this /* token */);
		if (start && mMaxSubscriptionTime > 0) {
		mTimer.postDelayed(this::onTimeout, this /* token */, mMaxSubscriptionTime);
		}
		}

		private void onTimeout() {
		Slog.e(TAG, "Max time exceeded for ALS logger - disabling: "
		+ mLightSensorListener.hashCode());
		disable();
		}
		}

services/core/java/com/android/server/biometrics/log/BiometricLogger.java

+17 −106

Original line number	Diff line number	Diff line
		@@ -17,21 +17,15 @@
		package com.android.server.biometrics.log;

		import android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.content.Context;
		import android.hardware.Sensor;
		import android.hardware.SensorEvent;
		import android.hardware.SensorEventListener;
		import android.hardware.SensorManager;
		import android.hardware.biometrics.BiometricConstants;
		import android.hardware.biometrics.BiometricsProtoEnums;
		import android.hardware.biometrics.common.OperationContext;
		import android.hardware.face.FaceManager;
		import android.hardware.fingerprint.FingerprintManager;
		import android.util.Log;
		import android.util.Slog;

		import com.android.internal.annotations.GuardedBy;
		import com.android.internal.annotations.VisibleForTesting;
		import com.android.internal.util.FrameworkStatsLog;
		import com.android.server.biometrics.Utils;
		@@ -43,61 +37,16 @@ public class BiometricLogger {

		public static final String TAG = "BiometricLogger";
		public static final boolean DEBUG = false;
		private static final Object sLock = new Object();

		@GuardedBy("sLock")
		private static int sAlsCounter;

		private final int mStatsModality;
		private final int mStatsAction;
		private final int mStatsClient;
		private final BiometricFrameworkStatsLogger mSink;
		@NonNull private final SensorManager mSensorManager;
		@NonNull private final ALSProbe mALSProbe;

		private long mFirstAcquireTimeMs;
		private boolean mLightSensorEnabled = false;
		private boolean mShouldLogMetrics = true;

		private class ALSProbe implements Probe {
		private boolean mDestroyed = false;

		@Override
		public synchronized void enable() {
		if (!mDestroyed) {
		setLightSensorLoggingEnabled(getAmbientLightSensor(mSensorManager));
		}
		}

		@Override
		public synchronized void disable() {
		if (!mDestroyed) {
		setLightSensorLoggingEnabled(null);
		}
		}

		@Override
		public synchronized void destroy() {
		disable();
		mDestroyed = true;
		}
		}

		// report only the most recent value
		// consider com.android.server.display.utils.AmbientFilter or similar if need arises
		private volatile float mLastAmbientLux = 0;

		private final SensorEventListener mLightSensorListener = new SensorEventListener() {
		@Override
		public void onSensorChanged(SensorEvent event) {
		mLastAmbientLux = event.values[0];
		}

		@Override
		public void onAccuracyChanged(Sensor sensor, int accuracy) {
		// Not used.
		}
		};

		/** Get a new logger with all unknown fields (for operations that do not require logs). */
		public static BiometricLogger ofUnknown(@NonNull Context context) {
		return new BiometricLogger(context, BiometricsProtoEnums.MODALITY_UNKNOWN,
		@@ -105,6 +54,11 @@ public class BiometricLogger {
		}

		/**
		* Creates a new logger for an instance of a biometric operation.
		*
		* Do not reuse across operations. Instead, create a new one or use
		* {@link #swapAction(Context, int)}.
		*
		* @param context system_server context
		* @param statsModality One of {@link BiometricsProtoEnums} MODALITY_* constants.
		* @param statsAction One of {@link BiometricsProtoEnums} ACTION_* constants.
		@@ -125,7 +79,7 @@ public class BiometricLogger {
		mStatsAction = statsAction;
		mStatsClient = statsClient;
		mSink = logSink;
		mSensorManager = sensorManager;
		mALSProbe = new ALSProbe(sensorManager);
		}

		/** Creates a new logger with the action replaced with the new action. */
		@@ -136,6 +90,7 @@ public class BiometricLogger {
		/** Disable logging metrics and only log critical events, such as system health issues. */
		public void disableMetrics() {
		mShouldLogMetrics = false;
		mALSProbe.destroy();
		}

		/** {@link BiometricsProtoEnums} CLIENT_* constants */
		@@ -265,7 +220,7 @@ public class BiometricLogger {
		+ ", RequireConfirmation: " + requireConfirmation
		+ ", State: " + authState
		+ ", Latency: " + latency
		+ ", Lux: " + mLastAmbientLux);
		+ ", Lux: " + mALSProbe.getCurrentLux());
		} else {
		Slog.v(TAG, "Authentication latency: " + latency);
		}
		@@ -276,7 +231,7 @@ public class BiometricLogger {

		mSink.authenticate(operationContext, mStatsModality, mStatsAction, mStatsClient,
		Utils.isDebugEnabled(context, targetUserId),
		latency, authState, requireConfirmation, targetUserId, mLastAmbientLux);
		latency, authState, requireConfirmation, targetUserId, mALSProbe.getCurrentLux());
		}

		/** Log enrollment outcome. */
		@@ -290,7 +245,7 @@ public class BiometricLogger {
		+ ", User: " + targetUserId
		+ ", Client: " + mStatsClient
		+ ", Latency: " + latency
		+ ", Lux: " + mLastAmbientLux
		+ ", Lux: " + mALSProbe.getCurrentLux()
		+ ", Success: " + enrollSuccessful);
		} else {
		Slog.v(TAG, "Enroll latency: " + latency);
		@@ -301,7 +256,7 @@ public class BiometricLogger {
		}

		mSink.enroll(mStatsModality, mStatsAction, mStatsClient,
		targetUserId, latency, enrollSuccessful, mLastAmbientLux);
		targetUserId, latency, enrollSuccessful, mALSProbe.getCurrentLux());
		}

		/** Report unexpected enrollment reported by the HAL. */
		@@ -323,7 +278,9 @@ public class BiometricLogger {
		}

		/**
		* Get a callback to start/stop ALS capture when a client runs.
		* Get a callback to start/stop ALS capture when the client runs. Do not create
		* multiple callbacks since there is at most one light sensor (they will all share
		* a single probe sampling from that sensor).
		*
		* If the probe should not run for the entire operation, do not set startWithClient and
		* start/stop the problem when needed.
		@@ -331,53 +288,7 @@ public class BiometricLogger {
		* @param startWithClient if probe should start automatically when the operation starts.
		*/
		@NonNull
		public CallbackWithProbe<Probe> createALSCallback(boolean startWithClient) {
		return new CallbackWithProbe<>(new ALSProbe(), startWithClient);
		}

		/** The sensor to use for ALS logging. */
		@Nullable
		protected Sensor getAmbientLightSensor(@NonNull SensorManager sensorManager) {
		return mShouldLogMetrics ? sensorManager.getDefaultSensor(Sensor.TYPE_LIGHT) : null;
		}

		private void setLightSensorLoggingEnabled(@Nullable Sensor lightSensor) {
		if (DEBUG) {
		Slog.v(TAG, "capturing ambient light using: "
		+ (lightSensor != null ? lightSensor : "[disabled]"));
		}

		if (lightSensor != null) {
		if (!mLightSensorEnabled) {
		mLightSensorEnabled = true;
		mLastAmbientLux = 0;
		int localAlsCounter;
		synchronized (sLock) {
		localAlsCounter = sAlsCounter++;
		}

		if (localAlsCounter == 0) {
		mSensorManager.registerListener(mLightSensorListener, lightSensor,
		SensorManager.SENSOR_DELAY_NORMAL);
		} else {
		Slog.e(TAG, "Ignoring request to subscribe to ALSProbe due to non-zero ALS"
		+ " counter: " + localAlsCounter);
		Slog.e(TAG, Log.getStackTraceString(new Throwable()));
		}
		}
		} else {
		mLightSensorEnabled = false;
		mLastAmbientLux = 0;
		mSensorManager.unregisterListener(mLightSensorListener);
		int localAlsCounter;
		synchronized (sLock) {
		localAlsCounter = --sAlsCounter;
		}
		if (localAlsCounter != 0) {
		Slog.e(TAG, "Non-zero ALS counter after unsubscribing from ALSProbe: "
		+ localAlsCounter);
		Slog.e(TAG, Log.getStackTraceString(new Throwable()));
		}
		}
		public CallbackWithProbe<Probe> getAmbientLightProbe(boolean startWithClient) {
		return new CallbackWithProbe<>(mALSProbe, startWithClient);
		}
		}

services/core/java/com/android/server/biometrics/sensors/face/aidl/FaceAuthenticationClient.java

+1 −1

Original line number	Diff line number	Diff line
		@@ -131,7 +131,7 @@ class FaceAuthenticationClient extends AuthenticationClient<AidlSession>
		@Override
		protected ClientMonitorCallback wrapCallbackForStart(@NonNull ClientMonitorCallback callback) {
		return new ClientMonitorCompositeCallback(
		getLogger().createALSCallback(true /* startWithClient */), callback);
		getLogger().getAmbientLightProbe(true /* startWithClient */), callback);
		}

		@Override

services/core/java/com/android/server/biometrics/sensors/face/aidl/FaceEnrollClient.java

+1 −1

Original line number	Diff line number	Diff line
		@@ -115,7 +115,7 @@ public class FaceEnrollClient extends EnrollClient<AidlSession> {
		@Override
		protected ClientMonitorCallback wrapCallbackForStart(@NonNull ClientMonitorCallback callback) {
		return new ClientMonitorCompositeCallback(mPreviewHandleDeleterCallback,
		getLogger().createALSCallback(true /* startWithClient */), callback);
		getLogger().getAmbientLightProbe(true /* startWithClient */), callback);
		}

		@Override

services/core/java/com/android/server/biometrics/sensors/face/hidl/FaceAuthenticationClient.java

+1 −1

Original line number	Diff line number	Diff line
		@@ -101,7 +101,7 @@ class FaceAuthenticationClient extends AuthenticationClient<IBiometricsFace> {
		@Override
		protected ClientMonitorCallback wrapCallbackForStart(@NonNull ClientMonitorCallback callback) {
		return new ClientMonitorCompositeCallback(
		getLogger().createALSCallback(true /* startWithClient */), callback);
		getLogger().getAmbientLightProbe(true /* startWithClient */), callback);
		}

		@Override