From 99e42a3ed87d44472226b2e2f8c2717dd4e5618c Mon Sep 17 00:00:00 2001 From: Arpan Kaphle Date: Fri, 10 Mar 2023 01:29:12 +0000 Subject: Candidate Metric Utilized in Framework This adds the candidate metric in the framework at various places and goes up to emits, with TODOs left for the actual emits once the atoms build as expected. Bug: 270403549 Test: Builds for now Change-Id: I1196dbf0a5d6d5c6573d5f8dbde15dc3bc916f86 --- .../server/credentials/CreateRequestSession.java | 2 +- .../credentials/CredentialManagerService.java | 10 ++- .../server/credentials/MetricUtilities.java | 30 ++++++++ .../server/credentials/ProviderClearSession.java | 17 ++--- .../server/credentials/ProviderCreateSession.java | 43 ++++++++---- .../server/credentials/ProviderGetSession.java | 59 +++++++++++----- .../server/credentials/ProviderSession.java | 56 +++++++++++---- .../android/server/credentials/RequestSession.java | 80 +++++++++++++--------- .../credentials/metrics/CandidatePhaseMetric.java | 29 ++++++++ 9 files changed, 233 insertions(+), 93 deletions(-) (limited to 'services/credentials/java') diff --git a/services/credentials/java/com/android/server/credentials/CreateRequestSession.java b/services/credentials/java/com/android/server/credentials/CreateRequestSession.java index 793d83e90cfe..4f8235a11b2a 100644 --- a/services/credentials/java/com/android/server/credentials/CreateRequestSession.java +++ b/services/credentials/java/com/android/server/credentials/CreateRequestSession.java @@ -168,7 +168,7 @@ public final class CreateRequestSession extends RequestSession providers, + int emitSequenceId) { + try { + var providerSessions = providers.values(); + int providerSize = providerSessions.size(); + int[] candidateUidList = new int[providerSize]; + int[] candidateQueryRoundTripTimeList = new int[providerSize]; + int[] candidateStatusList = new int[providerSize]; + int index = 0; + for (var session : providerSessions) { + CandidatePhaseMetric metric = session.mCandidatePhasePerProviderMetric; + candidateUidList[index] = metric.getCandidateUid(); + candidateQueryRoundTripTimeList[index] = metric.getQueryLatencyMicroseconds(); + candidateStatusList[index] = metric.getProviderQueryStatus(); + index++; + } + // TODO Handle the emit here + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } + } + /** * The most common logging helper, handles the overall status of the API request with the * provider status and latencies. Other versions of this method may be more useful depending @@ -90,6 +118,7 @@ public class MetricUtilities { * @param providers a map with known providers * @param callingUid the calling UID of the client app * @param chosenProviderFinalPhaseMetric the metric data type of the final chosen provider + * TODO remove soon */ protected static void logApiCalled(ApiName apiName, ApiStatus apiStatus, Map providers, int callingUid, @@ -133,6 +162,7 @@ public class MetricUtilities { * contain default values for all other optional parameters. * * TODO(b/271135048) - given space requirements, this may be a good candidate for another atom + * TODO immediately remove and carry over TODO to new log for this setup * * @param apiName the api name to log * @param apiStatus the status to log diff --git a/services/credentials/java/com/android/server/credentials/ProviderClearSession.java b/services/credentials/java/com/android/server/credentials/ProviderClearSession.java index 950cf4f9a482..b86dabaa8503 100644 --- a/services/credentials/java/com/android/server/credentials/ProviderClearSession.java +++ b/services/credentials/java/com/android/server/credentials/ProviderClearSession.java @@ -33,7 +33,7 @@ import android.util.Slog; * * @hide */ -public final class ProviderClearSession extends ProviderSession implements RemoteCredentialService.ProviderCallbacks { @@ -42,7 +42,8 @@ public final class ProviderClearSession extends ProviderSession 0) { + createEntries.forEach(c -> + mCandidatePhasePerProviderMetric.addEntry(EntryEnum.CREDENTIAL_ENTRY)); + } + mCandidatePhasePerProviderMetric.setNumEntriesTotal(numCreateEntries); + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } + } + @Override - @Nullable protected CreateCredentialProviderData prepareUiData() + @Nullable + protected CreateCredentialProviderData prepareUiData() throws IllegalArgumentException { Log.i(TAG, "In prepareUiData"); if (!ProviderSession.isUiInvokingStatus(getStatus())) { @@ -226,14 +248,7 @@ public final class ProviderCreateSession extends ProviderSession< @Override protected void invokeSession() { if (mRemoteCredentialService != null) { - /* - InitialPhaseMetric initMetric = ((RequestSession)mCallbacks).initMetric; - TODO immediately once the other change patched through - mCandidateProviderMetric.setSessionId(initMetric - .mInitialPhaseMetric.getSessionId()); - mCandidateProviderMetric.setStartTime(initMetric.getStartTime()) - */ - mCandidatePhasePerProviderMetric.setStartQueryTimeNanoseconds(System.nanoTime()); + startCandidateMetrics(); mRemoteCredentialService.onCreateCredential(mProviderRequest, this); } } @@ -305,12 +320,14 @@ public final class ProviderCreateSession extends ProviderSession< } private class ProviderResponseDataHandler { - @Nullable private final ComponentName mExpectedRemoteEntryProviderService; + @Nullable + private final ComponentName mExpectedRemoteEntryProviderService; @NonNull private final Map> mUiCreateEntries = new HashMap<>(); - @Nullable private Pair> mUiRemoteEntry = null; + @Nullable + private Pair> mUiRemoteEntry = null; ProviderResponseDataHandler(@Nullable ComponentName expectedRemoteEntryProviderService) { mExpectedRemoteEntryProviderService = expectedRemoteEntryProviderService; @@ -323,6 +340,7 @@ public final class ProviderCreateSession extends ProviderSession< setRemoteEntry(remoteEntry); } } + public void addCreateEntry(CreateEntry createEntry) { String id = generateUniqueId(); Entry entry = new Entry(SAVE_ENTRY_KEY, @@ -373,6 +391,7 @@ public final class ProviderCreateSession extends ProviderSession< private boolean isEmptyResponse() { return mUiCreateEntries.isEmpty() && mUiRemoteEntry == null; } + @Nullable public RemoteEntry getRemoteEntry(String entryKey) { return mUiRemoteEntry == null || mUiRemoteEntry diff --git a/services/credentials/java/com/android/server/credentials/ProviderGetSession.java b/services/credentials/java/com/android/server/credentials/ProviderGetSession.java index ec8bf22e4514..bf1db373446b 100644 --- a/services/credentials/java/com/android/server/credentials/ProviderGetSession.java +++ b/services/credentials/java/com/android/server/credentials/ProviderGetSession.java @@ -43,6 +43,8 @@ import android.util.Log; import android.util.Pair; import android.util.Slog; +import com.android.server.credentials.metrics.EntryEnum; + import java.util.ArrayList; import java.util.HashMap; import java.util.List; @@ -82,7 +84,8 @@ public final class ProviderGetSession extends ProviderSession beginGetOptionToCredentialOptionMap, String hybridService) { - super(context, beginGetRequest, callbacks, info.getComponentName() , + super(context, beginGetRequest, callbacks, info.getComponentName(), userId, remoteCredentialService); mCompleteRequest = completeGetRequest; mCallingAppInfo = callingAppInfo; @@ -191,6 +195,7 @@ public final class ProviderGetSession extends ProviderSession + mCandidatePhasePerProviderMetric.addEntry(EntryEnum.CREDENTIAL_ENTRY)); + response.getActions().forEach(c -> + mCandidatePhasePerProviderMetric.addEntry(EntryEnum.ACTION_ENTRY)); + response.getAuthenticationActions().forEach(c -> + mCandidatePhasePerProviderMetric.addEntry(EntryEnum.AUTHENTICATION_ENTRY)); + mCandidatePhasePerProviderMetric.setNumEntriesTotal(numCredEntries + numAuthEntries + + numActionEntries); + mCandidatePhasePerProviderMetric.setCredentialEntryCount(numCredEntries); + mCandidatePhasePerProviderMetric.setActionEntryCount(numActionEntries); + mCandidatePhasePerProviderMetric.setAuthenticationEntryCount(numAuthEntries); + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } + } + /** * When an invalid state occurs, e.g. entry mismatch or no response from provider, * we send back a TYPE_NO_CREDENTIAL error as to the developer. @@ -471,11 +494,12 @@ public final class ProviderGetSession extends ProviderSession> mUiCredentialEntries = new HashMap<>(); @@ -485,7 +509,8 @@ public final class ProviderGetSession extends ProviderSession> mUiAuthenticationEntries = new HashMap<>(); - @Nullable private Pair> mUiRemoteEntry = null; + @Nullable + private Pair> mUiRemoteEntry = null; ProviderResponseDataHandler(@Nullable ComponentName expectedRemoteEntryProviderService) { mExpectedRemoteEntryProviderService = expectedRemoteEntryProviderService; @@ -509,6 +534,7 @@ public final class ProviderGetSession extends ProviderSession @NonNull protected Boolean mProviderResponseSet = false; // Specific candidate provider metric for the provider this session handles - @Nullable - protected CandidatePhaseMetric mCandidatePhasePerProviderMetric; + @NonNull + protected final CandidatePhaseMetric mCandidatePhasePerProviderMetric = + new CandidatePhaseMetric(); @NonNull private int mProviderSessionUid; @@ -143,7 +145,6 @@ public abstract class ProviderSession mUserId = userId; mComponentName = componentName; mRemoteCredentialService = remoteCredentialService; - mCandidatePhasePerProviderMetric = new CandidatePhaseMetric(); mProviderSessionUid = MetricUtilities.getPackageUid(mContext, mComponentName); } @@ -208,6 +209,12 @@ public abstract class ProviderSession return mRemoteCredentialService; } + protected void captureCandidateFailure() { + mCandidatePhasePerProviderMetric.setHasException(true); + // TODO(b/271135048) - this is a true exception, but what about the empty case? + // Add more nuance in next iteration. + } + /** Updates the status . */ protected void updateStatusAndInvokeCallback(@NonNull Status status) { setStatus(status); @@ -216,18 +223,37 @@ public abstract class ProviderSession } private void updateCandidateMetric(Status status) { - mCandidatePhasePerProviderMetric.setCandidateUid(mProviderSessionUid); - // TODO immediately update the candidate phase here to have more new data - mCandidatePhasePerProviderMetric - .setQueryFinishTimeNanoseconds(System.nanoTime()); - if (isTerminatingStatus(status)) { - mCandidatePhasePerProviderMetric.setProviderQueryStatus( - ProviderStatusForMetrics.QUERY_FAILURE - .getMetricCode()); - } else if (isCompletionStatus(status)) { - mCandidatePhasePerProviderMetric.setProviderQueryStatus( - ProviderStatusForMetrics.QUERY_SUCCESS - .getMetricCode()); + try { + mCandidatePhasePerProviderMetric.setCandidateUid(mProviderSessionUid); + // TODO immediately update the candidate phase here to have more new data + mCandidatePhasePerProviderMetric + .setQueryFinishTimeNanoseconds(System.nanoTime()); + if (isTerminatingStatus(status)) { + mCandidatePhasePerProviderMetric.setQueryReturned(false); + mCandidatePhasePerProviderMetric.setProviderQueryStatus( + ProviderStatusForMetrics.QUERY_FAILURE + .getMetricCode()); + } else if (isCompletionStatus(status)) { + mCandidatePhasePerProviderMetric.setQueryReturned(true); + mCandidatePhasePerProviderMetric.setProviderQueryStatus( + ProviderStatusForMetrics.QUERY_SUCCESS + .getMetricCode()); + } + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } + } + + // Common method to transfer metrics from the initial phase to the candidate phase per provider + protected void startCandidateMetrics() { + try { + InitialPhaseMetric initMetric = ((RequestSession) mCallbacks).mInitialPhaseMetric; + mCandidatePhasePerProviderMetric.setSessionId(initMetric.getSessionId()); + mCandidatePhasePerProviderMetric.setServiceBeganTimeNanoseconds( + initMetric.getCredentialServiceStartedTimeNanoseconds()); + mCandidatePhasePerProviderMetric.setStartQueryTimeNanoseconds(System.nanoTime()); + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); } } diff --git a/services/credentials/java/com/android/server/credentials/RequestSession.java b/services/credentials/java/com/android/server/credentials/RequestSession.java index ed42bb2f010a..3ac10c9a7d22 100644 --- a/services/credentials/java/com/android/server/credentials/RequestSession.java +++ b/services/credentials/java/com/android/server/credentials/RequestSession.java @@ -19,7 +19,6 @@ package com.android.server.credentials; import static com.android.server.credentials.MetricUtilities.logApiCalled; import android.annotation.NonNull; -import android.annotation.Nullable; import android.annotation.UserIdInt; import android.content.ComponentName; import android.content.Context; @@ -79,14 +78,14 @@ abstract class RequestSession implements CredentialManagerUi.CredentialMan protected final CancellationSignal mCancellationSignal; protected final Map mProviders = new HashMap<>(); - protected InitialPhaseMetric mInitialPhaseMetric = new InitialPhaseMetric(); - protected ChosenProviderFinalPhaseMetric + protected final InitialPhaseMetric mInitialPhaseMetric = new InitialPhaseMetric(); + protected final ChosenProviderFinalPhaseMetric mChosenProviderFinalPhaseMetric = new ChosenProviderFinalPhaseMetric(); // TODO(b/271135048) - Group metrics used in a scope together, such as here in RequestSession // TODO(b/271135048) - Replace this with a new atom per each browsing emit (V4) - @Nullable - protected List mCandidateBrowsingPhaseMetric; + @NonNull + protected List mCandidateBrowsingPhaseMetric = new ArrayList<>(); // As emits occur in sequential order, increment this counter and utilize protected int mSequenceCounter = 0; protected final String mHybridService; @@ -124,9 +123,17 @@ abstract class RequestSession implements CredentialManagerUi.CredentialMan mUserId, this); mHybridService = context.getResources().getString( R.string.config_defaultCredentialManagerHybridService); - mInitialPhaseMetric.setCredentialServiceStartedTimeNanoseconds(timestampStarted); - mInitialPhaseMetric.setSessionId(mRequestId.hashCode()); - mInitialPhaseMetric.setCallerUid(mCallingUid); + initialPhaseMetricSetup(timestampStarted); + } + + private void initialPhaseMetricSetup(long timestampStarted) { + try { + mInitialPhaseMetric.setCredentialServiceStartedTimeNanoseconds(timestampStarted); + mInitialPhaseMetric.setSessionId(mRequestId.hashCode()); + mInitialPhaseMetric.setCallerUid(mCallingUid); + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } } public abstract ProviderSession initiateProviderSession(CredentialProviderInfo providerInfo, @@ -171,13 +178,17 @@ abstract class RequestSession implements CredentialManagerUi.CredentialMan private void logBrowsingPhasePerSelect(UserSelectionDialogResult selection, ProviderSession providerSession) { - CandidateBrowsingPhaseMetric browsingPhaseMetric = new CandidateBrowsingPhaseMetric(); - browsingPhaseMetric.setSessionId(this.mInitialPhaseMetric.getSessionId()); - browsingPhaseMetric.setEntryEnum( - EntryEnum.getMetricCodeFromString(selection.getEntryKey())); - browsingPhaseMetric.setProviderUid(providerSession.mCandidatePhasePerProviderMetric - .getCandidateUid()); - this.mCandidateBrowsingPhaseMetric.add(new CandidateBrowsingPhaseMetric()); + try { + CandidateBrowsingPhaseMetric browsingPhaseMetric = new CandidateBrowsingPhaseMetric(); + browsingPhaseMetric.setSessionId(this.mInitialPhaseMetric.getSessionId()); + browsingPhaseMetric.setEntryEnum( + EntryEnum.getMetricCodeFromString(selection.getEntryKey())); + browsingPhaseMetric.setProviderUid(providerSession.mCandidatePhasePerProviderMetric + .getCandidateUid()); + this.mCandidateBrowsingPhaseMetric.add(new CandidateBrowsingPhaseMetric()); + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } } protected void finishSession(boolean propagateCancellation) { @@ -234,6 +245,7 @@ abstract class RequestSession implements CredentialManagerUi.CredentialMan Log.i(TAG, "In getProviderDataAndInitiateUi providers size: " + mProviders.size()); if (isSessionCancelled()) { + MetricUtilities.logApiCalled(mProviders, ++mSequenceCounter); finishSession(/*propagateCancellation=*/true); return; } @@ -249,13 +261,8 @@ abstract class RequestSession implements CredentialManagerUi.CredentialMan } if (!providerDataList.isEmpty()) { Log.i(TAG, "provider list not empty about to initiate ui"); - // TODO immediately Add paths to end it (say it fails) - if (isSessionCancelled()) { - Log.i(TAG, "In getProviderDataAndInitiateUi but session has been cancelled"); - // TODO immedaitely Add paths - } else { - launchUiWithProviderData(providerDataList); - } + MetricUtilities.logApiCalled(mProviders, ++mSequenceCounter); + launchUiWithProviderData(providerDataList); } } @@ -265,22 +272,27 @@ abstract class RequestSession implements CredentialManagerUi.CredentialMan * @param componentName the componentName to associate with a provider */ protected void setChosenMetric(ComponentName componentName) { - CandidatePhaseMetric metric = this.mProviders.get(componentName.flattenToString()) - .mCandidatePhasePerProviderMetric; + try { + CandidatePhaseMetric metric = this.mProviders.get(componentName.flattenToString()) + .mCandidatePhasePerProviderMetric; - mChosenProviderFinalPhaseMetric.setSessionId(metric.getSessionId()); - mChosenProviderFinalPhaseMetric.setChosenUid(metric.getCandidateUid()); + mChosenProviderFinalPhaseMetric.setSessionId(metric.getSessionId()); + mChosenProviderFinalPhaseMetric.setChosenUid(metric.getCandidateUid()); - mChosenProviderFinalPhaseMetric.setQueryPhaseLatencyMicroseconds( - metric.getQueryLatencyMicroseconds()); + mChosenProviderFinalPhaseMetric.setQueryPhaseLatencyMicroseconds( + metric.getQueryLatencyMicroseconds()); - mChosenProviderFinalPhaseMetric.setServiceBeganTimeNanoseconds( - metric.getServiceBeganTimeNanoseconds()); - mChosenProviderFinalPhaseMetric.setQueryStartTimeNanoseconds( - metric.getStartQueryTimeNanoseconds()); + mChosenProviderFinalPhaseMetric.setServiceBeganTimeNanoseconds( + metric.getServiceBeganTimeNanoseconds()); + mChosenProviderFinalPhaseMetric.setQueryStartTimeNanoseconds( + metric.getStartQueryTimeNanoseconds()); - // TODO immediately update with the entry count numbers from the candidate metrics + // TODO immediately update with the entry count numbers from the candidate metrics + // TODO immediately add the exception bit for candidates and providers - mChosenProviderFinalPhaseMetric.setFinalFinishTimeNanoseconds(System.nanoTime()); + mChosenProviderFinalPhaseMetric.setFinalFinishTimeNanoseconds(System.nanoTime()); + } catch (Exception e) { + Log.w(TAG, "Unexpected error during metric logging: " + e); + } } } diff --git a/services/credentials/java/com/android/server/credentials/metrics/CandidatePhaseMetric.java b/services/credentials/java/com/android/server/credentials/metrics/CandidatePhaseMetric.java index c392d7806910..f00c7f46c5ae 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/CandidatePhaseMetric.java +++ b/services/credentials/java/com/android/server/credentials/metrics/CandidatePhaseMetric.java @@ -20,6 +20,9 @@ import android.util.Log; import com.android.server.credentials.MetricUtilities; +import java.util.ArrayList; +import java.util.List; + /** * The central candidate provider metric object that mimics our defined metric setup. * Some types are redundant across these metric collectors, but that has debug use-cases as @@ -66,6 +69,8 @@ public class CandidatePhaseMetric { private int mRemoteEntryCount = -1; // The count of authentication entries from this provider, defaults to -1 private int mAuthenticationEntryCount = -1; + // Gathered to pass on to chosen provider when required + private List mAvailableEntries = new ArrayList<>(); public CandidatePhaseMetric() { } @@ -236,4 +241,28 @@ public class CandidatePhaseMetric { public int getAuthenticationEntryCount() { return mAuthenticationEntryCount; } + + /* -------------- The Entries Gathered ---------------- */ + + /** + * Allows adding an entry record to this metric collector, which can then be propagated to + * the final phase to retain information on the data available to the candidate. + * + * @param e the entry enum collected by the candidate provider associated with this metric + * collector + */ + public void addEntry(EntryEnum e) { + this.mAvailableEntries.add(e); + } + + /** + * Returns a safely copied list of the entries captured by this metric collector associated + * with a particular candidate provider. + * + * @return the full collection of entries encountered by the candidate provider associated with + * this metric + */ + public List getAvailableEntries() { + return new ArrayList<>(this.mAvailableEntries); // no alias copy + } } -- cgit v1.2.3-59-g8ed1b