Adding logging for generateLinks

Bug: 67629726
Test: Added test and manually verified end-to-end
Change-Id: If5d20b7102b875a898a2fb897b624773554c9083
diff --git a/core/java/android/provider/Settings.java b/core/java/android/provider/Settings.java
index 2ec9009e..47bffc4 100644
--- a/core/java/android/provider/Settings.java
+++ b/core/java/android/provider/Settings.java
@@ -10479,6 +10479,7 @@
          * 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 cbc3828..1789edf 100644
--- a/core/java/android/view/textclassifier/SystemTextClassifier.java
+++ b/core/java/android/view/textclassifier/SystemTextClassifier.java
@@ -41,11 +41,13 @@
 
     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 @@
             @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 efa6948..69f16a4 100644
--- a/core/java/android/view/textclassifier/TextClassifierConstants.java
+++ b/core/java/android/view/textclassifier/TextClassifierConstants.java
@@ -53,6 +53,8 @@
             "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 @@
     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 @@
     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 @@
         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 @@
         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 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 c924658..1b1a3c5 100644
--- a/core/java/android/view/textclassifier/TextClassifierImpl.java
+++ b/core/java/android/view/textclassifier/TextClassifierImpl.java
@@ -38,10 +38,10 @@
 import android.text.util.Linkify;
 import android.util.Patterns;
 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;
@@ -100,7 +100,7 @@
     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.
@@ -121,6 +121,8 @@
     public TextClassifierImpl(Context context) {
         mContext = Preconditions.checkNotNull(context);
         mFallback = TextClassifier.NO_OP;
+        mGenerateLinksLogger = new GenerateLinksLogger(
+                getSettings().getGenerateLinksLogSampleRate());
     }
 
     /** @inheritDoc */
@@ -221,6 +223,7 @@
         }
 
         try {
+            final long startTimeMs = System.currentTimeMillis();
             final LocaleList defaultLocales = options != null ? options.getDefaultLocales() : null;
             final Collection<String> entitiesToIdentify =
                     options != null && options.getEntityConfig() != null
@@ -238,7 +241,15 @@
                 }
                 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 3d252f2..9fa8a90 100644
--- a/core/java/android/view/textclassifier/TextLinks.java
+++ b/core/java/android/view/textclassifier/TextLinks.java
@@ -305,6 +305,8 @@
         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 @@
         }
 
         /**
+         * 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 @@
             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 @@
                 mEntityConfig.writeToParcel(dest, flags);
             }
             dest.writeInt(mApplyStrategy);
+            dest.writeString(mCallingPackageName);
         }
 
         public static final Parcelable.Creator<Options> CREATOR =
@@ -456,6 +478,7 @@
                 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 0000000..fb6f205
--- /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();
+        }
+    }
+}
diff --git a/core/tests/coretests/src/android/view/textclassifier/logging/GenerateLinksLoggerTest.java b/core/tests/coretests/src/android/view/textclassifier/logging/GenerateLinksLoggerTest.java
new file mode 100644
index 0000000..b920ca3
--- /dev/null
+++ b/core/tests/coretests/src/android/view/textclassifier/logging/GenerateLinksLoggerTest.java
@@ -0,0 +1,114 @@
+/*
+ * 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 static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.fail;
+import static org.mockito.Mockito.doNothing;
+import static org.mockito.Mockito.mock;
+
+import android.metrics.LogMaker;
+import android.support.test.filters.SmallTest;
+import android.support.test.runner.AndroidJUnit4;
+import android.util.ArrayMap;
+import android.view.textclassifier.TextClassifier;
+import android.view.textclassifier.TextLinks;
+
+import com.android.internal.logging.MetricsLogger;
+import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
+
+import org.junit.Test;
+import org.junit.runner.RunWith;
+import org.mockito.ArgumentCaptor;
+
+import java.util.List;
+import java.util.Map;
+import java.util.Objects;
+
+@SmallTest
+@RunWith(AndroidJUnit4.class)
+public class GenerateLinksLoggerTest {
+
+    private static final String PACKAGE_NAME = "packageName";
+    private static final String ZERO = "0";
+    private static final int LATENCY_MS = 123;
+
+    @Test
+    public void testLogGenerateLinks() {
+        final String phoneText = "+12122537077";
+        final String addressText = "1600 Amphitheater Parkway, Mountain View, CA";
+        final String testText = "The number is " + phoneText + ", the address is " + addressText;
+        final int phoneOffset = testText.indexOf(phoneText);
+        final int addressOffset = testText.indexOf(addressText);
+
+        final Map<String, Float> phoneEntityScores = new ArrayMap<>();
+        phoneEntityScores.put(TextClassifier.TYPE_PHONE, 0.9f);
+        phoneEntityScores.put(TextClassifier.TYPE_OTHER, 0.1f);
+        final Map<String, Float> addressEntityScores = new ArrayMap<>();
+        addressEntityScores.put(TextClassifier.TYPE_ADDRESS, 1f);
+
+        TextLinks links = new TextLinks.Builder(testText)
+                .addLink(phoneOffset, phoneOffset + phoneText.length(), phoneEntityScores)
+                .addLink(addressOffset, addressOffset + addressText.length(), addressEntityScores)
+                .build();
+
+        // Set up mock.
+        MetricsLogger metricsLogger = mock(MetricsLogger.class);
+        ArgumentCaptor<LogMaker> logMakerCapture = ArgumentCaptor.forClass(LogMaker.class);
+        doNothing().when(metricsLogger).write(logMakerCapture.capture());
+
+        // Generate the log.
+        GenerateLinksLogger logger = new GenerateLinksLogger(1 /* sampleRate */, metricsLogger);
+        logger.logGenerateLinks(testText, links, PACKAGE_NAME, LATENCY_MS);
+
+        // Validate.
+        List<LogMaker> logs = logMakerCapture.getAllValues();
+        assertEquals(3, logs.size());
+        assertHasLog(logs, "" /* entityType */, 2, phoneText.length() + addressText.length(),
+                testText.length());
+        assertHasLog(logs, TextClassifier.TYPE_ADDRESS, 1, addressText.length(),
+                testText.length());
+        assertHasLog(logs, TextClassifier.TYPE_PHONE, 1, phoneText.length(),
+                testText.length());
+    }
+
+    private void assertHasLog(List<LogMaker> logs, String entityType, int numLinks,
+            int linkTextLength, int textLength) {
+        for (LogMaker log : logs) {
+            if (!entityType.equals(getEntityType(log))) {
+                continue;
+            }
+            assertEquals(PACKAGE_NAME, log.getPackageName());
+            assertNotNull(Objects.toString(log.getTaggedData(MetricsEvent.FIELD_LINKIFY_CALL_ID)));
+            assertEquals(numLinks, getIntValue(log, MetricsEvent.FIELD_LINKIFY_NUM_LINKS));
+            assertEquals(linkTextLength, getIntValue(log, MetricsEvent.FIELD_LINKIFY_LINK_LENGTH));
+            assertEquals(textLength, getIntValue(log, MetricsEvent.FIELD_LINKIFY_TEXT_LENGTH));
+            assertEquals(LATENCY_MS, getIntValue(log, MetricsEvent.FIELD_LINKIFY_LATENCY));
+            return;
+        }
+        fail("No log for entity type \"" + entityType + "\"");
+    }
+
+    private static String getEntityType(LogMaker log) {
+        return Objects.toString(log.getTaggedData(MetricsEvent.FIELD_LINKIFY_ENTITY_TYPE), "");
+    }
+
+    private static int getIntValue(LogMaker log, int eventField) {
+        return Integer.parseInt(Objects.toString(log.getTaggedData(eventField), ZERO));
+    }
+}
diff --git a/proto/src/metrics_constants.proto b/proto/src/metrics_constants.proto
index 7e86ef5..c0e5960 100644
--- a/proto/src/metrics_constants.proto
+++ b/proto/src/metrics_constants.proto
@@ -5283,6 +5283,40 @@
     // OS: P
     USB_DEFAULT = 1312;
 
+    // CATEGORY: The category for all actions related to TextClassifier generateLinks.
+    // OS: P
+    TEXT_CLASSIFIER_GENERATE_LINKS = 1313;
+
+    // FIELD: milliseconds spent generating links.
+    // CATEGORY: TEXT_CLASSIFIER_GENERATE_LINKS
+    // OS: P
+    FIELD_LINKIFY_LATENCY = 1314;
+
+    // FIELD: length of the input text in characters.
+    // CATEGORY: TEXT_CLASSIFIER_GENERATE_LINKS
+    // OS: P
+    FIELD_LINKIFY_TEXT_LENGTH = 1315;
+
+    // FIELD: number of links detected.
+    // CATEGORY: TEXT_CLASSIFIER_GENERATE_LINKS
+    // OS: P
+    FIELD_LINKIFY_NUM_LINKS = 1316;
+
+    // FIELD: length of all links in characters.
+    // CATEGORY: TEXT_CLASSIFIER_GENERATE_LINKS
+    // OS: P
+    FIELD_LINKIFY_LINK_LENGTH = 1317;
+
+    // FIELD: the type of entity the stats are for.
+    // CATEGORY: TEXT_CLASSIFIER_GENERATE_LINKS
+    // OS: P
+    FIELD_LINKIFY_ENTITY_TYPE = 1318;
+
+    // FIELD: a random uid for a single call to generateLinks
+    // CATEGORY: TEXT_CLASSIFIER_GENERATE_LINKS
+    // OS: P
+    FIELD_LINKIFY_CALL_ID = 1319;
+
     // ---- End P Constants, all P constants go above this line ----
     // Add new aosp constants above this line.
     // END OF AOSP CONSTANTS