Android/frameworks_base
1
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity

Merge "Add Logger Implementation for WestWorld" into sc-dev

Browse Source
This commit is contained in:
Xiaoyu Jin
2021-03-15 01:25:57 +00:00
committed by Android (Google) Code Review
parent f680c06c0f 4c1020ccb8
commit be03858fa6
3 changed files with 564 additions and 0 deletions
Download Patch File Download Diff File Expand all files Collapse all files

1
apex/appsearch/framework/java/android/app/appsearch/AppSearchSession.java
View File

@@ -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) {

315
apex/appsearch/service/java/com/android/server/appsearch/stats/PlatformLogger.java Normal file
View File

@@ -0,0 +1,315 @@
/*
* 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;
}
}

248
services/tests/servicestests/src/com/android/server/appsearch/stats/PlatformLoggerTest.java Normal file
View File

@@ -0,0 +1,248 @@
/*
* 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);
}
}