From 7b1399ec6db0053c1496f966aeb7a6465e485b4e Mon Sep 17 00:00:00 2001 From: Arpan Kaphle Date: Thu, 11 May 2023 21:02:16 +0000 Subject: [PATCH] Metric System Cleanup This fixes any final issues in the metric collection and emission system, including logs. The fixes primarily focus on ensuring the timestamps are properly recorded, the aggregations are done properly for the total canddiate, and that all types and values are recorded or collected as they should be and emitted when they should be. Statuses and TODOs are also fixed here, alongside any final logs. Bug: 271135048 Bug: 270568738 Test: Build, won't submit without E2E Test (No Affect + Validate Metric Emits) Change-Id: I3637bf4a84596ba72bdab9ef225e4e5c77ab0bb6 --- .../credentials/ClearRequestSession.java | 1 + .../credentials/CreateRequestSession.java | 2 +- .../credentials/CredentialManagerUi.java | 5 --- .../server/credentials/GetRequestSession.java | 1 + .../server/credentials/MetricUtilities.java | 41 +++++++++---------- .../credentials/ProviderCreateSession.java | 8 ++-- .../credentials/ProviderGetSession.java | 8 ++-- .../server/credentials/ProviderSession.java | 6 ++- .../metrics/BrowsedAuthenticationMetric.java | 3 -- .../metrics/CandidateAggregateMetric.java | 19 +++++---- .../server/credentials/metrics/EntryEnum.java | 4 ++ .../metrics/ProviderSessionMetric.java | 24 +++++++---- .../metrics/RequestSessionMetric.java | 25 +++++++---- .../metrics/shared/ResponseCollective.java | 5 ++- 14 files changed, 88 insertions(+), 64 deletions(-) diff --git a/services/credentials/java/com/android/server/credentials/ClearRequestSession.java b/services/credentials/java/com/android/server/credentials/ClearRequestSession.java index fe8a8c8979f7c..69a5e5c3a9016 100644 --- a/services/credentials/java/com/android/server/credentials/ClearRequestSession.java +++ b/services/credentials/java/com/android/server/credentials/ClearRequestSession.java @@ -93,6 +93,7 @@ public final class ClearRequestSession extends RequestSession Integer.MAX_VALUE) { - throw new ArithmeticException("Input timestamps are too far apart and unsupported"); + Slog.i(TAG, "Input timestamps are too far apart and unsupported, " + + "falling back to default int"); + return DEFAULT_INT_32; } if (t2 < t1) { Slog.i(TAG, "The timestamps aren't in expected order, falling back to default int"); @@ -229,7 +230,7 @@ public class MetricUtilities { authenticationMetric.isAuthReturned() ); } catch (Exception e) { - Slog.w(TAG, "Unexpected error during candidate get metric logging: " + e); + Slog.w(TAG, "Unexpected error during candidate auth metric logging: " + e); } } @@ -252,22 +253,18 @@ public class MetricUtilities { } var sessions = providers.values(); for (var session : sessions) { - try { - var metric = session.getProviderSessionMetric() - .getCandidatePhasePerProviderMetric(); - FrameworkStatsLog.write( - FrameworkStatsLog.CREDENTIAL_MANAGER_GET_REPORTED, - /* session_id */ metric.getSessionIdProvider(), - /* sequence_num */ emitSequenceId, - /* candidate_provider_uid */ metric.getCandidateUid(), - /* response_unique_classtypes */ - metric.getResponseCollective().getUniqueResponseStrings(), - /* per_classtype_counts */ - metric.getResponseCollective().getUniqueResponseCounts() - ); - } catch (Exception e) { - Slog.w(TAG, "Unexpected exception during get metric logging" + e); - } + var metric = session.getProviderSessionMetric() + .getCandidatePhasePerProviderMetric(); + FrameworkStatsLog.write( + FrameworkStatsLog.CREDENTIAL_MANAGER_GET_REPORTED, + /* session_id */ metric.getSessionIdProvider(), + /* sequence_num */ emitSequenceId, + /* candidate_provider_uid */ metric.getCandidateUid(), + /* response_unique_classtypes */ + metric.getResponseCollective().getUniqueResponseStrings(), + /* per_classtype_counts */ + metric.getResponseCollective().getUniqueResponseCounts() + ); } } catch (Exception e) { Slog.w(TAG, "Unexpected error during candidate get metric logging: " + e); @@ -399,7 +396,7 @@ public class MetricUtilities { /* caller_uid */ callingUid, /* api_status */ apiStatus.getMetricCode()); } catch (Exception e) { - Slog.w(TAG, "Unexpected error during metric logging: " + e); + Slog.w(TAG, "Unexpected error during simple v2 metric logging: " + e); } } @@ -505,7 +502,7 @@ public class MetricUtilities { candidateAggregateMetric.isAuthReturned() ); } catch (Exception e) { - Slog.w(TAG, "Unexpected error during metric logging: " + e); + Slog.w(TAG, "Unexpected error during total candidate metric logging: " + e); } } @@ -570,7 +567,7 @@ public class MetricUtilities { /* primary_indicated */ finalPhaseMetric.isPrimary() ); } catch (Exception e) { - Slog.w(TAG, "Unexpected error during metric logging: " + e); + Slog.w(TAG, "Unexpected error during final no uid metric logging: " + e); } } diff --git a/services/credentials/java/com/android/server/credentials/ProviderCreateSession.java b/services/credentials/java/com/android/server/credentials/ProviderCreateSession.java index 25f20caee16db..6f79852df02f4 100644 --- a/services/credentials/java/com/android/server/credentials/ProviderCreateSession.java +++ b/services/credentials/java/com/android/server/credentials/ProviderCreateSession.java @@ -54,7 +54,7 @@ public final class ProviderCreateSession extends ProviderSession< private static final String TAG = "ProviderCreateSession"; // Key to be used as an entry key for a save entry - private static final String SAVE_ENTRY_KEY = "save_entry_key"; + public static final String SAVE_ENTRY_KEY = "save_entry_key"; // Key to be used as an entry key for a remote entry private static final String REMOTE_ENTRY_KEY = "remote_entry_key"; @@ -193,11 +193,13 @@ public final class ProviderCreateSession extends ProviderSession< mProviderResponseDataHandler.addResponseContent(response.getCreateEntries(), response.getRemoteCreateEntry()); if (mProviderResponseDataHandler.isEmptyResponse(response)) { - mProviderSessionMetric.collectCandidateEntryMetrics(response, /*isAuthEntry*/false); + mProviderSessionMetric.collectCandidateEntryMetrics(response, /*isAuthEntry*/false, + ((RequestSession) mCallbacks).mRequestSessionMetric.getInitialPhaseMetric()); updateStatusAndInvokeCallback(Status.EMPTY_RESPONSE, /*source=*/ CredentialsSource.REMOTE_PROVIDER); } else { - mProviderSessionMetric.collectCandidateEntryMetrics(response, /*isAuthEntry*/false); + mProviderSessionMetric.collectCandidateEntryMetrics(response, /*isAuthEntry*/false, + ((RequestSession) mCallbacks).mRequestSessionMetric.getInitialPhaseMetric()); updateStatusAndInvokeCallback(Status.SAVE_ENTRIES_RECEIVED, /*source=*/ CredentialsSource.REMOTE_PROVIDER); } diff --git a/services/credentials/java/com/android/server/credentials/ProviderGetSession.java b/services/credentials/java/com/android/server/credentials/ProviderGetSession.java index 14260f0e1ad43..9b0a1cb0c57c5 100644 --- a/services/credentials/java/com/android/server/credentials/ProviderGetSession.java +++ b/services/credentials/java/com/android/server/credentials/ProviderGetSession.java @@ -435,7 +435,7 @@ public final class ProviderGetSession extends ProviderSession CredentialsSource source) { setStatus(status); boolean isPrimary = mProviderInfo != null && mProviderInfo.isPrimary(); - mProviderSessionMetric.collectCandidateMetricUpdate(isTerminatingStatus(status), - isCompletionStatus(status), mProviderSessionUid, + mProviderSessionMetric.collectCandidateMetricUpdate(isTerminatingStatus(status) + || isStatusWaitingForRemoteResponse(status), + isCompletionStatus(status) || isUiInvokingStatus(status), + mProviderSessionUid, /*isAuthEntry*/source == CredentialsSource.AUTH_ENTRY, /*isPrimary*/isPrimary); mCallbacks.onProviderStatusChanged(status, mComponentName, source); diff --git a/services/credentials/java/com/android/server/credentials/metrics/BrowsedAuthenticationMetric.java b/services/credentials/java/com/android/server/credentials/metrics/BrowsedAuthenticationMetric.java index 62b8f24eb2013..1ac8a71e745e9 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/BrowsedAuthenticationMetric.java +++ b/services/credentials/java/com/android/server/credentials/metrics/BrowsedAuthenticationMetric.java @@ -43,9 +43,6 @@ public class BrowsedAuthenticationMetric { // Indicates if this provider returned from the authentication entry query, default false private boolean mAuthReturned = false; - // TODO(b/271135048) - Match the atom and provide a clean per provider session metric - // encapsulation. - public BrowsedAuthenticationMetric(int sessionIdProvider) { mSessionIdProvider = sessionIdProvider; } diff --git a/services/credentials/java/com/android/server/credentials/metrics/CandidateAggregateMetric.java b/services/credentials/java/com/android/server/credentials/metrics/CandidateAggregateMetric.java index 339c221b0cccb..91547788a23be 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/CandidateAggregateMetric.java +++ b/services/credentials/java/com/android/server/credentials/metrics/CandidateAggregateMetric.java @@ -16,6 +16,7 @@ package com.android.server.credentials.metrics; +import com.android.server.credentials.MetricUtilities; import com.android.server.credentials.ProviderSession; import com.android.server.credentials.metrics.shared.ResponseCollective; @@ -29,7 +30,7 @@ import java.util.Map; */ public class CandidateAggregateMetric { - private static final String TAG = "CandidateProviderMetric"; + private static final String TAG = "CandidateTotalMetric"; // The session id of this provider metric private final int mSessionIdProvider; // Indicates if this provider returned from the candidate query phase, @@ -74,8 +75,6 @@ public class CandidateAggregateMetric { /** * This will take all the candidate data captured and aggregate that information. - * TODO(b/271135048) : Add on authentication entry outputs from track 2 here as well once - * generated * @param providers the providers associated with the candidate flow */ public void collectAverages(Map providers) { @@ -88,11 +87,15 @@ public class CandidateAggregateMetric { Map responseCountQuery = new LinkedHashMap<>(); Map entryCountQuery = new LinkedHashMap<>(); var providerSessions = providers.values(); - long min_query_start = Integer.MAX_VALUE; - long max_query_end = Integer.MIN_VALUE; + long min_query_start = Long.MAX_VALUE; + long max_query_end = Long.MIN_VALUE; for (var session : providerSessions) { var sessionMetric = session.getProviderSessionMetric(); var candidateMetric = sessionMetric.getCandidatePhasePerProviderMetric(); + if (candidateMetric.getCandidateUid() == MetricUtilities.DEFAULT_INT_32) { + mNumProviders--; + continue; // Do not aggregate this one and reduce the size of actual candidates + } if (mServiceBeganTimeNanoseconds == -1) { mServiceBeganTimeNanoseconds = candidateMetric.getServiceBeganTimeNanoseconds(); } @@ -119,15 +122,17 @@ public class CandidateAggregateMetric { } private void collectAuthAggregates(Map providers) { - mNumProviders = providers.size(); Map responseCountAuth = new LinkedHashMap<>(); Map entryCountAuth = new LinkedHashMap<>(); var providerSessions = providers.values(); for (var session : providerSessions) { var sessionMetric = session.getProviderSessionMetric(); var authMetrics = sessionMetric.getBrowsedAuthenticationMetric(); - mNumAuthEntriesTapped += authMetrics.size(); for (var authMetric : authMetrics) { + if (authMetric.getProviderUid() == MetricUtilities.DEFAULT_INT_32) { + continue; // skip this unfilled base auth entry + } + mNumAuthEntriesTapped++; mAuthReturned = mAuthReturned || authMetric.isAuthReturned(); ResponseCollective authCollective = authMetric.getAuthEntryCollective(); ResponseCollective.combineTypeCountMaps(responseCountAuth, diff --git a/services/credentials/java/com/android/server/credentials/metrics/EntryEnum.java b/services/credentials/java/com/android/server/credentials/metrics/EntryEnum.java index 530f01cbdfc56..226cd2c11b158 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/EntryEnum.java +++ b/services/credentials/java/com/android/server/credentials/metrics/EntryEnum.java @@ -28,6 +28,8 @@ import static com.android.server.credentials.ProviderGetSession.REMOTE_ENTRY_KEY import android.util.Slog; +import com.android.server.credentials.ProviderCreateSession; + import java.util.AbstractMap; import java.util.Map; @@ -52,6 +54,8 @@ public enum EntryEnum { new AbstractMap.SimpleEntry<>(REMOTE_ENTRY_KEY, REMOTE_ENTRY.mInnerMetricCode), new AbstractMap.SimpleEntry<>(CREDENTIAL_ENTRY_KEY, + CREDENTIAL_ENTRY.mInnerMetricCode), + new AbstractMap.SimpleEntry<>(ProviderCreateSession.SAVE_ENTRY_KEY, CREDENTIAL_ENTRY.mInnerMetricCode) ); diff --git a/services/credentials/java/com/android/server/credentials/metrics/ProviderSessionMetric.java b/services/credentials/java/com/android/server/credentials/metrics/ProviderSessionMetric.java index 44d845eaaf43e..c1f6b4779ed47 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/ProviderSessionMetric.java +++ b/services/credentials/java/com/android/server/credentials/metrics/ProviderSessionMetric.java @@ -20,6 +20,7 @@ import static com.android.server.credentials.MetricUtilities.DELTA_RESPONSES_CUT import static com.android.server.credentials.MetricUtilities.generateMetricKey; import android.annotation.NonNull; +import android.annotation.Nullable; import android.service.credentials.BeginCreateCredentialResponse; import android.service.credentials.BeginGetCredentialResponse; import android.service.credentials.CredentialEntry; @@ -205,18 +206,22 @@ public class ProviderSessionMetric { * * @param response contains entries and data from the candidate provider responses * @param isAuthEntry indicates if this is an auth entry collection or not + * @param initialPhaseMetric for create flows, this helps identify the response type, which + * will identify the *type* of create flow, especially important in + * track 2. This is expected to be null in get flows. * @param the response type associated with the API flow in progress */ - public void collectCandidateEntryMetrics(R response, boolean isAuthEntry) { + public void collectCandidateEntryMetrics(R response, boolean isAuthEntry, + @Nullable InitialPhaseMetric initialPhaseMetric) { try { if (response instanceof BeginGetCredentialResponse) { beginGetCredentialResponseCollectionCandidateEntryMetrics( (BeginGetCredentialResponse) response, isAuthEntry); } else if (response instanceof BeginCreateCredentialResponse) { beginCreateCredentialResponseCollectionCandidateEntryMetrics( - (BeginCreateCredentialResponse) response); + (BeginCreateCredentialResponse) response, initialPhaseMetric); } else { - Slog.i(TAG, "Your response type is unsupported for metric logging"); + Slog.i(TAG, "Your response type is unsupported for candidate metric logging"); } } catch (Exception e) { Slog.i(TAG, "Unexpected error during candidate entry metric logging: " + e); @@ -245,7 +250,6 @@ public class ProviderSessionMetric { String entryKey = generateMetricKey(entry.getType(), DELTA_RESPONSES_CUT); responseCounts.put(entryKey, responseCounts.getOrDefault(entryKey, 0) + 1); }); - ResponseCollective responseCollective = new ResponseCollective(responseCounts, entryCounts); mCandidatePhasePerProviderMetric.setResponseCollective(responseCollective); } @@ -262,19 +266,21 @@ public class ProviderSessionMetric { } private void beginCreateCredentialResponseCollectionCandidateEntryMetrics( - BeginCreateCredentialResponse response) { + BeginCreateCredentialResponse response, InitialPhaseMetric initialPhaseMetric) { Map entryCounts = new LinkedHashMap<>(); var createEntries = response.getCreateEntries(); - int numRemoteEntry = response.getRemoteCreateEntry() != null ? MetricUtilities.ZERO : + int numRemoteEntry = response.getRemoteCreateEntry() == null ? MetricUtilities.ZERO : MetricUtilities.UNIT; int numCreateEntries = createEntries.size(); entryCounts.put(EntryEnum.REMOTE_ENTRY, numRemoteEntry); entryCounts.put(EntryEnum.CREDENTIAL_ENTRY, numCreateEntries); Map responseCounts = new LinkedHashMap<>(); - responseCounts.put(MetricUtilities.DEFAULT_STRING, numCreateEntries); - // We don't store create response because it's directly related to the request - // We do still store the count, however + String[] requestStrings = initialPhaseMetric == null ? new String[0] : + initialPhaseMetric.getUniqueRequestStrings(); + if (requestStrings.length > 0) { + responseCounts.put(requestStrings[0], initialPhaseMetric.getUniqueRequestCounts()[0]); + } ResponseCollective responseCollective = new ResponseCollective(responseCounts, entryCounts); mCandidatePhasePerProviderMetric.setResponseCollective(responseCollective); diff --git a/services/credentials/java/com/android/server/credentials/metrics/RequestSessionMetric.java b/services/credentials/java/com/android/server/credentials/metrics/RequestSessionMetric.java index 281f3cc705be3..83b57c4f78c26 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/RequestSessionMetric.java +++ b/services/credentials/java/com/android/server/credentials/metrics/RequestSessionMetric.java @@ -26,13 +26,17 @@ import static com.android.server.credentials.MetricUtilities.logApiCalledCandida import static com.android.server.credentials.MetricUtilities.logApiCalledCandidatePhase; import static com.android.server.credentials.MetricUtilities.logApiCalledFinalPhase; import static com.android.server.credentials.MetricUtilities.logApiCalledNoUidFinal; +import static com.android.server.credentials.metrics.ApiName.GET_CREDENTIAL; +import static com.android.server.credentials.metrics.ApiName.GET_CREDENTIAL_VIA_REGISTRY; import android.annotation.NonNull; import android.content.ComponentName; +import android.credentials.CreateCredentialRequest; import android.credentials.GetCredentialRequest; import android.credentials.ui.UserSelectionDialogResult; import android.util.Slog; +import com.android.server.credentials.MetricUtilities; import com.android.server.credentials.ProviderSession; import java.util.ArrayList; @@ -112,7 +116,7 @@ public class RequestSessionMetric { mInitialPhaseMetric.setCallerUid(mCallingUid); mInitialPhaseMetric.setApiName(metricCode); } catch (Exception e) { - Slog.i(TAG, "Unexpected error collecting initial metrics: " + e); + Slog.i(TAG, "Unexpected error collecting initial phase metric start info: " + e); } } @@ -177,9 +181,12 @@ public class RequestSessionMetric { * * @param origin indicates if an origin was passed in or not */ - public void collectCreateFlowInitialMetricInfo(boolean origin) { + public void collectCreateFlowInitialMetricInfo(boolean origin, + CreateCredentialRequest request) { try { mInitialPhaseMetric.setOriginSpecified(origin); + mInitialPhaseMetric.setRequestCounts(Map.of(generateMetricKey(request.getType(), + DELTA_RESPONSES_CUT), MetricUtilities.UNIT)); } catch (Exception e) { Slog.i(TAG, "Unexpected error collecting create flow metric: " + e); } @@ -195,7 +202,7 @@ public class RequestSessionMetric { 0) + 1); }); } catch (Exception e) { - Slog.i(TAG, "Unexpected error during get request metric logging: " + e); + Slog.i(TAG, "Unexpected error during get request count map metric logging: " + e); } return uniqueRequestCounts; } @@ -210,7 +217,7 @@ public class RequestSessionMetric { mInitialPhaseMetric.setOriginSpecified(request.getOrigin() != null); mInitialPhaseMetric.setRequestCounts(getRequestCountMap(request)); } catch (Exception e) { - Slog.i(TAG, "Unexpected error collecting get flow metric: " + e); + Slog.i(TAG, "Unexpected error collecting get flow initial metric: " + e); } } @@ -277,7 +284,7 @@ public class RequestSessionMetric { mChosenProviderFinalPhaseMetric.setChosenProviderStatus( finalStatus.getMetricCode()); } catch (Exception e) { - Slog.i(TAG, "Unexpected error during metric logging: " + e); + Slog.i(TAG, "Unexpected error during final phase provider status metric logging: " + e); } } @@ -367,7 +374,11 @@ public class RequestSessionMetric { public void logCandidatePhaseMetrics(Map providers) { try { logApiCalledCandidatePhase(providers, ++mSequenceCounter, mInitialPhaseMetric); - logApiCalledCandidateGetMetric(providers, mSequenceCounter); + if (mInitialPhaseMetric.getApiName() == GET_CREDENTIAL.getMetricCode() + || mInitialPhaseMetric.getApiName() == GET_CREDENTIAL_VIA_REGISTRY + .getMetricCode()) { + logApiCalledCandidateGetMetric(providers, mSequenceCounter); + } } catch (Exception e) { Slog.i(TAG, "Unexpected error during candidate metric emit: " + e); } @@ -405,7 +416,7 @@ public class RequestSessionMetric { } logApiCalledAuthenticationMetric(browsedAuthenticationMetric, ++mSequenceCounter); } catch (Exception e) { - Slog.i(TAG, "Unexpected error during metric logging: " + e); + Slog.i(TAG, "Unexpected error during auth entry metric emit: " + e); } } diff --git a/services/credentials/java/com/android/server/credentials/metrics/shared/ResponseCollective.java b/services/credentials/java/com/android/server/credentials/metrics/shared/ResponseCollective.java index 0958a841fe7ee..ceb957100aec0 100644 --- a/services/credentials/java/com/android/server/credentials/metrics/shared/ResponseCollective.java +++ b/services/credentials/java/com/android/server/credentials/metrics/shared/ResponseCollective.java @@ -18,6 +18,7 @@ package com.android.server.credentials.metrics.shared; import android.annotation.NonNull; +import com.android.server.credentials.MetricUtilities; import com.android.server.credentials.metrics.EntryEnum; import java.util.Collections; @@ -121,7 +122,7 @@ public class ResponseCollective { * @return a count of this particular entry enum stored by this provider */ public int getCountForEntry(EntryEnum e) { - return mEntryCounts.get(e); + return mEntryCounts.getOrDefault(e, MetricUtilities.ZERO); } /** @@ -167,7 +168,7 @@ public class ResponseCollective { public static Map combineTypeCountMaps(Map first, Map second) { for (T response : second.keySet()) { - first.merge(response, first.getOrDefault(response, 0), Integer::sum); + first.put(response, first.getOrDefault(response, 0) + second.get(response)); } return first; }