Merge "Adding logging for generateLinks"

6 files changed, 218 insertions, 3 deletions

diff --git a/core/java/android/provider/Settings.java b/core/java/android/provider/Settings.java
index 2ec9009ee549..47bffc42f9bf 100644
--- a/core/java/android/provider/Settings.java
+++ b/core/java/android/provider/Settings.java
@@ -10479,6 +10479,7 @@ public final class Settings {
          * suggest_selection_max_range_length       (int)
          * classify_text_max_range_length           (int)
          * generate_links_max_text_length           (int)
+         * generate_links_log_sample_rate           (int)
          * </pre>
          *
          * <p>
diff --git a/core/java/android/view/textclassifier/SystemTextClassifier.java b/core/java/android/view/textclassifier/SystemTextClassifier.java
index cbc3828ba56e..1789edf1e876 100644
--- a/core/java/android/view/textclassifier/SystemTextClassifier.java
+++ b/core/java/android/view/textclassifier/SystemTextClassifier.java
@@ -41,11 +41,13 @@ final class SystemTextClassifier implements TextClassifier {
 
     private final ITextClassifierService mManagerService;
     private final TextClassifier mFallback;
+    private final String mPackageName;
 
     SystemTextClassifier(Context context) throws ServiceManager.ServiceNotFoundException {
         mManagerService = ITextClassifierService.Stub.asInterface(
                 ServiceManager.getServiceOrThrow(Context.TEXT_CLASSIFICATION_SERVICE));
         mFallback = new TextClassifierImpl(context);
+        mPackageName = context.getPackageName();
     }
 
     /**
@@ -107,6 +109,11 @@ final class SystemTextClassifier implements TextClassifier {
             @NonNull CharSequence text, @Nullable TextLinks.Options options) {
         Utils.validate(text, false /* allowInMainThread */);
         try {
+            if (options == null) {
+                options = new TextLinks.Options().setCallingPackageName(mPackageName);
+            } else if (!mPackageName.equals(options.getCallingPackageName())) {
+                options.setCallingPackageName(mPackageName);
+            }
             final TextLinksCallback callback = new TextLinksCallback();
             mManagerService.onGenerateLinks(text, options, callback);
             final TextLinks links = callback.mReceiver.get();
diff --git a/core/java/android/view/textclassifier/TextClassifierConstants.java b/core/java/android/view/textclassifier/TextClassifierConstants.java
index efa69488521f..69f16a4b5174 100644
--- a/core/java/android/view/textclassifier/TextClassifierConstants.java
+++ b/core/java/android/view/textclassifier/TextClassifierConstants.java
@@ -53,6 +53,8 @@ public final class TextClassifierConstants {
             "classify_text_max_range_length";
     private static final String GENERATE_LINKS_MAX_TEXT_LENGTH =
             "generate_links_max_text_length";
+    private static final String GENERATE_LINKS_LOG_SAMPLE_RATE =
+            "generate_links_log_sample_rate";
 
     private static final boolean SMART_SELECTION_DARK_LAUNCH_DEFAULT = false;
     private static final boolean SMART_SELECTION_ENABLED_FOR_EDIT_TEXT_DEFAULT = true;
@@ -60,6 +62,7 @@ public final class TextClassifierConstants {
     private static final int SUGGEST_SELECTION_MAX_RANGE_LENGTH_DEFAULT = 10 * 1000;
     private static final int CLASSIFY_TEXT_MAX_RANGE_LENGTH_DEFAULT = 10 * 1000;
     private static final int GENERATE_LINKS_MAX_TEXT_LENGTH_DEFAULT = 100 * 1000;
+    private static final int GENERATE_LINKS_LOG_SAMPLE_RATE_DEFAULT = 100;
 
     /** Default settings. */
     static final TextClassifierConstants DEFAULT = new TextClassifierConstants();
@@ -70,6 +73,7 @@ public final class TextClassifierConstants {
     private final int mSuggestSelectionMaxRangeLength;
     private final int mClassifyTextMaxRangeLength;
     private final int mGenerateLinksMaxTextLength;
+    private final int mGenerateLinksLogSampleRate;
 
     private TextClassifierConstants() {
         mDarkLaunch = SMART_SELECTION_DARK_LAUNCH_DEFAULT;
@@ -78,6 +82,7 @@ public final class TextClassifierConstants {
         mSuggestSelectionMaxRangeLength = SUGGEST_SELECTION_MAX_RANGE_LENGTH_DEFAULT;
         mClassifyTextMaxRangeLength = CLASSIFY_TEXT_MAX_RANGE_LENGTH_DEFAULT;
         mGenerateLinksMaxTextLength = GENERATE_LINKS_MAX_TEXT_LENGTH_DEFAULT;
+        mGenerateLinksLogSampleRate = GENERATE_LINKS_LOG_SAMPLE_RATE_DEFAULT;
     }
 
     private TextClassifierConstants(@Nullable String settings) {
@@ -106,6 +111,9 @@ public final class TextClassifierConstants {
         mGenerateLinksMaxTextLength = parser.getInt(
                 GENERATE_LINKS_MAX_TEXT_LENGTH,
                 GENERATE_LINKS_MAX_TEXT_LENGTH_DEFAULT);
+        mGenerateLinksLogSampleRate = parser.getInt(
+                GENERATE_LINKS_LOG_SAMPLE_RATE,
+                GENERATE_LINKS_LOG_SAMPLE_RATE_DEFAULT);
     }
 
     static TextClassifierConstants loadFromString(String settings) {
@@ -135,4 +143,8 @@ public final class TextClassifierConstants {
     public int getGenerateLinksMaxTextLength() {
         return mGenerateLinksMaxTextLength;
     }
+
+    public int getGenerateLinksLogSampleRate() {
+        return mGenerateLinksLogSampleRate;
+    }
 }
diff --git a/core/java/android/view/textclassifier/TextClassifierImpl.java b/core/java/android/view/textclassifier/TextClassifierImpl.java
index 8f6f600cfc72..90619c491cff 100644
--- a/core/java/android/view/textclassifier/TextClassifierImpl.java
+++ b/core/java/android/view/textclassifier/TextClassifierImpl.java
@@ -36,10 +36,10 @@ import android.provider.CalendarContract;
 import android.provider.ContactsContract;
 import android.provider.Settings;
 import android.view.textclassifier.logging.DefaultLogger;
+import android.view.textclassifier.logging.GenerateLinksLogger;
 import android.view.textclassifier.logging.Logger;
 
 import com.android.internal.annotations.GuardedBy;
-import com.android.internal.logging.MetricsLogger;
 import com.android.internal.util.Preconditions;
 
 import java.io.File;
@@ -92,7 +92,7 @@ public final class TextClassifierImpl implements TextClassifier {
     private final Context mContext;
     private final TextClassifier mFallback;
 
-    private final MetricsLogger mMetricsLogger = new MetricsLogger();
+    private final GenerateLinksLogger mGenerateLinksLogger;
 
     private final Object mLock = new Object();
     @GuardedBy("mLock") // Do not access outside this lock.
@@ -113,6 +113,8 @@ public final class TextClassifierImpl implements TextClassifier {
     public TextClassifierImpl(Context context) {
         mContext = Preconditions.checkNotNull(context);
         mFallback = TextClassifier.NO_OP;
+        mGenerateLinksLogger = new GenerateLinksLogger(
+                getSettings().getGenerateLinksLogSampleRate());
     }
 
     /** @inheritDoc */
@@ -226,6 +228,7 @@ public final class TextClassifierImpl implements TextClassifier {
         }
 
         try {
+            final long startTimeMs = System.currentTimeMillis();
             final LocaleList defaultLocales = options != null ? options.getDefaultLocales() : null;
             final Calendar refTime = Calendar.getInstance();
             final Collection<String> entitiesToIdentify =
@@ -255,7 +258,15 @@ public final class TextClassifierImpl implements TextClassifier {
                 }
                 builder.addLink(span.getStartIndex(), span.getEndIndex(), entityScores);
             }
-            return builder.build();
+            final TextLinks links = builder.build();
+            final long endTimeMs = System.currentTimeMillis();
+            final String callingPackageName =
+                    options == null || options.getCallingPackageName() == null
+                            ? mContext.getPackageName()  // local (in process) TC.
+                            : options.getCallingPackageName();
+            mGenerateLinksLogger.logGenerateLinks(
+                    text, links, callingPackageName, endTimeMs - startTimeMs);
+            return links;
         } catch (Throwable t) {
             // Avoid throwing from this method. Log the error.
             Log.e(LOG_TAG, "Error getting links info.", t);
diff --git a/core/java/android/view/textclassifier/TextLinks.java b/core/java/android/view/textclassifier/TextLinks.java
index dc24d0c4d681..884cbe861deb 100644
--- a/core/java/android/view/textclassifier/TextLinks.java
+++ b/core/java/android/view/textclassifier/TextLinks.java
@@ -305,6 +305,8 @@ public final class TextLinks implements Parcelable {
         private @ApplyStrategy int mApplyStrategy;
         private Function<TextLink, TextLinkSpan> mSpanFactory;
 
+        private String mCallingPackageName;
+
         /**
          * Returns a new options object based on the specified link mask.
          */
@@ -377,6 +379,15 @@ public final class TextLinks implements Parcelable {
         }
 
         /**
+         * Sets the name of the package that requested the links to get generated.
+         * @hide
+         */
+        public Options setCallingPackageName(@Nullable String callingPackageName) {
+            mCallingPackageName = callingPackageName;
+            return this;
+        }
+
+        /**
          * @return ordered list of locale preferences that can be used to disambiguate
          *      the provided text
          */
@@ -417,6 +428,16 @@ public final class TextLinks implements Parcelable {
             return mSpanFactory;
         }
 
+        /**
+         * @return the name of the package that requested the links to get generated.
+         * TODO: make available as system API
+         * @hide
+         */
+        @Nullable
+        public String getCallingPackageName() {
+            return mCallingPackageName;
+        }
+
         @Override
         public int describeContents() {
             return 0;
@@ -433,6 +454,7 @@ public final class TextLinks implements Parcelable {
                 mEntityConfig.writeToParcel(dest, flags);
             }
             dest.writeInt(mApplyStrategy);
+            dest.writeString(mCallingPackageName);
         }
 
         public static final Parcelable.Creator<Options> CREATOR =
@@ -456,6 +478,7 @@ public final class TextLinks implements Parcelable {
                 mEntityConfig = TextClassifier.EntityConfig.CREATOR.createFromParcel(in);
             }
             mApplyStrategy = in.readInt();
+            mCallingPackageName = in.readString();
         }
     }
 
diff --git a/core/java/android/view/textclassifier/logging/GenerateLinksLogger.java b/core/java/android/view/textclassifier/logging/GenerateLinksLogger.java
new file mode 100644
index 000000000000..fb6f205eb462
--- /dev/null
+++ b/core/java/android/view/textclassifier/logging/GenerateLinksLogger.java
@@ -0,0 +1,161 @@
+/*
+ * Copyright (C) 2017 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.view.textclassifier.logging;
+
+import android.annotation.Nullable;
+import android.metrics.LogMaker;
+import android.util.ArrayMap;
+import android.util.Log;
+import android.view.textclassifier.TextClassifier;
+import android.view.textclassifier.TextLinks;
+
+import com.android.internal.annotations.VisibleForTesting;
+import com.android.internal.logging.MetricsLogger;
+import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
+import com.android.internal.util.Preconditions;
+
+import java.util.Map;
+import java.util.Objects;
+import java.util.Random;
+import java.util.UUID;
+
+/**
+ * A helper for logging calls to generateLinks.
+ * @hide
+ */
+@VisibleForTesting(visibility = VisibleForTesting.Visibility.PACKAGE)
+public final class GenerateLinksLogger {
+
+    private static final String LOG_TAG = "GenerateLinksLogger";
+    private static final String ZERO = "0";
+
+    private final MetricsLogger mMetricsLogger;
+    private final Random mRng;
+    private final int mSampleRate;
+
+    /**
+     * @param sampleRate the rate at which log events are written. (e.g. 100 means there is a 0.01
+     *                   chance that a call to logGenerateLinks results in an event being written).
+     *                   To write all events, pass 1.
+     */
+    public GenerateLinksLogger(int sampleRate) {
+        mSampleRate = sampleRate;
+        mRng = new Random(System.nanoTime());
+        mMetricsLogger = new MetricsLogger();
+    }
+
+    @VisibleForTesting
+    public GenerateLinksLogger(int sampleRate, MetricsLogger metricsLogger) {
+        mSampleRate = sampleRate;
+        mRng = new Random(System.nanoTime());
+        mMetricsLogger = metricsLogger;
+    }
+
+    /** Logs statistics about a call to generateLinks. */
+    public void logGenerateLinks(CharSequence text, TextLinks links, String callingPackageName,
+            long latencyMs) {
+        Preconditions.checkNotNull(text);
+        Preconditions.checkNotNull(links);
+        Preconditions.checkNotNull(callingPackageName);
+        if (!shouldLog()) {
+            return;
+        }
+
+        // Always populate the total stats, and per-entity stats for each entity type detected.
+        final LinkifyStats totalStats = new LinkifyStats();
+        final Map<String, LinkifyStats> perEntityTypeStats = new ArrayMap<>();
+        for (TextLinks.TextLink link : links.getLinks()) {
+            if (link.getEntityCount() == 0) continue;
+            final String entityType = link.getEntity(0);
+            if (entityType == null
+                    || TextClassifier.TYPE_OTHER.equals(entityType)
+                    || TextClassifier.TYPE_UNKNOWN.equals(entityType)) {
+                continue;
+            }
+            totalStats.countLink(link);
+            perEntityTypeStats.computeIfAbsent(entityType, k -> new LinkifyStats()).countLink(link);
+        }
+
+        final String callId = UUID.randomUUID().toString();
+        writeStats(callId, callingPackageName, null, totalStats, text, latencyMs);
+        for (Map.Entry<String, LinkifyStats> entry : perEntityTypeStats.entrySet()) {
+            writeStats(callId, callingPackageName, entry.getKey(), entry.getValue(), text,
+                       latencyMs);
+        }
+    }
+
+    /**
+     * Returns whether this particular event should be logged.
+     *
+     * Sampling is used to reduce the amount of logging data generated.
+     **/
+    private boolean shouldLog() {
+        if (mSampleRate <= 1) {
+            return true;
+        } else {
+            return mRng.nextInt(mSampleRate) == 0;
+        }
+    }
+
+    /** Writes a log event for the given stats. */
+    private void writeStats(String callId, String callingPackageName, @Nullable String entityType,
+                            LinkifyStats stats, CharSequence text, long latencyMs) {
+        final LogMaker log = new LogMaker(MetricsEvent.TEXT_CLASSIFIER_GENERATE_LINKS)
+                .setPackageName(callingPackageName)
+                .addTaggedData(MetricsEvent.FIELD_LINKIFY_CALL_ID, callId)
+                .addTaggedData(MetricsEvent.FIELD_LINKIFY_NUM_LINKS, stats.mNumLinks)
+                .addTaggedData(MetricsEvent.FIELD_LINKIFY_LINK_LENGTH, stats.mNumLinksTextLength)
+                .addTaggedData(MetricsEvent.FIELD_LINKIFY_TEXT_LENGTH, text.length())
+                .addTaggedData(MetricsEvent.FIELD_LINKIFY_LATENCY, latencyMs);
+        if (entityType != null) {
+            log.addTaggedData(MetricsEvent.FIELD_LINKIFY_ENTITY_TYPE, entityType);
+        }
+        mMetricsLogger.write(log);
+        debugLog(log);
+    }
+
+    private static void debugLog(LogMaker log) {
+        if (!Logger.DEBUG_LOG_ENABLED) return;
+
+        final String callId = Objects.toString(
+                log.getTaggedData(MetricsEvent.FIELD_LINKIFY_CALL_ID), "");
+        final String entityType = Objects.toString(
+                log.getTaggedData(MetricsEvent.FIELD_LINKIFY_ENTITY_TYPE), "ANY_ENTITY");
+        final int numLinks = Integer.parseInt(
+                Objects.toString(log.getTaggedData(MetricsEvent.FIELD_LINKIFY_NUM_LINKS), ZERO));
+        final int linkLength = Integer.parseInt(
+                Objects.toString(log.getTaggedData(MetricsEvent.FIELD_LINKIFY_LINK_LENGTH), ZERO));
+        final int textLength = Integer.parseInt(
+                Objects.toString(log.getTaggedData(MetricsEvent.FIELD_LINKIFY_TEXT_LENGTH), ZERO));
+        final int latencyMs = Integer.parseInt(
+                Objects.toString(log.getTaggedData(MetricsEvent.FIELD_LINKIFY_LATENCY), ZERO));
+
+        Log.d(LOG_TAG, String.format("%s:%s %d links (%d/%d chars) %dms %s", callId, entityType,
+                numLinks, linkLength, textLength, latencyMs, log.getPackageName()));
+    }
+
+    /** Helper class for storing per-entity type statistics. */
+    private static final class LinkifyStats {
+        int mNumLinks;
+        int mNumLinksTextLength;
+
+        void countLink(TextLinks.TextLink link) {
+            mNumLinks += 1;
+            mNumLinksTextLength += link.getEnd() - link.getStart();
+        }
+    }
+}