Add Logger Implementation for WestWorld (4c1020cc) · Commits · e / os / android_frameworks_base

apex/appsearch/framework/java/android/app/appsearch/AppSearchSession.java

+1 −0

Original line number	Diff line number	Diff line
		@@ -241,6 +241,7 @@ public final class AppSearchSession implements Closeable {
		documentBundles.add(documents.get(i).getBundle());
		}
		try {
		// TODO(b/173532925) a timestamp needs to be sent here to calculate binder latency
		mService.putDocuments(mPackageName, mDatabaseName, documentBundles, mUserId,
		new IAppSearchBatchResultCallback.Stub() {
		public void onResult(AppSearchBatchResult result) {

apex/appsearch/service/java/com/android/server/appsearch/stats/PlatformLogger.java

0 → 100644

+315 −0

Original line number	Diff line number	Diff line
		/*
		* 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.server.appsearch.stats;

		import android.annotation.NonNull;
		import android.annotation.Nullable;
		import android.content.Context;
		import android.content.pm.PackageManager;
		import android.os.Process;
		import android.os.SystemClock;
		import android.util.ArrayMap;
		import android.util.SparseIntArray;

		import com.android.internal.annotations.GuardedBy;
		import com.android.internal.annotations.VisibleForTesting;
		import com.android.internal.util.Preconditions;
		import com.android.server.appsearch.external.localstorage.AppSearchLogger;
		import com.android.server.appsearch.external.localstorage.stats.CallStats;
		import com.android.server.appsearch.external.localstorage.stats.PutDocumentStats;

		import java.util.Map;
		import java.util.Random;

		/**
		* Logger Implementation using Westworld.
		*
		* <p>This class is thread-safe.
		*
		* @hide
		*/
		public final class PlatformLogger implements AppSearchLogger {
		private static final String TAG = "AppSearchPlatformLogger";

		// Context of the system service.
		private final Context mContext;

		// User ID of the caller who we're logging for.
		private final int mUserId;

		// Configuration for the logger
		private final Config mConfig;

		private final Random mRng = new Random();
		private final Object mLock = new Object();

		/**
		* SparseArray to track how many stats we skipped due to
		* {@link Config#mMinTimeIntervalBetweenSamplesMillis}.
		*
		* <p> We can have correct extrapolated number by adding those counts back when we log
		* the same type of stats next time. E.g. the true count of an event could be estimated as:
		* SUM(sampling_ratio * (num_skipped_sample + 1)) as est_count
		*
		* <p>The key to the SparseArray is {@link CallStats.CallType}
		*/
		@GuardedBy("mLock")
		private final SparseIntArray mSkippedSampleCountLocked =
		new SparseIntArray();

		/**
		* Map to cache the packageUid for each package.
		*
		* <p>It maps packageName to packageUid.
		*
		* <p>The entry will be removed whenever the app gets uninstalled
		*/
		@GuardedBy("mLock")
		private final Map<String, Integer> mPackageUidCacheLocked =
		new ArrayMap<>();

		/**
		* Elapsed time for last stats logged from boot in millis
		*/
		@GuardedBy("mLock")
		private long mLastPushTimeMillisLocked = 0;

		/**
		* Class to configure the {@link PlatformLogger}
		*/
		public static final class Config {
		// Minimum time interval (in millis) since last message logged to Westworld before
		// logging again.
		private final long mMinTimeIntervalBetweenSamplesMillis;

		// Default sampling ratio for all types of stats
		private final int mDefaultSamplingRatio;

		/**
		* Sampling ratios for different types of stats
		*
		* <p>This SparseArray is passed by client and is READ-ONLY. The key to that SparseArray is
		* {@link CallStats.CallType}
		*
		* <p>If sampling ratio is missing for certain stats type,
		* {@link Config#mDefaultSamplingRatio} will be used.
		*
		* <p>E.g. sampling ratio=10 means that one out of every 10 stats was logged. If sampling
		* ratio is 1, we will log each sample and it acts as if the sampling is disabled.
		*/
		@NonNull
		private final SparseIntArray mSamplingRatios;

		/**
		* Configuration for {@link PlatformLogger}
		*
		* @param minTimeIntervalBetweenSamplesMillis minimum time interval apart in Milliseconds
		* required for two consecutive stats logged
		* @param defaultSamplingRatio default sampling ratio
		* @param samplingRatios SparseArray to customize sampling ratio for
		* different stat types
		*/
		public Config(long minTimeIntervalBetweenSamplesMillis,
		int defaultSamplingRatio,
		@Nullable SparseIntArray samplingRatios) {
		mMinTimeIntervalBetweenSamplesMillis = minTimeIntervalBetweenSamplesMillis;
		mDefaultSamplingRatio = defaultSamplingRatio;
		if (samplingRatios != null) {
		mSamplingRatios = samplingRatios;
		} else {
		mSamplingRatios = new SparseIntArray();
		}
		}
		}

		/**
		* Helper class to hold platform specific stats for Westworld.
		*/
		static final class ExtraStats {
		// UID for the calling package of the stats.
		final int mPackageUid;
		// sampling ratio for the call type of the stats.
		final int mSamplingRatio;
		// number of samplings skipped before the current one for the same call type.
		final int mSkippedSampleCount;

		ExtraStats(int packageUid, int samplingRatio, int skippedSampleCount) {
		mPackageUid = packageUid;
		mSamplingRatio = samplingRatio;
		mSkippedSampleCount = skippedSampleCount;
		}
		}

		/**
		* Westworld constructor
		*/
		public PlatformLogger(@NonNull Context context, int userId, @NonNull Config config) {
		mContext = Preconditions.checkNotNull(context);
		mConfig = Preconditions.checkNotNull(config);
		mUserId = userId;
		}

		/** Logs {@link CallStats}. */
		@Override
		public void logStats(@NonNull CallStats stats) {
		Preconditions.checkNotNull(stats);
		synchronized (mLock) {
		if (shouldLogForTypeLocked(stats.getCallType())) {
		logToWestworldLocked(stats);
		}
		}
		}

		/** Logs {@link PutDocumentStats}. */
		@Override
		public void logStats(@NonNull PutDocumentStats stats) {
		Preconditions.checkNotNull(stats);
		synchronized (mLock) {
		if (shouldLogForTypeLocked(CallStats.CALL_TYPE_PUT_DOCUMENT)) {
		logToWestworldLocked(stats);
		}
		}
		}

		/**
		* Removes cached UID for package.
		*
		* @return removed UID for the package, or {@code INVALID_UID} if package was not previously
		* cached.
		*/
		public int removeCachedUidForPackage(@NonNull String packageName) {
		// TODO(b/173532925) This needs to be called when we get PACKAGE_REMOVED intent
		Preconditions.checkNotNull(packageName);
		synchronized (mLock) {
		Integer uid = mPackageUidCacheLocked.remove(packageName);
		return uid != null ? uid : Process.INVALID_UID;
		}
		}

		@GuardedBy("mLock")
		private void logToWestworldLocked(@NonNull CallStats stats) {
		mLastPushTimeMillisLocked = SystemClock.elapsedRealtime();
		ExtraStats extraStats = createExtraStatsLocked(stats.getGeneralStats().getPackageName(),
		stats.getCallType());
		/* TODO(b/173532925) Log the CallStats to Westworld
		stats.log(..., samplingRatio, skippedSampleCount, ...)
		*/
		}

		@GuardedBy("mLock")
		private void logToWestworldLocked(@NonNull PutDocumentStats stats) {
		mLastPushTimeMillisLocked = SystemClock.elapsedRealtime();
		ExtraStats extraStats = createExtraStatsLocked(stats.getGeneralStats().getPackageName(),
		CallStats.CALL_TYPE_PUT_DOCUMENT);
		/* TODO(b/173532925) Log the PutDocumentStats to Westworld
		stats.log(..., samplingRatio, skippedSampleCount, ...)
		*/
		}

		@VisibleForTesting
		@GuardedBy("mLock")
		@NonNull
		ExtraStats createExtraStatsLocked(@NonNull String packageName,
		@CallStats.CallType int callType) {
		int packageUid = getPackageUidAsUserLocked(packageName);
		int samplingRatio = mConfig.mSamplingRatios.get(callType,
		mConfig.mDefaultSamplingRatio);

		int skippedSampleCount = mSkippedSampleCountLocked.get(callType,
		/valueOfKeyIfNotFound=/ 0);
		mSkippedSampleCountLocked.put(callType, 0);

		return new ExtraStats(packageUid, samplingRatio, skippedSampleCount);
		}

		/**
		* Checks if this stats should be logged.
		*
		* <p>It won't be logged if it is "sampled" out, or it is too close to the previous logged
		* stats.
		*/
		@GuardedBy("mLock")
		@VisibleForTesting
		boolean shouldLogForTypeLocked(@CallStats.CallType int callType) {
		int samplingRatio = mConfig.mSamplingRatios.get(callType,
		mConfig.mDefaultSamplingRatio);

		// Sampling
		if (!shouldSample(samplingRatio)) {
		return false;
		}

		// Rate limiting
		// Check the timestamp to see if it is too close to last logged sample
		long currentTimeMillis = SystemClock.elapsedRealtime();
		if (mLastPushTimeMillisLocked
		> currentTimeMillis - mConfig.mMinTimeIntervalBetweenSamplesMillis) {
		int count = mSkippedSampleCountLocked.get(callType, /valueOfKeyIfNotFound=/ 0);
		++count;
		mSkippedSampleCountLocked.put(callType, count);
		return false;
		}

		return true;
		}

		/**
		* Checks if the stats should be "sampled"
		*
		* @param samplingRatio sampling ratio
		* @return if the stats should be sampled
		*/
		private boolean shouldSample(int samplingRatio) {
		if (samplingRatio <= 0) {
		return false;
		}

		return mRng.nextInt((int) samplingRatio) == 0;
		}

		/**
		* Finds the UID of the {@code packageName}. Returns {@link Process#INVALID_UID} if unable to
		* find the UID.
		*/
		@GuardedBy("mLock")
		private int getPackageUidAsUserLocked(@NonNull String packageName) {
		Integer packageUid = mPackageUidCacheLocked.get(packageName);
		if (packageUid != null) {
		return packageUid;
		}

		// TODO(b/173532925) since VisibilityStore has the same method, we can make this a
		// utility function
		try {
		packageUid = mContext.getPackageManager().getPackageUidAsUser(packageName, mUserId);
		mPackageUidCacheLocked.put(packageName, packageUid);
		return packageUid;
		} catch (PackageManager.NameNotFoundException e) {
		// Package doesn't exist, continue
		}
		return Process.INVALID_UID;
		}

		//
		// Functions below are used for tests only
		//
		@VisibleForTesting
		@GuardedBy("mLock")
		void setLastPushTimeMillisLocked(long lastPushElapsedTimeMillis) {
		mLastPushTimeMillisLocked = lastPushElapsedTimeMillis;
		}
		}

services/tests/servicestests/src/com/android/server/appsearch/stats/PlatformLoggerTest.java

0 → 100644

+248 −0

Original line number	Diff line number	Diff line
		/*
		* 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.server.appsearch.stats;

		import static com.google.common.truth.Truth.assertThat;

		import static org.mockito.Mockito.anyInt;
		import static org.mockito.Mockito.eq;
		import static org.mockito.Mockito.times;
		import static org.mockito.Mockito.verify;

		import android.content.Context;
		import android.content.ContextWrapper;
		import android.content.pm.PackageManager;
		import android.os.SystemClock;
		import android.os.UserHandle;
		import android.util.SparseIntArray;

		import androidx.test.core.app.ApplicationProvider;

		import com.android.server.appsearch.external.localstorage.MockPackageManager;
		import com.android.server.appsearch.external.localstorage.stats.CallStats;

		import org.junit.Before;
		import org.junit.Test;

		public class PlatformLoggerTest {
		private static final int TEST_MIN_TIME_INTERVAL_BETWEEN_SAMPLES_MILLIS = 100;
		private static final int TEST_DEFAULT_SAMPLING_RATIO = 10;
		private static final String TEST_PACKAGE_NAME = "packageName";
		private MockPackageManager mMockPackageManager = new MockPackageManager();
		private Context mContext;

		@Before
		public void setUp() throws Exception {
		Context context = ApplicationProvider.getApplicationContext();
		mContext =
		new ContextWrapper(context) {
		@Override
		public PackageManager getPackageManager() {
		return mMockPackageManager.getMockPackageManager();
		}
		};
		}

		@Test
		public void testcreateExtraStatsLocked_nullSamplingRatioMap_returnsDefaultSamplingRatio() {
		PlatformLogger logger = new PlatformLogger(
		ApplicationProvider.getApplicationContext(),
		UserHandle.USER_NULL,
		new PlatformLogger.Config(
		TEST_MIN_TIME_INTERVAL_BETWEEN_SAMPLES_MILLIS,
		TEST_DEFAULT_SAMPLING_RATIO,
		/samplingRatioMap=/ null));

		// Make sure default sampling ratio is used if samplingMap is not provided.
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_UNKNOWN).mSamplingRatio).isEqualTo(
		TEST_DEFAULT_SAMPLING_RATIO);
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_INITIALIZE).mSamplingRatio).isEqualTo(
		TEST_DEFAULT_SAMPLING_RATIO);
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_QUERY).mSamplingRatio).isEqualTo(
		TEST_DEFAULT_SAMPLING_RATIO);
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_FLUSH).mSamplingRatio).isEqualTo(
		TEST_DEFAULT_SAMPLING_RATIO);
		}


		@Test
		public void testcreateExtraStatsLocked_with_samplingRatioMap_returnsConfiguredSamplingRatio() {
		int putDocumentSamplingRatio = 1;
		int querySamplingRatio = 2;
		final SparseIntArray samplingRatios = new SparseIntArray();
		samplingRatios.put(CallStats.CALL_TYPE_PUT_DOCUMENT, putDocumentSamplingRatio);
		samplingRatios.put(CallStats.CALL_TYPE_QUERY, querySamplingRatio);
		PlatformLogger logger = new PlatformLogger(
		ApplicationProvider.getApplicationContext(),
		UserHandle.USER_NULL,
		new PlatformLogger.Config(
		TEST_MIN_TIME_INTERVAL_BETWEEN_SAMPLES_MILLIS,
		TEST_DEFAULT_SAMPLING_RATIO,
		samplingRatios));

		// The default sampling ratio should be used if no sampling ratio is
		// provided for certain call type.
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_INITIALIZE).mSamplingRatio).isEqualTo(
		TEST_DEFAULT_SAMPLING_RATIO);
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_FLUSH).mSamplingRatio).isEqualTo(
		TEST_DEFAULT_SAMPLING_RATIO);

		// The configured sampling ratio is used if sampling ratio is available
		// for certain call type.
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_PUT_DOCUMENT).mSamplingRatio).isEqualTo(
		putDocumentSamplingRatio);
		assertThat(logger.createExtraStatsLocked(TEST_PACKAGE_NAME,
		CallStats.CALL_TYPE_QUERY).mSamplingRatio).isEqualTo(
		querySamplingRatio);
		}

		@Test
		public void testShouldLogForTypeLocked_trueWhenSampleRatioIsOne() {
		final int samplingRatio = 1;
		final String testPackageName = "packageName";
		PlatformLogger logger = new PlatformLogger(
		ApplicationProvider.getApplicationContext(),
		UserHandle.USER_NULL,
		new PlatformLogger.Config(
		TEST_MIN_TIME_INTERVAL_BETWEEN_SAMPLES_MILLIS,
		samplingRatio,
		/* samplingMap=*/ null));

		// Sample should always be logged for the first time if sampling is disabled(value is one).
		assertThat(logger.shouldLogForTypeLocked(CallStats.CALL_TYPE_PUT_DOCUMENT)).isTrue();
		assertThat(logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT).mSkippedSampleCount).isEqualTo(0);
		}

		@Test
		public void testShouldLogForTypeLocked_falseWhenSampleRatioIsNegative() {
		final int samplingRatio = -1;
		final String testPackageName = "packageName";
		PlatformLogger logger = new PlatformLogger(
		ApplicationProvider.getApplicationContext(),
		UserHandle.USER_NULL,
		new PlatformLogger.Config(
		TEST_MIN_TIME_INTERVAL_BETWEEN_SAMPLES_MILLIS,
		samplingRatio,
		/* samplingMap=*/ null));

		// Makes sure sample will be excluded due to sampling if sample ratio is negative.
		assertThat(logger.shouldLogForTypeLocked(CallStats.CALL_TYPE_PUT_DOCUMENT)).isFalse();
		// Skipped count should be 0 since it doesn't pass the sampling.
		assertThat(logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT).mSkippedSampleCount).isEqualTo(0);
		}

		@Test
		public void testShouldLogForTypeLocked_falseWhenWithinCoolOffInterval() {
		// Next sample won't be excluded due to sampling.
		final int samplingRatio = 1;
		// Next sample would guaranteed to be too close.
		final int minTimeIntervalBetweenSamplesMillis = Integer.MAX_VALUE;
		final String testPackageName = "packageName";
		PlatformLogger logger = new PlatformLogger(
		ApplicationProvider.getApplicationContext(),
		UserHandle.USER_NULL,
		new PlatformLogger.Config(
		minTimeIntervalBetweenSamplesMillis,
		samplingRatio,
		/* samplingMap=*/ null));
		logger.setLastPushTimeMillisLocked(SystemClock.elapsedRealtime());

		// Makes sure sample will be excluded due to rate limiting if samples are too close.
		assertThat(logger.shouldLogForTypeLocked(CallStats.CALL_TYPE_PUT_DOCUMENT)).isFalse();
		assertThat(logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT).mSkippedSampleCount).isEqualTo(1);
		}

		@Test
		public void testShouldLogForTypeLocked_trueWhenOutsideOfCoolOffInterval() {
		// Next sample won't be excluded due to sampling.
		final int samplingRatio = 1;
		// Next sample would guaranteed to be included.
		final int minTimeIntervalBetweenSamplesMillis = 0;
		final String testPackageName = "packageName";
		PlatformLogger logger = new PlatformLogger(
		ApplicationProvider.getApplicationContext(),
		UserHandle.USER_NULL,
		new PlatformLogger.Config(
		minTimeIntervalBetweenSamplesMillis,
		samplingRatio,
		/* samplingMap=*/ null));
		logger.setLastPushTimeMillisLocked(SystemClock.elapsedRealtime());

		// Makes sure sample will be logged if it is not too close to previous sample.
		assertThat(logger.shouldLogForTypeLocked(CallStats.CALL_TYPE_PUT_DOCUMENT)).isTrue();
		assertThat(logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT).mSkippedSampleCount).isEqualTo(0);
		}

		/** Makes sure the caching works while getting the UID for calling package. */
		@Test
		public void testGetPackageUidAsUser() throws Exception {
		final String testPackageName = "packageName";
		final int testUid = 1234;
		PlatformLogger logger = new PlatformLogger(
		mContext,
		mContext.getUserId(),
		new PlatformLogger.Config(
		TEST_MIN_TIME_INTERVAL_BETWEEN_SAMPLES_MILLIS,
		TEST_DEFAULT_SAMPLING_RATIO,
		/* samplingMap=*/ null));
		mMockPackageManager.mockGetPackageUidAsUser(testPackageName, mContext.getUserId(), testUid);

		//
		// First time, no cache
		//
		PlatformLogger.ExtraStats extraStats = logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT);

		verify(mMockPackageManager.getMockPackageManager(), times(1)).getPackageUidAsUser(
		eq(testPackageName), /userId=/ anyInt());
		assertThat(extraStats.mPackageUid).isEqualTo(testUid);

		//
		// Second time, we have cache
		//
		extraStats = logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT);

		// Count is still one since we will use the cache
		verify(mMockPackageManager.getMockPackageManager(), times(1)).getPackageUidAsUser(
		eq(testPackageName), /userId=/ anyInt());
		assertThat(extraStats.mPackageUid).isEqualTo(testUid);

		//
		// Remove the cache and try again
		//
		assertThat(logger.removeCachedUidForPackage(testPackageName)).isEqualTo(testUid);
		extraStats = logger.createExtraStatsLocked(testPackageName,
		CallStats.CALL_TYPE_PUT_DOCUMENT);

		// count increased by 1 since cache is cleared
		verify(mMockPackageManager.getMockPackageManager(), times(2)).getPackageUidAsUser(
		eq(testPackageName), /userId=/ anyInt());
		assertThat(extraStats.mPackageUid).isEqualTo(testUid);
		}
		}