Merge "Added moar augmented-autofill metrics:" into qt-dev

3 files changed, 91 insertions, 26 deletions

diff --git a/core/java/android/service/autofill/augmented/AugmentedAutofillService.java b/core/java/android/service/autofill/augmented/AugmentedAutofillService.java
index 656127ad77a9..87e369f20d58 100644
--- a/core/java/android/service/autofill/augmented/AugmentedAutofillService.java
+++ b/core/java/android/service/autofill/augmented/AugmentedAutofillService.java
@@ -15,6 +15,9 @@
  */
 package android.service.autofill.augmented;
 
+import static android.service.autofill.augmented.Helper.logResponse;
+import static android.util.TimeUtils.formatDuration;
+
 import static com.android.internal.util.function.pooled.PooledLambda.obtainMessage;
 
 import android.annotation.CallSuper;
@@ -38,9 +41,7 @@ import android.os.SystemClock;
 import android.service.autofill.augmented.PresentationParams.SystemPopupPresentationParams;
 import android.util.Log;
 import android.util.Pair;
-import android.util.Slog;
 import android.util.SparseArray;
-import android.util.TimeUtils;
 import android.view.autofill.AutofillId;
 import android.view.autofill.AutofillManager;
 import android.view.autofill.AutofillValue;
@@ -48,6 +49,7 @@ import android.view.autofill.IAugmentedAutofillManagerClient;
 import android.view.autofill.IAutofillWindowPresenter;
 
 import com.android.internal.annotations.GuardedBy;
+import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
 
 import java.io.FileDescriptor;
 import java.io.PrintWriter;
@@ -84,6 +86,9 @@ public abstract class AugmentedAutofillService extends Service {
 
     private SparseArray<AutofillProxy> mAutofillProxies;
 
+    // Used for metrics / debug only
+    private ComponentName mServiceComponentName;
+
     private final IAugmentedAutofillService mInterface = new IAugmentedAutofillService.Stub() {
 
         @Override
@@ -125,6 +130,7 @@ public abstract class AugmentedAutofillService extends Service {
     /** @hide */
     @Override
     public final IBinder onBind(Intent intent) {
+        mServiceComponentName = intent.getComponent();
         if (SERVICE_INTERFACE.equals(intent.getAction())) {
             return mInterface.asBinder();
         }
@@ -215,8 +221,9 @@ public abstract class AugmentedAutofillService extends Service {
         final CancellationSignal cancellationSignal = CancellationSignal.fromTransport(transport);
         AutofillProxy proxy = mAutofillProxies.get(sessionId);
         if (proxy == null) {
-            proxy = new AutofillProxy(sessionId, client, taskId, componentName, focusedId,
-                    focusedValue, requestTime, callback, cancellationSignal);
+            proxy = new AutofillProxy(sessionId, client, taskId, mServiceComponentName,
+                    componentName, focusedId, focusedValue, requestTime, callback,
+                    cancellationSignal);
             mAutofillProxies.put(sessionId,  proxy);
         } else {
             // TODO(b/123099468): figure out if it's ok to reuse the proxy; add logging
@@ -272,6 +279,8 @@ public abstract class AugmentedAutofillService extends Service {
     @Override
     /** @hide */
     protected final void dump(FileDescriptor fd, PrintWriter pw, String[] args) {
+        pw.print("Service component: "); pw.println(
+                ComponentName.flattenToShortString(mServiceComponentName));
         if (mAutofillProxies != null) {
             final int size = mAutofillProxies.size();
             pw.print("Number proxies: "); pw.println(size);
@@ -301,12 +310,12 @@ public abstract class AugmentedAutofillService extends Service {
     /** @hide */
     static final class AutofillProxy {
 
-        static final int REPORT_EVENT_ON_SUCCESS = 1;
+        static final int REPORT_EVENT_NO_RESPONSE = 1;
         static final int REPORT_EVENT_UI_SHOWN = 2;
         static final int REPORT_EVENT_UI_DESTROYED = 3;
 
         @IntDef(prefix = { "REPORT_EVENT_" }, value = {
-                REPORT_EVENT_ON_SUCCESS,
+                REPORT_EVENT_NO_RESPONSE,
                 REPORT_EVENT_UI_SHOWN,
                 REPORT_EVENT_UI_DESTROYED
         })
@@ -319,6 +328,8 @@ public abstract class AugmentedAutofillService extends Service {
         private final int mSessionId;
         public final int taskId;
         public final ComponentName componentName;
+        // Used for metrics / debug only
+        private String mServicePackageName;
         @GuardedBy("mLock")
         private AutofillId mFocusedId;
         @GuardedBy("mLock")
@@ -349,6 +360,7 @@ public abstract class AugmentedAutofillService extends Service {
         private CancellationSignal mCancellationSignal;
 
         private AutofillProxy(int sessionId, @NonNull IBinder client, int taskId,
+                @NonNull ComponentName serviceComponentName,
                 @NonNull ComponentName componentName, @NonNull AutofillId focusedId,
                 @Nullable AutofillValue focusedValue, long requestTime,
                 @NonNull IFillCallback callback, @NonNull CancellationSignal cancellationSignal) {
@@ -357,6 +369,7 @@ public abstract class AugmentedAutofillService extends Service {
             mCallback = callback;
             this.taskId = taskId;
             this.componentName = componentName;
+            mServicePackageName = serviceComponentName.getPackageName();
             mFocusedId = focusedId;
             mFocusedValue = focusedValue;
             mFirstRequestTime = requestTime;
@@ -439,9 +452,9 @@ public abstract class AugmentedAutofillService extends Service {
                             mCallback.cancel();
                         }
                     } catch (RemoteException e) {
-                        Slog.e(TAG, "failed to check current pending request status", e);
+                        Log.e(TAG, "failed to check current pending request status", e);
                     }
-                    Slog.d(TAG, "mCallback is updated.");
+                    Log.d(TAG, "mCallback is updated.");
                 }
                 mCallback = callback;
             }
@@ -463,13 +476,17 @@ public abstract class AugmentedAutofillService extends Service {
 
         // Used (mostly) for metrics.
         public void report(@ReportEvent int event) {
+            if (sVerbose) Log.v(TAG, "report(): " + event);
+            long duration = -1;
+            int type = MetricsEvent.TYPE_UNKNOWN;
             switch (event) {
-                case REPORT_EVENT_ON_SUCCESS:
+                case REPORT_EVENT_NO_RESPONSE:
+                    type = MetricsEvent.TYPE_SUCCESS;
                     if (mFirstOnSuccessTime == 0) {
                         mFirstOnSuccessTime = SystemClock.elapsedRealtime();
+                        duration = mFirstOnSuccessTime - mFirstRequestTime;
                         if (sDebug) {
-                            Slog.d(TAG, "Service responded in " + TimeUtils.formatDuration(
-                                    mFirstOnSuccessTime - mFirstRequestTime));
+                            Log.d(TAG, "Service responded nothing in " + formatDuration(duration));
                         }
                     }
                     try {
@@ -479,27 +496,25 @@ public abstract class AugmentedAutofillService extends Service {
                     }
                     break;
                 case REPORT_EVENT_UI_SHOWN:
+                    type = MetricsEvent.TYPE_OPEN;
                     if (mUiFirstShownTime == 0) {
                         mUiFirstShownTime = SystemClock.elapsedRealtime();
-                        if (sDebug) {
-                            Slog.d(TAG, "UI shown in " + TimeUtils.formatDuration(
-                                    mUiFirstShownTime - mFirstRequestTime));
-                        }
+                        duration = mUiFirstShownTime - mFirstRequestTime;
+                        if (sDebug) Log.d(TAG, "UI shown in " + formatDuration(duration));
                     }
                     break;
                 case REPORT_EVENT_UI_DESTROYED:
+                    type = MetricsEvent.TYPE_CLOSE;
                     if (mUiFirstDestroyedTime == 0) {
                         mUiFirstDestroyedTime = SystemClock.elapsedRealtime();
-                        if (sDebug) {
-                            Slog.d(TAG, "UI destroyed in " + TimeUtils.formatDuration(
-                                    mUiFirstDestroyedTime - mFirstRequestTime));
-                        }
+                        duration =  mUiFirstDestroyedTime - mFirstRequestTime;
+                        if (sDebug) Log.d(TAG, "UI destroyed in " + formatDuration(duration));
                     }
                     break;
                 default:
-                    Slog.w(TAG, "invalid event reported: " + event);
+                    Log.w(TAG, "invalid event reported: " + event);
             }
-            // TODO(b/122858578): log metrics as well
+            logResponse(type, mServicePackageName, componentName, mSessionId, duration);
         }
 
         public void dump(@NonNull String prefix, @NonNull PrintWriter pw) {
@@ -527,19 +542,19 @@ public abstract class AugmentedAutofillService extends Service {
             if (mFirstOnSuccessTime > 0) {
                 final long responseTime = mFirstOnSuccessTime - mFirstRequestTime;
                 pw.print(prefix); pw.print("response time: ");
-                TimeUtils.formatDuration(responseTime, pw); pw.println();
+                formatDuration(responseTime, pw); pw.println();
             }
 
             if (mUiFirstShownTime > 0) {
                 final long uiRenderingTime = mUiFirstShownTime - mFirstRequestTime;
                 pw.print(prefix); pw.print("UI rendering time: ");
-                TimeUtils.formatDuration(uiRenderingTime, pw); pw.println();
+                formatDuration(uiRenderingTime, pw); pw.println();
             }
 
             if (mUiFirstDestroyedTime > 0) {
                 final long uiTotalTime = mUiFirstDestroyedTime - mFirstRequestTime;
                 pw.print(prefix); pw.print("UI life time: ");
-                TimeUtils.formatDuration(uiTotalTime, pw); pw.println();
+                formatDuration(uiTotalTime, pw); pw.println();
             }
         }
 
diff --git a/core/java/android/service/autofill/augmented/FillCallback.java b/core/java/android/service/autofill/augmented/FillCallback.java
index 33e6a8c25ba4..0251386bd7ce 100644
--- a/core/java/android/service/autofill/augmented/FillCallback.java
+++ b/core/java/android/service/autofill/augmented/FillCallback.java
@@ -50,8 +50,10 @@ public final class FillCallback {
     public void onSuccess(@Nullable FillResponse response) {
         if (sDebug) Log.d(TAG, "onSuccess(): " + response);
 
-        mProxy.report(AutofillProxy.REPORT_EVENT_ON_SUCCESS);
-        if (response == null) return;
+        if (response == null) {
+            mProxy.report(AutofillProxy.REPORT_EVENT_NO_RESPONSE);
+            return;
+        }
 
         final FillWindow fillWindow = response.getFillWindow();
         if (fillWindow != null) {
diff --git a/core/java/android/service/autofill/augmented/Helper.java b/core/java/android/service/autofill/augmented/Helper.java
new file mode 100644
index 000000000000..501696f99c66
--- /dev/null
+++ b/core/java/android/service/autofill/augmented/Helper.java
@@ -0,0 +1,48 @@
+/*
+ * Copyright (C) 2019 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 android.service.autofill.augmented;
+
+import android.annotation.NonNull;
+import android.content.ComponentName;
+import android.metrics.LogMaker;
+
+import com.android.internal.logging.MetricsLogger;
+import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
+
+/** @hide */
+public final class Helper {
+
+    private static final MetricsLogger sMetricsLogger = new MetricsLogger();
+
+    /**
+     * Logs a {@code MetricsEvent.AUTOFILL_AUGMENTED_RESPONSE} event.
+     */
+    public static void logResponse(int type, @NonNull String servicePackageName,
+            @NonNull ComponentName componentName, int mSessionId, long durationMs) {
+        final LogMaker log = new LogMaker(MetricsEvent.AUTOFILL_AUGMENTED_RESPONSE)
+                .setType(type)
+                .setComponentName(componentName)
+                .addTaggedData(MetricsEvent.FIELD_AUTOFILL_SESSION_ID, mSessionId)
+                .addTaggedData(MetricsEvent.FIELD_AUTOFILL_SERVICE, servicePackageName)
+                .addTaggedData(MetricsEvent.FIELD_AUTOFILL_DURATION, durationMs);
+        System.out.println("LOGGGO: " + log.getEntries()); // felipeal: tmp
+        sMetricsLogger.write(log);
+    }
+
+    private Helper() {
+        throw new UnsupportedOperationException("contains only static methods");
+    }
+}