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

Merge "Log CallStats for more api calls" into sc-dev

Browse Source
This commit is contained in:
Xiaoyu Jin
2021-05-14 05:26:58 +00:00
committed by Android (Google) Code Review
parent d9c05c23e6 2830ace18c
commit 05e3aca989
5 changed files with 197 additions and 11 deletions
Download Patch File Download Diff File Expand all files Collapse all files

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

@@ -353,6 +353,7 @@ public final class AppSearchSession implements Closeable {
new ArrayList<>(request.getIds()),
request.getProjectionsInternal(),
mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime(),
new IAppSearchBatchResultCallback.Stub() {
@Override
public void onResult(AppSearchBatchResultParcel resultParcel) {
@@ -566,6 +567,7 @@ public final class AppSearchSession implements Closeable {
try {
mService.removeByDocumentId(mPackageName, mDatabaseName, request.getNamespace(),
new ArrayList<>(request.getIds()), mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime(),
new IAppSearchBatchResultCallback.Stub() {
@Override
public void onResult(AppSearchBatchResultParcel resultParcel) {
@@ -616,6 +618,7 @@ public final class AppSearchSession implements Closeable {
try {
mService.removeByQuery(mPackageName, mDatabaseName, queryExpression,
searchSpec.getBundle(), mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime(),
new IAppSearchResultCallback.Stub() {
@Override
public void onResult(AppSearchResultParcel resultParcel) {
@@ -675,7 +678,8 @@ public final class AppSearchSession implements Closeable {
public void close() {
if (mIsMutated && !mIsClosed) {
try {
mService.persistToDisk(mUserId);
mService.persistToDisk(mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime());
mIsClosed = true;
} catch (RemoteException e) {
Log.e(TAG, "Unable to close the AppSearchSession", e);
@@ -705,6 +709,7 @@ public final class AppSearchSession implements Closeable {
request.isForceOverride(),
request.getVersion(),
mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime(),
new IAppSearchResultCallback.Stub() {
@Override
public void onResult(AppSearchResultParcel resultParcel) {
@@ -792,6 +797,7 @@ public final class AppSearchSession implements Closeable {
/*forceOverride=*/ false,
request.getVersion(),
mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime(),
new IAppSearchResultCallback.Stub() {
@Override
public void onResult(AppSearchResultParcel resultParcel) {
@@ -843,6 +849,7 @@ public final class AppSearchSession implements Closeable {
/*forceOverride=*/ true,
request.getVersion(),
mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime(),
new IAppSearchResultCallback.Stub() {
@Override
public void onResult(AppSearchResultParcel resultParcel) {

3
apex/appsearch/framework/java/android/app/appsearch/GlobalSearchSession.java
View File

@@ -186,7 +186,8 @@ public class GlobalSearchSession implements Closeable {
public void close() {
if (mIsMutated && !mIsClosed) {
try {
mService.persistToDisk(mUserId);
mService.persistToDisk(mUserId,
/*binderCallStartTimeMillis=*/ SystemClock.elapsedRealtime());
mIsClosed = true;
} catch (RemoteException e) {
Log.e(TAG, "Unable to close the GlobalSearchSession", e);

11
apex/appsearch/framework/java/android/app/appsearch/aidl/IAppSearchManager.aidl
View File

@@ -37,6 +37,7 @@ interface IAppSearchManager {
* incompatible documents will be deleted.
* @param schemaVersion The overall schema version number of the request.
* @param userId Id of the calling user
* @param binderCallStartTimeMillis start timestamp of binder call in Millis
* @param callback {@link IAppSearchResultCallback#onResult} will be called with an
* {@link AppSearchResult}&lt;{@link Bundle}&gt;, where the value are
* {@link SetSchemaResponse} bundle.
@@ -50,6 +51,7 @@ interface IAppSearchManager {
boolean forceOverride,
in int schemaVersion,
in int userId,
in long binderCallStartTimeMillis,
in IAppSearchResultCallback callback);
/**
@@ -115,6 +117,7 @@ interface IAppSearchManager {
* @param typePropertyPaths A map of schema type to a list of property paths to return in the
* result.
* @param userId Id of the calling user
* @param binderCallStartTimeMillis start timestamp of binder call in Millis
* @param callback
* If the call fails to start, {@link IAppSearchBatchResultCallback#onSystemError}
* will be called with the cause throwable. Otherwise,
@@ -129,6 +132,7 @@ interface IAppSearchManager {
in List<String> ids,
in Map<String, List<String>> typePropertyPaths,
in int userId,
in long binderCallStartTimeMillis,
in IAppSearchBatchResultCallback callback);
/**
@@ -273,6 +277,7 @@ interface IAppSearchManager {
* @param namespace Namespace of the document to remove.
* @param ids The IDs of the documents to delete
* @param userId Id of the calling user
* @param binderCallStartTimeMillis start timestamp of binder call in Millis
* @param callback
* If the call fails to start, {@link IAppSearchBatchResultCallback#onSystemError}
* will be called with the cause throwable. Otherwise,
@@ -287,6 +292,7 @@ interface IAppSearchManager {
in String namespace,
in List<String> ids,
in int userId,
in long binderCallStartTimeMillis,
in IAppSearchBatchResultCallback callback);
/**
@@ -297,6 +303,7 @@ interface IAppSearchManager {
* @param queryExpression String to search for
* @param searchSpecBundle SearchSpec bundle
* @param userId Id of the calling user
* @param binderCallStartTimeMillis start timestamp of binder call in Millis
* @param callback {@link IAppSearchResultCallback#onResult} will be called with an
* {@link AppSearchResult}&lt;{@link Void}&gt;.
*/
@@ -306,6 +313,7 @@ interface IAppSearchManager {
in String queryExpression,
in Bundle searchSpecBundle,
in int userId,
in long binderCallStartTimeMillis,
in IAppSearchResultCallback callback);
/**
@@ -328,8 +336,9 @@ interface IAppSearchManager {
* Persists all update/delete requests to the disk.
*
* @param userId Id of the calling user
* @param binderCallStartTimeMillis start timestamp of binder call in Millis
*/
void persistToDisk(in int userId);
void persistToDisk(in int userId, in long binderCallStartTimeMillis);
/**
* Creates and initializes AppSearchImpl for the calling app.

172
apex/appsearch/service/java/com/android/server/appsearch/AppSearchManagerService.java
View File

@@ -278,14 +278,20 @@ public class AppSearchManagerService extends SystemService {
boolean forceOverride,
int schemaVersion,
@UserIdInt int userId,
@ElapsedRealtimeLong long binderCallStartTimeMillis,
@NonNull IAppSearchResultCallback callback) {
Objects.requireNonNull(packageName);
Objects.requireNonNull(databaseName);
Objects.requireNonNull(schemaBundles);
Objects.requireNonNull(callback);
long totalLatencyStartTimeMillis = SystemClock.elapsedRealtime();
int callingUid = Binder.getCallingUid();
int callingUserId = handleIncomingUser(userId, callingUid);
EXECUTOR.execute(() -> {
@AppSearchResult.ResultCode int statusCode = AppSearchResult.RESULT_OK;
PlatformLogger logger = null;
int operationSuccessCount = 0;
int operationFailureCount = 0;
try {
verifyUserUnlocked(callingUserId);
verifyCallingPackage(callingUid, packageName);
@@ -306,6 +312,7 @@ public class AppSearchManagerService extends SystemService {
schemasPackageAccessible.put(entry.getKey(), packageIdentifiers);
}
AppSearchImpl impl = mImplInstanceManager.getAppSearchImpl(callingUserId);
logger = mLoggerInstanceManager.getPlatformLogger(callingUserId);
SetSchemaResponse setSchemaResponse = impl.setSchema(
packageName,
databaseName,
@@ -314,10 +321,33 @@ public class AppSearchManagerService extends SystemService {
schemasPackageAccessible,
forceOverride,
schemaVersion);
++operationSuccessCount;
invokeCallbackOnResult(callback,
AppSearchResult.newSuccessfulResult(setSchemaResponse.getBundle()));
} catch (Throwable t) {
++operationFailureCount;
statusCode = throwableToFailedResult(t).getResultCode();
invokeCallbackOnError(callback, t);
} finally {
if (logger != null) {
int estimatedBinderLatencyMillis =
2 * (int) (totalLatencyStartTimeMillis - binderCallStartTimeMillis);
int totalLatencyMillis =
(int) (SystemClock.elapsedRealtime() - totalLatencyStartTimeMillis);
CallStats.Builder cBuilder = new CallStats.Builder(packageName,
databaseName)
.setCallType(CallStats.CALL_TYPE_SET_SCHEMA)
// TODO(b/173532925) check the existing binder call latency chart
// is good enough for us:
// http://dashboards/view/_72c98f9a_91d9_41d4_ab9a_bc14f79742b4
.setEstimatedBinderLatencyMillis(estimatedBinderLatencyMillis)
.setNumOperationsSucceeded(operationSuccessCount)
.setNumOperationsFailed(operationFailureCount);
cBuilder.getGeneralStatsBuilder()
.setStatusCode(statusCode)
.setTotalLatencyMillis(totalLatencyMillis);
logger.logStats(cBuilder.build());
}
}
});
}
@@ -414,7 +444,8 @@ public class AppSearchManagerService extends SystemService {
throwableToFailedResult(t));
AppSearchResult<Void> result = throwableToFailedResult(t);
resultBuilder.setResult(document.getId(), result);
// for failures, we would just log the one for last failure
// Since we can only include one status code in the atom,
// for failures, we would just save the one for the last failure
statusCode = result.getResultCode();
++operationFailureCount;
}
@@ -423,6 +454,8 @@ public class AppSearchManagerService extends SystemService {
impl.persistToDisk(PersistType.Code.LITE);
invokeCallbackOnResult(callback, resultBuilder.build());
} catch (Throwable t) {
++operationFailureCount;
statusCode = throwableToFailedResult(t).getResultCode();
invokeCallbackOnError(callback, t);
} finally {
if (logger != null) {
@@ -456,15 +489,21 @@ public class AppSearchManagerService extends SystemService {
@NonNull List<String> ids,
@NonNull Map<String, List<String>> typePropertyPaths,
@UserIdInt int userId,
@ElapsedRealtimeLong long binderCallStartTimeMillis,
@NonNull IAppSearchBatchResultCallback callback) {
Objects.requireNonNull(packageName);
Objects.requireNonNull(databaseName);
Objects.requireNonNull(namespace);
Objects.requireNonNull(ids);
Objects.requireNonNull(callback);
long totalLatencyStartTimeMillis = SystemClock.elapsedRealtime();
int callingUid = Binder.getCallingUid();
int callingUserId = handleIncomingUser(userId, callingUid);
EXECUTOR.execute(() -> {
@AppSearchResult.ResultCode int statusCode = AppSearchResult.RESULT_OK;
PlatformLogger logger = null;
int operationSuccessCount = 0;
int operationFailureCount = 0;
try {
verifyUserUnlocked(callingUserId);
verifyCallingPackage(callingUid, packageName);
@@ -472,6 +511,7 @@ public class AppSearchManagerService extends SystemService {
new AppSearchBatchResult.Builder<>();
AppSearchImpl impl =
mImplInstanceManager.getAppSearchImpl(callingUserId);
logger = mLoggerInstanceManager.getPlatformLogger(callingUserId);
for (int i = 0; i < ids.size(); i++) {
String id = ids.get(i);
try {
@@ -482,14 +522,42 @@ public class AppSearchManagerService extends SystemService {
namespace,
id,
typePropertyPaths);
++operationSuccessCount;
resultBuilder.setSuccess(id, document.getBundle());
} catch (Throwable t) {
resultBuilder.setResult(id, throwableToFailedResult(t));
// Since we can only include one status code in the atom,
// for failures, we would just save the one for the last failure
AppSearchResult<Bundle> result = throwableToFailedResult(t);
resultBuilder.setResult(id, result);
statusCode = result.getResultCode();
++operationFailureCount;
}
}
invokeCallbackOnResult(callback, resultBuilder.build());
} catch (Throwable t) {
++operationFailureCount;
statusCode = throwableToFailedResult(t).getResultCode();
invokeCallbackOnError(callback, t);
} finally {
if (logger != null) {
int estimatedBinderLatencyMillis =
2 * (int) (totalLatencyStartTimeMillis - binderCallStartTimeMillis);
int totalLatencyMillis =
(int) (SystemClock.elapsedRealtime() - totalLatencyStartTimeMillis);
CallStats.Builder cBuilder = new CallStats.Builder(packageName,
databaseName)
.setCallType(CallStats.CALL_TYPE_GET_DOCUMENTS)
// TODO(b/173532925) check the existing binder call latency chart
// is good enough for us:
// http://dashboards/view/_72c98f9a_91d9_41d4_ab9a_bc14f79742b4
.setEstimatedBinderLatencyMillis(estimatedBinderLatencyMillis)
.setNumOperationsSucceeded(operationSuccessCount)
.setNumOperationsFailed(operationFailureCount);
cBuilder.getGeneralStatsBuilder()
.setStatusCode(statusCode)
.setTotalLatencyMillis(totalLatencyMillis);
logger.logStats(cBuilder.build());
}
}
});
}
@@ -803,14 +871,20 @@ public class AppSearchManagerService extends SystemService {
@NonNull String namespace,
@NonNull List<String> ids,
@UserIdInt int userId,
@ElapsedRealtimeLong long binderCallStartTimeMillis,
@NonNull IAppSearchBatchResultCallback callback) {
Objects.requireNonNull(packageName);
Objects.requireNonNull(databaseName);
Objects.requireNonNull(ids);
Objects.requireNonNull(callback);
long totalLatencyStartTimeMillis = SystemClock.elapsedRealtime();
int callingUid = Binder.getCallingUid();
int callingUserId = handleIncomingUser(userId, callingUid);
EXECUTOR.execute(() -> {
@AppSearchResult.ResultCode int statusCode = AppSearchResult.RESULT_OK;
PlatformLogger logger = null;
int operationSuccessCount = 0;
int operationFailureCount = 0;
try {
verifyUserUnlocked(callingUserId);
verifyCallingPackage(callingUid, packageName);
@@ -818,20 +892,49 @@ public class AppSearchManagerService extends SystemService {
new AppSearchBatchResult.Builder<>();
AppSearchImpl impl =
mImplInstanceManager.getAppSearchImpl(callingUserId);
logger = mLoggerInstanceManager.getPlatformLogger(callingUserId);
for (int i = 0; i < ids.size(); i++) {
String id = ids.get(i);
try {
impl.remove(packageName, databaseName, namespace, id);
++operationSuccessCount;
resultBuilder.setSuccess(id, /*result= */ null);
} catch (Throwable t) {
resultBuilder.setResult(id, throwableToFailedResult(t));
AppSearchResult<Void> result = throwableToFailedResult(t);
resultBuilder.setResult(id, result);
// Since we can only include one status code in the atom,
// for failures, we would just save the one for the last failure
statusCode = result.getResultCode();
++operationFailureCount;
}
}
// Now that the batch has been written. Persist the newly written data.
impl.persistToDisk(PersistType.Code.LITE);
invokeCallbackOnResult(callback, resultBuilder.build());
} catch (Throwable t) {
++operationFailureCount;
statusCode = throwableToFailedResult(t).getResultCode();
invokeCallbackOnError(callback, t);
} finally {
if (logger != null) {
int estimatedBinderLatencyMillis =
2 * (int) (totalLatencyStartTimeMillis - binderCallStartTimeMillis);
int totalLatencyMillis =
(int) (SystemClock.elapsedRealtime() - totalLatencyStartTimeMillis);
CallStats.Builder cBuilder = new CallStats.Builder(packageName,
databaseName)
.setCallType(CallStats.CALL_TYPE_REMOVE_DOCUMENTS_BY_ID)
// TODO(b/173532925) check the existing binder call latency chart
// is good enough for us:
// http://dashboards/view/_72c98f9a_91d9_41d4_ab9a_bc14f79742b4
.setEstimatedBinderLatencyMillis(estimatedBinderLatencyMillis)
.setNumOperationsSucceeded(operationSuccessCount)
.setNumOperationsFailed(operationFailureCount);
cBuilder.getGeneralStatsBuilder()
.setStatusCode(statusCode)
.setTotalLatencyMillis(totalLatencyMillis);
logger.logStats(cBuilder.build());
}
}
});
}
@@ -843,20 +946,28 @@ public class AppSearchManagerService extends SystemService {
@NonNull String queryExpression,
@NonNull Bundle searchSpecBundle,
@UserIdInt int userId,
@ElapsedRealtimeLong long binderCallStartTimeMillis,
@NonNull IAppSearchResultCallback callback) {
// TODO(b/173532925) log CallStats once we have CALL_TYPE_REMOVE_BY_QUERY added
Objects.requireNonNull(packageName);
Objects.requireNonNull(databaseName);
Objects.requireNonNull(queryExpression);
Objects.requireNonNull(searchSpecBundle);
Objects.requireNonNull(callback);
long totalLatencyStartTimeMillis = SystemClock.elapsedRealtime();
int callingUid = Binder.getCallingUid();
int callingUserId = handleIncomingUser(userId, callingUid);
EXECUTOR.execute(() -> {
@AppSearchResult.ResultCode int statusCode = AppSearchResult.RESULT_OK;
PlatformLogger logger = null;
int operationSuccessCount = 0;
int operationFailureCount = 0;
try {
verifyUserUnlocked(callingUserId);
verifyCallingPackage(callingUid, packageName);
AppSearchImpl impl =
mImplInstanceManager.getAppSearchImpl(callingUserId);
logger = mLoggerInstanceManager.getPlatformLogger(callingUserId);
impl.removeByQuery(
packageName,
databaseName,
@@ -864,9 +975,32 @@ public class AppSearchManagerService extends SystemService {
new SearchSpec(searchSpecBundle));
// Now that the batch has been written. Persist the newly written data.
impl.persistToDisk(PersistType.Code.LITE);
++operationSuccessCount;
invokeCallbackOnResult(callback, AppSearchResult.newSuccessfulResult(null));
} catch (Throwable t) {
++operationFailureCount;
statusCode = throwableToFailedResult(t).getResultCode();
invokeCallbackOnError(callback, t);
} finally {
if (logger != null) {
int estimatedBinderLatencyMillis =
2 * (int) (totalLatencyStartTimeMillis - binderCallStartTimeMillis);
int totalLatencyMillis =
(int) (SystemClock.elapsedRealtime() - totalLatencyStartTimeMillis);
CallStats.Builder cBuilder = new CallStats.Builder(packageName,
databaseName)
.setCallType(CallStats.CALL_TYPE_REMOVE_DOCUMENTS_BY_SEARCH)
// TODO(b/173532925) check the existing binder call latency chart
// is good enough for us:
// http://dashboards/view/_72c98f9a_91d9_41d4_ab9a_bc14f79742b4
.setEstimatedBinderLatencyMillis(estimatedBinderLatencyMillis)
.setNumOperationsSucceeded(operationSuccessCount)
.setNumOperationsFailed(operationFailureCount);
cBuilder.getGeneralStatsBuilder()
.setStatusCode(statusCode)
.setTotalLatencyMillis(totalLatencyMillis);
logger.logStats(cBuilder.build());
}
}
});
}
@@ -900,17 +1034,47 @@ public class AppSearchManagerService extends SystemService {
}
@Override
public void persistToDisk(@UserIdInt int userId) {
public void persistToDisk(@UserIdInt int userId,
@ElapsedRealtimeLong long binderCallStartTimeMillis) {
long totalLatencyStartTimeMillis = SystemClock.elapsedRealtime();
int callingUid = Binder.getCallingUid();
int callingUserId = handleIncomingUser(userId, callingUid);
EXECUTOR.execute(() -> {
@AppSearchResult.ResultCode int statusCode = AppSearchResult.RESULT_OK;
PlatformLogger logger = null;
int operationSuccessCount = 0;
int operationFailureCount = 0;
try {
verifyUserUnlocked(callingUserId);
AppSearchImpl impl =
mImplInstanceManager.getAppSearchImpl(callingUserId);
logger = mLoggerInstanceManager.getPlatformLogger(callingUserId);
impl.persistToDisk(PersistType.Code.FULL);
++operationSuccessCount;
} catch (Throwable t) {
++operationFailureCount;
statusCode = throwableToFailedResult(t).getResultCode();
Log.e(TAG, "Unable to persist the data to disk", t);
} finally {
if (logger != null) {
int estimatedBinderLatencyMillis =
2 * (int) (totalLatencyStartTimeMillis - binderCallStartTimeMillis);
int totalLatencyMillis =
(int) (SystemClock.elapsedRealtime() - totalLatencyStartTimeMillis);
CallStats.Builder cBuilder = new CallStats.Builder(/*packageName=*/ "",
/*databaseName=*/ "")
.setCallType(CallStats.CALL_TYPE_FLUSH)
// TODO(b/173532925) check the existing binder call latency chart
// is good enough for us:
// http://dashboards/view/_72c98f9a_91d9_41d4_ab9a_bc14f79742b4
.setEstimatedBinderLatencyMillis(estimatedBinderLatencyMillis)
.setNumOperationsSucceeded(operationSuccessCount)
.setNumOperationsFailed(operationFailureCount);
cBuilder.getGeneralStatsBuilder()
.setStatusCode(statusCode)
.setTotalLatencyMillis(totalLatencyMillis);
logger.logStats(cBuilder.build());
}
}
});
}

13
services/tests/servicestests/src/com/android/server/pm/BaseShortcutManagerTest.java
View File

@@ -661,7 +661,8 @@ public abstract class BaseShortcutManagerTest extends InstrumentationTestCase {
public void setSchema(String packageName, String databaseName, List<Bundle> schemaBundles,
List<String> schemasNotPlatformSurfaceable,
Map<String, List<Bundle>> schemasPackageAccessibleBundles, boolean forceOverride,
int userId, int version, IAppSearchResultCallback callback) throws RemoteException {
int userId, int version, long binderCallStartTimeMillis,
IAppSearchResultCallback callback) throws RemoteException {
for (Map.Entry<String, List<Bundle>> entry :
schemasPackageAccessibleBundles.entrySet()) {
final String key = entry.getKey();
@@ -721,6 +722,7 @@ public abstract class BaseShortcutManagerTest extends InstrumentationTestCase {
@Override
public void getDocuments(String packageName, String databaseName, String namespace,
List<String> ids, Map<String, List<String>> typePropertyPaths, int userId,
long binderCallStartTimeMillis,
IAppSearchBatchResultCallback callback) throws RemoteException {
final AppSearchBatchResult.Builder<String, Bundle> builder =
new AppSearchBatchResult.Builder<>();
@@ -822,7 +824,8 @@ public abstract class BaseShortcutManagerTest extends InstrumentationTestCase {
@Override
public void removeByDocumentId(String packageName, String databaseName, String namespace,
List<String> ids, int userId, IAppSearchBatchResultCallback callback)
List<String> ids, int userId, long binderCallStartTimeMillis,
IAppSearchBatchResultCallback callback)
throws RemoteException {
final AppSearchBatchResult.Builder<String, Void> builder =
new AppSearchBatchResult.Builder<>();
@@ -849,7 +852,8 @@ public abstract class BaseShortcutManagerTest extends InstrumentationTestCase {
@Override
public void removeByQuery(String packageName, String databaseName, String queryExpression,
Bundle searchSpecBundle, int userId, IAppSearchResultCallback callback)
Bundle searchSpecBundle, int userId, long binderCallStartTimeMillis,
IAppSearchResultCallback callback)
throws RemoteException {
final String key = getKey(userId, databaseName);
if (!mDocumentMap.containsKey(key)) {
@@ -869,7 +873,8 @@ public abstract class BaseShortcutManagerTest extends InstrumentationTestCase {
}
@Override
public void persistToDisk(int userId) throws RemoteException {
public void persistToDisk(int userId, long binderCallStartTimeMillis)
throws RemoteException {
}