Merge "Further V2 Modifications, Prep for V3" into udc-dev

services/credentials/java/com/android/server/credentials/MetricUtilities.java

@@ -43,8 +43,8 @@ public class MetricUtilities {
 
     private static final String TAG = "MetricUtilities";
 
-    private static final int DEFAULT_INT_32 = -1;
+    public static final int DEFAULT_INT_32 = -1;
-    private static final int[] DEFAULT_REPEATED_INT_32 = new int[0];
+    public static final int[] DEFAULT_REPEATED_INT_32 = new int[0];
 
     // Metrics constants TODO(b/269290341) migrate to enums eventually to improve
     protected static final int METRICS_PROVIDER_STATUS_FINAL_FAILURE =
@@ -79,6 +79,21 @@ public class MetricUtilities {
         return sessUid;
     }
 
+    /**
+     * Given any two timestamps in nanoseconds, this gets the difference and converts to
+     * milliseconds. Assumes the difference is not larger than the maximum int size.
+     *
+     * @param t2 the final timestamp
+     * @param t1 the initial timestamp
+     * @return the timestamp difference converted to microseconds
+     */
+    protected static int getMetricTimestampDifferenceMicroseconds(long t2, long t1) {
+        if (t2 - t1 > Integer.MAX_VALUE) {
+            throw new ArithmeticException("Input timestamps are too far apart and unsupported");
+        }
+        return (int) ((t2 - t1) / 1000);
+    }
+
     /**
      * 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
@@ -102,7 +117,7 @@ public class MetricUtilities {
         for (var session : providerSessions) {
             CandidateProviderMetric metric = session.mCandidateProviderMetric;
             candidateUidList[index] = metric.getCandidateUid();
-            candidateQueryRoundTripTimeList[index] = metric.getQueryLatencyMs();
+            candidateQueryRoundTripTimeList[index] = metric.getQueryLatencyMicroseconds();
             candidateStatusList[index] = metric.getProviderQueryStatus();
             index++;
         }
@@ -116,9 +131,11 @@ public class MetricUtilities {
                 /* repeated_candidate_provider_status */ candidateStatusList,
                 /* chosen_provider_uid */ chosenProviderMetric.getChosenUid(),
                 /* chosen_provider_round_trip_time_overall_microseconds */
-                chosenProviderMetric.getEntireProviderLatencyMs(),
+                chosenProviderMetric.getEntireProviderLatencyMicroseconds(),
-                /* chosen_provider_final_phase_microseconds */
+                /* chosen_provider_final_phase_microseconds (backwards compat only) */
-                chosenProviderMetric.getFinalPhaseLatencyMs(),
+                getMetricTimestampDifferenceMicroseconds(chosenProviderMetric
+                                .getFinalFinishTimeNanoseconds(),
+                        chosenProviderMetric.getUiCallEndTimeNanoseconds()),
                 /* chosen_provider_status */ chosenProviderMetric.getChosenProviderStatus());
     }
 

services/credentials/java/com/android/server/credentials/ProviderClearSession.java

@@ -119,8 +119,8 @@ public final class  ProviderClearSession extends ProviderSession<ClearCredential
     @Override
     protected void invokeSession() {
         if (mRemoteCredentialService != null) {
+            mCandidateProviderMetric.setStartQueryTimeNanoseconds(System.nanoTime());
             mRemoteCredentialService.onClearCredentialState(mProviderRequest, this);
-            mCandidateProviderMetric.setStartTimeNanoseconds(System.nanoTime());
         }
     }
 }

services/credentials/java/com/android/server/credentials/ProviderCreateSession.java

@@ -226,8 +226,8 @@ public final class ProviderCreateSession extends ProviderSession<
     @Override
     protected void invokeSession() {
         if (mRemoteCredentialService != null) {
+            mCandidateProviderMetric.setStartQueryTimeNanoseconds(System.nanoTime());
             mRemoteCredentialService.onCreateCredential(mProviderRequest, this);
-            mCandidateProviderMetric.setStartTimeNanoseconds(System.nanoTime());
         }
     }
 

services/credentials/java/com/android/server/credentials/ProviderGetSession.java

@@ -268,8 +268,8 @@ public final class ProviderGetSession extends ProviderSession<BeginGetCredential
     @Override
     protected void invokeSession() {
         if (mRemoteCredentialService != null) {
+            mCandidateProviderMetric.setStartQueryTimeNanoseconds(System.nanoTime());
             mRemoteCredentialService.onBeginGetCredential(mProviderRequest, this);
-            mCandidateProviderMetric.setStartTimeNanoseconds(System.nanoTime());
         }
     }
 

services/credentials/java/com/android/server/credentials/RequestSession.java

@@ -78,7 +78,8 @@ abstract class RequestSession<T, U> implements CredentialManagerUi.CredentialMan
     //TODO improve design to allow grouped metrics per request
     protected final String mHybridService;
 
-    @NonNull protected RequestSessionStatus mRequestSessionStatus =
+    @NonNull
+    protected RequestSessionStatus mRequestSessionStatus =
             RequestSessionStatus.IN_PROGRESS;
 
     /** The status in which a given request session is. */
@@ -213,6 +214,7 @@ abstract class RequestSession<T, U> implements CredentialManagerUi.CredentialMan
 
     /**
      * Called by RequestSession's upon chosen metric determination.
+     *
      * @param componentName the componentName to associate with a provider
      */
     protected void setChosenMetric(ComponentName componentName) {
@@ -220,8 +222,8 @@ abstract class RequestSession<T, U> implements CredentialManagerUi.CredentialMan
                 .mCandidateProviderMetric;
         mChosenProviderMetric.setChosenUid(metric.getCandidateUid());
         mChosenProviderMetric.setFinalFinishTimeNanoseconds(System.nanoTime());
-        mChosenProviderMetric.setQueryFinishTimeNanoseconds(
+        mChosenProviderMetric.setQueryPhaseLatencyMicroseconds(
-                metric.getQueryFinishTimeNanoseconds());
+                metric.getQueryLatencyMicroseconds());
-        mChosenProviderMetric.setStartTimeNanoseconds(metric.getStartTimeNanoseconds());
+        mChosenProviderMetric.setQueryStartTimeNanoseconds(metric.getStartQueryTimeNanoseconds());
     }
 }

services/credentials/java/com/android/server/credentials/metrics/CandidateProviderMetric.java

@@ -18,63 +18,69 @@ package com.android.server.credentials.metrics;
 
 /**
  * The central candidate provider metric object that mimics our defined metric setup.
+ * TODO(b/270403549) - iterate on this in V3+
  */
 public class CandidateProviderMetric {
 
+    private static final String TAG = "CandidateProviderMetric";
     private int mCandidateUid = -1;
-    private long mStartTimeNanoseconds = -1;
+
+    // Raw timestamp in nanoseconds, will be converted to microseconds for logging
+
+    private long mStartQueryTimeNanoseconds = -1;
     private long mQueryFinishTimeNanoseconds = -1;
 
     private int mProviderQueryStatus = -1;
 
-    public CandidateProviderMetric(long startTime, long queryFinishTime, int providerQueryStatus,
+    public CandidateProviderMetric() {
-            int candidateUid) {
-        this.mStartTimeNanoseconds = startTime;
-        this.mQueryFinishTimeNanoseconds = queryFinishTime;
-        this.mProviderQueryStatus = providerQueryStatus;
-        this.mCandidateUid = candidateUid;
     }
 
-    public CandidateProviderMetric(){}
+    /* ---------- Latencies ---------- */
 
-    public void setStartTimeNanoseconds(long startTimeNanoseconds) {
+    public void setStartQueryTimeNanoseconds(long startQueryTimeNanoseconds) {
-        this.mStartTimeNanoseconds = startTimeNanoseconds;
+        this.mStartQueryTimeNanoseconds = startQueryTimeNanoseconds;
     }
 
     public void setQueryFinishTimeNanoseconds(long queryFinishTimeNanoseconds) {
         this.mQueryFinishTimeNanoseconds = queryFinishTimeNanoseconds;
     }
 
-    public void setProviderQueryStatus(int providerQueryStatus) {
+    public long getStartQueryTimeNanoseconds() {
-        this.mProviderQueryStatus = providerQueryStatus;
+        return this.mStartQueryTimeNanoseconds;
-    }
-
-    public void setCandidateUid(int candidateUid) {
-        this.mCandidateUid = candidateUid;
-    }
-
-    public long getStartTimeNanoseconds() {
-        return this.mStartTimeNanoseconds;
     }
 
     public long getQueryFinishTimeNanoseconds() {
         return this.mQueryFinishTimeNanoseconds;
     }
 
+    /**
+     * Returns the latency in microseconds for the query phase.
+     */
+    public int getQueryLatencyMicroseconds() {
+        return (int) ((this.getQueryFinishTimeNanoseconds()
+                - this.getStartQueryTimeNanoseconds()) / 1000);
+    }
+
+    // TODO (in direct next dependent CL, so this is transient) - add reference timestamp in micro
+    // seconds for this too.
+
+    /* ------------- Provider Query Status ------------ */
+
+    public void setProviderQueryStatus(int providerQueryStatus) {
+        this.mProviderQueryStatus = providerQueryStatus;
+    }
+
     public int getProviderQueryStatus() {
         return this.mProviderQueryStatus;
     }
 
+    /* -------------- Candidate Uid ---------------- */
+
+    public void setCandidateUid(int candidateUid) {
+        this.mCandidateUid = candidateUid;
+    }
+
     public int getCandidateUid() {
         return this.mCandidateUid;
     }
-
-    /**
-     * Returns the latency in microseconds for the query phase.
-     */
-    public int getQueryLatencyMs() {
-        return (int) ((this.getQueryFinishTimeNanoseconds()
-                - this.getStartTimeNanoseconds()) / 1000);
-    }
-
 }

services/credentials/java/com/android/server/credentials/metrics/ChosenProviderMetric.java

@@ -16,18 +16,39 @@
 
 package com.android.server.credentials.metrics;
 
+import android.util.Log;
+
+import com.android.server.credentials.MetricUtilities;
+
 /**
  * The central chosen provider metric object that mimics our defined metric setup.
+ * TODO(b/270403549) - iterate on this in V3+
  */
 public class ChosenProviderMetric {
 
+    // TODO(b/270403549) - applies elsewhere, likely removed or replaced with a count-index (1,2,3)
+    private static final String TAG = "ChosenProviderMetric";
     private int mChosenUid = -1;
-    private long mStartTimeNanoseconds = -1;
+
-    private long mQueryFinishTimeNanoseconds = -1;
+    // Latency figures typically fed in from prior CandidateProviderMetric
+
+    private int mPreQueryPhaseLatencyMicroseconds = -1;
+    private int mQueryPhaseLatencyMicroseconds = -1;
+
+    // Timestamps kept in raw nanoseconds. Expected to be converted to microseconds from using
+    // reference 'mServiceBeganTimeNanoseconds' during metric log point.
+
+    private long mServiceBeganTimeNanoseconds = -1;
+    private long mQueryStartTimeNanoseconds = -1;
+    private long mUiCallStartTimeNanoseconds = -1;
+    private long mUiCallEndTimeNanoseconds = -1;
     private long mFinalFinishTimeNanoseconds = -1;
     private int mChosenProviderStatus = -1;
 
-    public ChosenProviderMetric() {}
+    public ChosenProviderMetric() {
+    }
+
+    /* ------------------- UID ------------------- */
 
     public int getChosenUid() {
         return mChosenUid;
@@ -37,29 +58,139 @@ public class ChosenProviderMetric {
         mChosenUid = chosenUid;
     }
 
-    public long getStartTimeNanoseconds() {
+    /* ---------------- Latencies ------------------ */
-        return mStartTimeNanoseconds;
+
+
+    /* ----- Direct Latencies ------- */
+
+    /**
+     * In order for a chosen provider to be selected, the call must have successfully begun.
+     * Thus, the {@link PreCandidateMetric} can directly pass this initial latency figure into
+     * this chosen provider metric.
+     *
+     * @param preQueryPhaseLatencyMicroseconds the millisecond latency for the service start,
+     *                                         typically passed in through the
+     *                                         {@link PreCandidateMetric}
+     */
+    public void setPreQueryPhaseLatencyMicroseconds(int preQueryPhaseLatencyMicroseconds) {
+        mPreQueryPhaseLatencyMicroseconds = preQueryPhaseLatencyMicroseconds;
     }
 
-    public void setStartTimeNanoseconds(long startTimeNanoseconds) {
+    /**
-        mStartTimeNanoseconds = startTimeNanoseconds;
+     * In order for a chosen provider to be selected, a candidate provider must exist. The
+     * candidate provider can directly pass the final latency figure into this chosen provider
+     * metric.
+     *
+     * @param queryPhaseLatencyMicroseconds the millisecond latency for the query phase, typically
+     *                                      passed in through the {@link CandidateProviderMetric}
+     */
+    public void setQueryPhaseLatencyMicroseconds(int queryPhaseLatencyMicroseconds) {
+        mQueryPhaseLatencyMicroseconds = queryPhaseLatencyMicroseconds;
     }
 
-    public long getQueryFinishTimeNanoseconds() {
+    public int getPreQueryPhaseLatencyMicroseconds() {
-        return mQueryFinishTimeNanoseconds;
+        return mPreQueryPhaseLatencyMicroseconds;
     }
 
-    public void setQueryFinishTimeNanoseconds(long queryFinishTimeNanoseconds) {
+    public int getQueryPhaseLatencyMicroseconds() {
-        mQueryFinishTimeNanoseconds = queryFinishTimeNanoseconds;
+        return mQueryPhaseLatencyMicroseconds;
+    }
+
+    public int getUiPhaseLatencyMicroseconds() {
+        return (int) ((this.mUiCallEndTimeNanoseconds
+                - this.mUiCallStartTimeNanoseconds) / 1000);
+    }
+
+    /**
+     * Returns the full provider (invocation to response) latency in microseconds. Expects the
+     * start time to be provided, such as from {@link CandidateProviderMetric}.
+     */
+    public int getEntireProviderLatencyMicroseconds() {
+        return (int) ((this.mFinalFinishTimeNanoseconds
+                - this.mQueryStartTimeNanoseconds) / 1000);
+    }
+
+    /**
+     * Returns the full (platform invoked to response) latency in microseconds. Expects the
+     * start time to be provided, such as from {@link PreCandidateMetric}.
+     */
+    public int getEntireLatencyMicroseconds() {
+        return (int) ((this.mFinalFinishTimeNanoseconds
+                - this.mServiceBeganTimeNanoseconds) / 1000);
+    }
+
+    /* ----- Timestamps for Latency ----- */
+
+    /**
+     * In order for a chosen provider to be selected, the call must have successfully begun.
+     * Thus, the {@link PreCandidateMetric} can directly pass this initial timestamp into this
+     * chosen provider metric.
+     *
+     * @param serviceBeganTimeNanoseconds the timestamp moment when the platform was called,
+     *                                    typically passed in through the {@link PreCandidateMetric}
+     */
+    public void setServiceBeganTimeNanoseconds(long serviceBeganTimeNanoseconds) {
+        mServiceBeganTimeNanoseconds = serviceBeganTimeNanoseconds;
+    }
+
+    public void setQueryStartTimeNanoseconds(long queryStartTimeNanoseconds) {
+        mQueryStartTimeNanoseconds = queryStartTimeNanoseconds;
+    }
+
+    public void setUiCallStartTimeNanoseconds(long uiCallStartTimeNanoseconds) {
+        this.mUiCallStartTimeNanoseconds = uiCallStartTimeNanoseconds;
+    }
+
+    public void setUiCallEndTimeNanoseconds(long uiCallEndTimeNanoseconds) {
+        this.mUiCallEndTimeNanoseconds = uiCallEndTimeNanoseconds;
+    }
+
+    public void setFinalFinishTimeNanoseconds(long finalFinishTimeNanoseconds) {
+        mFinalFinishTimeNanoseconds = finalFinishTimeNanoseconds;
+    }
+
+    public long getServiceBeganTimeNanoseconds() {
+        return mServiceBeganTimeNanoseconds;
+    }
+
+    public long getQueryStartTimeNanoseconds() {
+        return mQueryStartTimeNanoseconds;
+    }
+
+    public long getUiCallStartTimeNanoseconds() {
+        return mUiCallStartTimeNanoseconds;
+    }
+
+    public long getUiCallEndTimeNanoseconds() {
+        return mUiCallEndTimeNanoseconds;
     }
 
     public long getFinalFinishTimeNanoseconds() {
         return mFinalFinishTimeNanoseconds;
     }
 
-    public void setFinalFinishTimeNanoseconds(long finalFinishTimeNanoseconds) {
+    /* --- Time Stamp Conversion to Microseconds --- */
-        mFinalFinishTimeNanoseconds = finalFinishTimeNanoseconds;
+
+    /**
+     * We collect raw timestamps in nanoseconds for ease of collection. However, given the scope
+     * of our logging timeframe, and size considerations of the metric, we require these to give us
+     * the microsecond timestamps from the start reference point.
+     *
+     * @param specificTimestamp the timestamp to consider, must be greater than the reference
+     * @return the microsecond integer timestamp from service start to query began
+     */
+    public int getTimestampFromReferenceStartMicroseconds(long specificTimestamp) {
+        if (specificTimestamp < this.mServiceBeganTimeNanoseconds) {
+            Log.i(TAG, "The timestamp is before service started, falling back to default int");
+            return MetricUtilities.DEFAULT_INT_32;
         }
+        return (int) ((specificTimestamp
+                - this.mServiceBeganTimeNanoseconds) / 1000);
+    }
+
+
+
+    /* ----------- Provider Status -------------- */
 
     public int getChosenProviderStatus() {
         return mChosenProviderStatus;
@@ -68,23 +199,4 @@ public class ChosenProviderMetric {
     public void setChosenProviderStatus(int chosenProviderStatus) {
         mChosenProviderStatus = chosenProviderStatus;
     }
-
-    /**
-     * Returns the full provider (invocation to response) latency in microseconds.
-     */
-    public int getEntireProviderLatencyMs() {
-        return (int) ((this.getFinalFinishTimeNanoseconds()
-                - this.getStartTimeNanoseconds()) / 1000);
-    }
-
-    // TODO get post click final phase and re-add the query phase time to metric
-
-    /**
-     * Returns the end of query to response phase latency in microseconds.
-     */
-    public int getFinalPhaseLatencyMs() {
-        return (int) ((this.getFinalFinishTimeNanoseconds()
-                - this.getQueryFinishTimeNanoseconds()) / 1000);
-    }
-
 }

services/credentials/java/com/android/server/credentials/metrics/PreCandidateMetric.java

@@ -0,0 +1,65 @@
+/*
+ * Copyright (C) 2023 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.credentials.metrics;
+
+/**
+ * This handles metrics collected prior to any remote calls to providers.
+ * TODO(b/270403549) - iterate on this in V3+
+ */
+public class PreCandidateMetric {
+
+    private static final String TAG = "PreCandidateMetric";
+
+    // Raw timestamps in nanoseconds, *the only* one logged as such (i.e. 64 bits) since it is a
+    // reference point.
+
+    private long mCredentialServiceStartedTimeNanoseconds = -1;
+    private long mCredentialServiceBeginQueryTimeNanoseconds = -1;
+
+    public PreCandidateMetric() {
+    }
+
+    /* ---------- Latencies ---------- */
+
+    /* -- Direct Latencies -- */
+
+    public int getServiceStartToQueryLatencyMicroseconds() {
+        return (int) ((this.mCredentialServiceStartedTimeNanoseconds
+                - this.mCredentialServiceBeginQueryTimeNanoseconds) / 1000);
+    }
+
+    /* -- Timestamps -- */
+
+    public void setCredentialServiceStartedTimeNanoseconds(
+            long credentialServiceStartedTimeNanoseconds
+    ) {
+        this.mCredentialServiceStartedTimeNanoseconds = credentialServiceStartedTimeNanoseconds;
+    }
+
+    public void setCredentialServiceBeginQueryTimeNanoseconds(
+            long credentialServiceBeginQueryTimeNanoseconds) {
+        mCredentialServiceBeginQueryTimeNanoseconds = credentialServiceBeginQueryTimeNanoseconds;
+    }
+
+    public long getCredentialServiceStartedTimeNanoseconds() {
+        return mCredentialServiceStartedTimeNanoseconds;
+    }
+
+    public long getCredentialServiceBeginQueryTimeNanoseconds() {
+        return mCredentialServiceBeginQueryTimeNanoseconds;
+    }
+}