[Rlog1] Track time of log statements

Log statements are now recorded with a timestamp.  This is important for filtering out statements
not part of words that are sampled when spaces are inserted automatically.

multi-project commit with Change-Id: I68221a2528045d25632aef4bb716f92a4f4a56a4

Change-Id: I46ac9b3b1dcbb08425160d0109028cb64445139c

java/src/com/android/inputmethod/research/LogUnit.java

@@ -18,7 +18,7 @@ package com.android.inputmethod.research;
 
 import com.android.inputmethod.latin.CollectionUtils;
 
-import java.util.ArrayList;
+import java.util.List;
 
 /**
  * A group of log statements related to each other.
@@ -35,16 +35,39 @@ import java.util.ArrayList;
  * been published recently, or whether the LogUnit contains numbers, etc.
  */
 /* package */ class LogUnit {
-    private final ArrayList<String[]> mKeysList = CollectionUtils.newArrayList();
+    private final List<String[]> mKeysList;
-    private final ArrayList<Object[]> mValuesList = CollectionUtils.newArrayList();
+    private final List<Object[]> mValuesList;
-    private final ArrayList<Boolean> mIsPotentiallyPrivate = CollectionUtils.newArrayList();
+    // Assume that mTimeList is sorted in increasing order.  Do not insert null values into
+    // mTimeList.
+    private final List<Long> mTimeList;
+    private final List<Boolean> mIsPotentiallyPrivate;
     private String mWord;
-    private boolean mContainsDigit;
+    private boolean mMayContainDigit;
 
+    public LogUnit() {
+        mKeysList = CollectionUtils.newArrayList();
+        mValuesList = CollectionUtils.newArrayList();
+        mTimeList = CollectionUtils.newArrayList();
+        mIsPotentiallyPrivate = CollectionUtils.newArrayList();
+    }
+
+    private LogUnit(final List<String[]> keysList, final List<Object[]> valuesList,
+            final List<Long> timeList, final List<Boolean> isPotentiallyPrivate) {
+        mKeysList = keysList;
+        mValuesList = valuesList;
+        mTimeList = timeList;
+        mIsPotentiallyPrivate = isPotentiallyPrivate;
+    }
+
+    /**
+     * Adds a new log statement.  The time parameter in successive calls to this method must be
+     * monotonically increasing, or splitByTime() will not work.
+     */
     public void addLogStatement(final String[] keys, final Object[] values,
-            final Boolean isPotentiallyPrivate) {
+            final long time, final boolean isPotentiallyPrivate) {
         mKeysList.add(keys);
         mValuesList.add(values);
+        mTimeList.add(time);
         mIsPotentiallyPrivate.add(isPotentiallyPrivate);
     }
 
@@ -52,7 +75,7 @@ import java.util.ArrayList;
         final int size = mKeysList.size();
         for (int i = 0; i < size; i++) {
             if (!mIsPotentiallyPrivate.get(i) || isIncludingPrivateData) {
-                researchLog.outputEvent(mKeysList.get(i), mValuesList.get(i));
+                researchLog.outputEvent(mKeysList.get(i), mValuesList.get(i), mTimeList.get(i));
             }
         }
     }
@@ -69,15 +92,37 @@ import java.util.ArrayList;
         return mWord != null;
     }
 
-    public void setContainsDigit() {
+    public void setMayContainDigit() {
-        mContainsDigit = true;
+        mMayContainDigit = true;
     }
 
-    public boolean hasDigit() {
+    public boolean mayContainDigit() {
-        return mContainsDigit;
+        return mMayContainDigit;
     }
 
     public boolean isEmpty() {
         return mKeysList.isEmpty();
     }
+
+    /**
+     * Split this logUnit, with all events before maxTime staying in the current logUnit, and all
+     * events after maxTime going into a new LogUnit that is returned.
+     */
+    public LogUnit splitByTime(final long maxTime) {
+        // Assume that mTimeList is in sorted order.
+        final int length = mTimeList.size();
+        for (int index = 0; index < length; index++) {
+            if (mTimeList.get(index) >= maxTime) {
+                final LogUnit newLogUnit = new LogUnit(
+                        mKeysList.subList(index, length),
+                        mValuesList.subList(index, length),
+                        mTimeList.subList(index, length),
+                        mIsPotentiallyPrivate.subList(index, length));
+                newLogUnit.mWord = null;
+                newLogUnit.mMayContainDigit = mMayContainDigit;
+                return newLogUnit;
+            }
+        }
+        return new LogUnit();
+    }
 }

java/src/com/android/inputmethod/research/MainLogBuffer.java

@@ -113,7 +113,7 @@ public class MainLogBuffer extends LogBuffer {
             final String word = logUnit.getWord();
             if (word == null) {
                 // Digits outside words are a privacy threat.
-                if (logUnit.hasDigit()) {
+                if (logUnit.mayContainDigit()) {
                     return false;
                 }
             } else {

java/src/com/android/inputmethod/research/ResearchLog.java

@@ -207,7 +207,7 @@ public class ResearchLog {
     private static final String UPTIME_KEY = "_ut";
     private static final String EVENT_TYPE_KEY = "_ty";
 
-    void outputEvent(final String[] keys, final Object[] values) {
+    void outputEvent(final String[] keys, final Object[] values, final long time) {
         // Not thread safe.
         if (keys.length == 0) {
             return;
@@ -225,7 +225,7 @@ public class ResearchLog {
             }
             mJsonWriter.beginObject();
             mJsonWriter.name(CURRENT_TIME_KEY).value(System.currentTimeMillis());
-            mJsonWriter.name(UPTIME_KEY).value(SystemClock.uptimeMillis());
+            mJsonWriter.name(UPTIME_KEY).value(time);
             mJsonWriter.name(EVENT_TYPE_KEY).value(keys[0]);
             final int length = values.length;
             for (int i = 0; i < length; i++) {

java/src/com/android/inputmethod/research/ResearchLogger.java

@@ -377,7 +377,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             Log.d(TAG, "stop called");
         }
         logStatistics();
-        commitCurrentLogUnit();
+        commitCurrentLogUnit(SystemClock.uptimeMillis());
 
         if (mMainLogBuffer != null) {
             publishLogBuffer(mMainLogBuffer, mMainResearchLog, false /* isIncludingPrivateData */);
@@ -530,7 +530,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             return;
         }
         if (includeHistory) {
-            commitCurrentLogUnit();
+            commitCurrentLogUnit(SystemClock.uptimeMillis());
         } else {
             mFeedbackLogBuffer.clear();
         }
@@ -539,7 +539,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             feedbackContents
         };
         feedbackLogUnit.addLogStatement(EVENTKEYS_FEEDBACK, values,
-                false /* isPotentiallyPrivate */);
+                SystemClock.uptimeMillis(), false /* isPotentiallyPrivate */);
         mFeedbackLogBuffer.shiftIn(feedbackLogUnit);
         publishLogBuffer(mFeedbackLogBuffer, mFeedbackLog, true /* isIncludingPrivateData */);
         mFeedbackLog.close(new Runnable() {
@@ -641,12 +641,13 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             final Object[] values) {
         assert values.length + 1 == keys.length;
         if (isAllowedToLog()) {
-            mCurrentLogUnit.addLogStatement(keys, values, true /* isPotentiallyPrivate */);
+            final long time = SystemClock.uptimeMillis();
+            mCurrentLogUnit.addLogStatement(keys, values, time, true /* isPotentiallyPrivate */);
         }
     }
 
     private void setCurrentLogUnitContainsDigitFlag() {
-        mCurrentLogUnit.setContainsDigit();
+        mCurrentLogUnit.setMayContainDigit();
     }
 
     /**
@@ -664,16 +665,18 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
     private synchronized void enqueueEvent(final String[] keys, final Object[] values) {
         assert values.length + 1 == keys.length;
         if (isAllowedToLog()) {
-            mCurrentLogUnit.addLogStatement(keys, values, false /* isPotentiallyPrivate */);
+            final long time = SystemClock.uptimeMillis();
+            mCurrentLogUnit.addLogStatement(keys, values, time, false /* isPotentiallyPrivate */);
         }
     }
 
-    /* package for test */ void commitCurrentLogUnit() {
+    /* package for test */ void commitCurrentLogUnit(final long maxTime) {
         if (DEBUG) {
             Log.d(TAG, "commitCurrentLogUnit" + (mCurrentLogUnit.hasWord() ?
                     ": " + mCurrentLogUnit.getWord() : ""));
         }
         if (!mCurrentLogUnit.isEmpty()) {
+            final LogUnit newLogUnit = mCurrentLogUnit.splitByTime(maxTime);
             if (mMainLogBuffer != null) {
                 mMainLogBuffer.shiftIn(mCurrentLogUnit);
                 if (mMainLogBuffer.isSafeToLog() && mMainResearchLog != null) {
@@ -685,7 +688,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             if (mFeedbackLogBuffer != null) {
                 mFeedbackLogBuffer.shiftIn(mCurrentLogUnit);
             }
-            mCurrentLogUnit = new LogUnit();
+            mCurrentLogUnit = newLogUnit;
             Log.d(TAG, "commitCurrentLogUnit");
         }
     }
@@ -703,7 +706,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             isIncludingPrivateData
         };
         openingLogUnit.addLogStatement(EVENTKEYS_LOG_SEGMENT_START, values,
-                false /* isPotentiallyPrivate */);
+                SystemClock.uptimeMillis(), false /* isPotentiallyPrivate */);
         researchLog.publish(openingLogUnit, true /* isIncludingPrivateData */);
         LogUnit logUnit;
         while ((logUnit = logBuffer.shiftOut()) != null) {
@@ -711,7 +714,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
         }
         final LogUnit closingLogUnit = new LogUnit();
         closingLogUnit.addLogStatement(EVENTKEYS_LOG_SEGMENT_END, EVENTKEYS_NULLVALUES,
-                false /* isPotentiallyPrivate */);
+                SystemClock.uptimeMillis(), false /* isPotentiallyPrivate */);
         researchLog.publish(closingLogUnit, true /* isIncludingPrivateData */);
     }
 
@@ -726,13 +729,13 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
         return false;
     }
 
-    private void onWordComplete(final String word) {
+    private void onWordComplete(final String word, final long maxTime) {
         Log.d(TAG, "onWordComplete: " + word);
         if (word != null && word.length() > 0 && hasLetters(word)) {
             mCurrentLogUnit.setWord(word);
             mStatistics.recordWordEntered();
         }
-        commitCurrentLogUnit();
+        commitCurrentLogUnit(maxTime);
     }
 
     private static int scrubDigitFromCodePoint(int codePoint) {
@@ -943,7 +946,7 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
             }
             final ResearchLogger researchLogger = getInstance();
             researchLogger.enqueueEvent(EVENTKEYS_LATINIME_ONWINDOWHIDDEN, values);
-            researchLogger.commitCurrentLogUnit();
+            researchLogger.commitCurrentLogUnit(SystemClock.uptimeMillis());
             getInstance().stop();
         }
     }
@@ -1189,7 +1192,8 @@ public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChang
         final ResearchLogger researchLogger = getInstance();
         researchLogger.enqueuePotentiallyPrivateEvent(EVENTKEYS_RICHINPUTCONNECTION_COMMITTEXT,
                 values);
-        researchLogger.onWordComplete(scrubbedWord);
+        // TODO: Replace Long.MAX_VALUE with timestamp of last data to include
+        researchLogger.onWordComplete(scrubbedWord, Long.MAX_VALUE);
     }
 
     private static final String[] EVENTKEYS_RICHINPUTCONNECTION_DELETESURROUNDINGTEXT = {