From d05afa3f4c59641c8fabed034e457cb25f0c57f0 Mon Sep 17 00:00:00 2001 From: Kurt Partridge Date: Thu, 22 Mar 2012 11:13:33 +0900 Subject: [PATCH] move usability log code to new class (ResearchLogger) and clean api This change also undoes the effects of I8694eb9016, which was an initial effort built on Utils.UsabilityStudyLogs. Now Utils operates as it did previously, for backward compatibility, but the ResearchLogger retains the new log format. Coordinated with I274b75c5. Bug: 6188932 Change-Id: I41208bdc6b511f69a010c9fc38a936521beba7d5 --- .../keyboard/LatinKeyboardView.java | 63 +++- .../android/inputmethod/latin/LatinIME.java | 5 +- .../inputmethod/latin/ResearchLogger.java | 302 ++++++++++++++++++ .../com/android/inputmethod/latin/Utils.java | 82 ++--- 4 files changed, 379 insertions(+), 73 deletions(-) create mode 100644 java/src/com/android/inputmethod/latin/ResearchLogger.java diff --git a/java/src/com/android/inputmethod/keyboard/LatinKeyboardView.java b/java/src/com/android/inputmethod/keyboard/LatinKeyboardView.java index b66d1661d..3f6c37477 100644 --- a/java/src/com/android/inputmethod/keyboard/LatinKeyboardView.java +++ b/java/src/com/android/inputmethod/keyboard/LatinKeyboardView.java @@ -46,6 +46,7 @@ import com.android.inputmethod.keyboard.internal.KeySpecParser; import com.android.inputmethod.latin.LatinIME; import com.android.inputmethod.latin.LatinImeLogger; import com.android.inputmethod.latin.R; +import com.android.inputmethod.latin.ResearchLogger; import com.android.inputmethod.latin.StaticInnerHandlerWrapper; import com.android.inputmethod.latin.StringUtils; import com.android.inputmethod.latin.SubtypeUtils; @@ -66,6 +67,9 @@ public class LatinKeyboardView extends KeyboardView implements PointerTracker.Ke SuddenJumpingTouchEventHandler.ProcessMotionEvent { private static final String TAG = LatinKeyboardView.class.getSimpleName(); + // TODO: Kill process when the usability study mode was changed. + private static final boolean ENABLE_USABILITY_STUDY_LOG = LatinImeLogger.sUsabilityStudy; + /** Listener for {@link KeyboardActionListener}. */ private KeyboardActionListener mKeyboardActionListener; @@ -653,8 +657,6 @@ public class LatinKeyboardView extends KeyboardView implements PointerTracker.Ke final int index = me.getActionIndex(); final int id = me.getPointerId(index); final int x, y; - final float size = me.getSize(index); - final float pressure = me.getPressure(index); if (mMoreKeysPanel != null && id == mMoreKeysPanelPointerTrackerId) { x = mMoreKeysPanel.translateX((int)me.getX(index)); y = mMoreKeysPanel.translateY((int)me.getY(index)); @@ -662,10 +664,44 @@ public class LatinKeyboardView extends KeyboardView implements PointerTracker.Ke x = (int)me.getX(index); y = (int)me.getY(index); } - if (LatinImeLogger.sUsabilityStudy) { + if (ENABLE_USABILITY_STUDY_LOG) { + final String eventTag; + switch (action) { + case MotionEvent.ACTION_UP: + eventTag = "[Up]"; + break; + case MotionEvent.ACTION_DOWN: + eventTag = "[Down]"; + break; + case MotionEvent.ACTION_POINTER_UP: + eventTag = "[PointerUp]"; + break; + case MotionEvent.ACTION_POINTER_DOWN: + eventTag = "[PointerDown]"; + break; + case MotionEvent.ACTION_MOVE: // Skip this as being logged below + eventTag = ""; + break; + default: + eventTag = "[Action" + action + "]"; + break; + } + if (!TextUtils.isEmpty(eventTag)) { + final float size = me.getSize(index); + final float pressure = me.getPressure(index); + UsabilityStudyLogUtils.getInstance().write( + eventTag + eventTime + "," + id + "," + x + "," + y + "," + + size + "," + pressure); + } + } + if (ResearchLogger.sIsLogging) { + // TODO: remove redundant calculations of size and pressure by + // removing UsabilityStudyLog code once the ResearchLogger is mature enough + final float size = me.getSize(index); + final float pressure = me.getPressure(index); if (action != MotionEvent.ACTION_MOVE) { // Skip ACTION_MOVE events as they are logged below - UsabilityStudyLogUtils.getInstance().writeMotionEvent(action, eventTime, id, x, + ResearchLogger.getInstance().logMotionEvent(action, eventTime, id, x, y, size, pressure); } } @@ -714,8 +750,9 @@ public class LatinKeyboardView extends KeyboardView implements PointerTracker.Ke if (action == MotionEvent.ACTION_MOVE) { for (int i = 0; i < pointerCount; i++) { + final int pointerId = me.getPointerId(i); final PointerTracker tracker = PointerTracker.getPointerTracker( - me.getPointerId(i), this); + pointerId, this); final int px, py; if (mMoreKeysPanel != null && tracker.mPointerId == mMoreKeysPanelPointerTrackerId) { @@ -726,9 +763,19 @@ public class LatinKeyboardView extends KeyboardView implements PointerTracker.Ke py = (int)me.getY(i); } tracker.onMoveEvent(px, py, eventTime); - if (LatinImeLogger.sUsabilityStudy) { - UsabilityStudyLogUtils.getInstance().writeMotionEvent(action, eventTime, id, - px, py, size, pressure); + if (ENABLE_USABILITY_STUDY_LOG) { + final float pointerSize = me.getSize(i); + final float pointerPressure = me.getPressure(i); + UsabilityStudyLogUtils.getInstance().write("[Move]" + eventTime + "," + + pointerId + "," + px + "," + py + "," + + pointerSize + "," + pointerPressure); + } + if (ResearchLogger.sIsLogging) { + // TODO: earlier comment about redundant calculations applies here too + final float pointerSize = me.getSize(i); + final float pointerPressure = me.getPressure(i); + ResearchLogger.getInstance().logMotionEvent(action, eventTime, pointerId, + px, py, pointerSize, pointerPressure); } } } else { diff --git a/java/src/com/android/inputmethod/latin/LatinIME.java b/java/src/com/android/inputmethod/latin/LatinIME.java index 175d953a6..f5fe8663e 100644 --- a/java/src/com/android/inputmethod/latin/LatinIME.java +++ b/java/src/com/android/inputmethod/latin/LatinIME.java @@ -439,6 +439,7 @@ public class LatinIME extends InputMethodServiceCompatWrapper implements Keyboar final SharedPreferences prefs = PreferenceManager.getDefaultSharedPreferences(this); mPrefs = prefs; LatinImeLogger.init(this, prefs); + ResearchLogger.init(this, prefs); LanguageSwitcherProxy.init(this, prefs); InputMethodManagerCompatWrapper.init(this); SubtypeSwitcher.init(this); @@ -1263,8 +1264,8 @@ public class LatinIME extends InputMethodServiceCompatWrapper implements Keyboar } mLastKeyTime = when; - if (LatinImeLogger.sUsabilityStudy) { - UsabilityStudyLogUtils.getInstance().writeKeyEvent(primaryCode, x, y); + if (ResearchLogger.sIsLogging) { + ResearchLogger.getInstance().logKeyEvent(primaryCode, x, y); } final KeyboardSwitcher switcher = mKeyboardSwitcher; diff --git a/java/src/com/android/inputmethod/latin/ResearchLogger.java b/java/src/com/android/inputmethod/latin/ResearchLogger.java new file mode 100644 index 000000000..509fbe0fd --- /dev/null +++ b/java/src/com/android/inputmethod/latin/ResearchLogger.java @@ -0,0 +1,302 @@ +/* + * Copyright (C) 2012 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.inputmethod.latin; + +import android.content.SharedPreferences; +import android.inputmethodservice.InputMethodService; +import android.os.Handler; +import android.os.HandlerThread; +import android.os.Process; +import android.text.TextUtils; +import android.util.Log; +import android.view.MotionEvent; + +import com.android.inputmethod.keyboard.Keyboard; + +import java.io.File; +import java.io.FileNotFoundException; +import java.io.FileOutputStream; +import java.io.PrintWriter; +import java.text.SimpleDateFormat; +import java.util.Date; + +/** + * Logs the use of the LatinIME keyboard. + * + * This class logs operations on the IME keyboard, including what the user has typed. + * Data is stored locally in a file in app-specific storage. + * + * This functionality is off by default. + */ +public class ResearchLogger implements SharedPreferences.OnSharedPreferenceChangeListener { + private static final String TAG = ResearchLogger.class.getSimpleName(); + private static final String PREF_USABILITY_STUDY_MODE = "usability_study_mode"; + + private static final ResearchLogger sInstance = new ResearchLogger(new LogFileManager()); + public static boolean sIsLogging = false; + private final Handler mLoggingHandler; + private InputMethodService mIms; + private final Date mDate; + private final SimpleDateFormat mDateFormat; + + /** + * Isolates management of files. This variable should never be null, but can be changed + * to support testing. + */ + private LogFileManager mLogFileManager; + + /** + * Manages the file(s) that stores the logs. + * + * Handles creation, deletion, and provides Readers, Writers, and InputStreams to access + * the logs. + */ + public static class LogFileManager { + private static final String DEFAULT_FILENAME = "log.txt"; + private static final String DEFAULT_LOG_DIRECTORY = "researchLogger"; + + private static final long LOGFILE_PURGE_INTERVAL = 1000 * 60 * 60 * 24; + + private InputMethodService mIms; + private File mFile; + private PrintWriter mPrintWriter; + + /* package */ LogFileManager() { + } + + public void init(InputMethodService ims) { + mIms = ims; + } + + public synchronized void createLogFile() { + try { + createLogFile(DEFAULT_LOG_DIRECTORY, DEFAULT_FILENAME); + } catch (FileNotFoundException e) { + Log.w(TAG, e); + } + } + + public synchronized void createLogFile(String dir, String filename) + throws FileNotFoundException { + if (mIms == null) { + Log.w(TAG, "InputMethodService is not configured. Logging is off."); + return; + } + File filesDir = mIms.getFilesDir(); + if (filesDir == null || !filesDir.exists()) { + Log.w(TAG, "Storage directory does not exist. Logging is off."); + return; + } + File directory = new File(filesDir, dir); + if (!directory.exists()) { + boolean wasCreated = directory.mkdirs(); + if (!wasCreated) { + Log.w(TAG, "Log directory cannot be created. Logging is off."); + return; + } + } + + close(); + mFile = new File(directory, filename); + boolean append = true; + if (mFile.exists() && mFile.lastModified() + LOGFILE_PURGE_INTERVAL < + System.currentTimeMillis()) { + append = false; + } + mPrintWriter = new PrintWriter(new FileOutputStream(mFile, append), true); + } + + public synchronized boolean append(String s) { + if (mPrintWriter == null) { + Log.w(TAG, "PrintWriter is null"); + return false; + } else { + mPrintWriter.print(s); + return !mPrintWriter.checkError(); + } + } + + public synchronized void reset() { + if (mPrintWriter != null) { + mPrintWriter.close(); + mPrintWriter = null; + } + if (mFile != null && mFile.exists()) { + mFile.delete(); + mFile = null; + } + } + + public synchronized void close() { + if (mPrintWriter != null) { + mPrintWriter.close(); + mPrintWriter = null; + mFile = null; + } + } + } + + private ResearchLogger(LogFileManager logFileManager) { + mDate = new Date(); + mDateFormat = new SimpleDateFormat("yyyyMMdd-HHmmss.SSSZ"); + + HandlerThread handlerThread = new HandlerThread("ResearchLogger logging task", + Process.THREAD_PRIORITY_BACKGROUND); + handlerThread.start(); + mLoggingHandler = new Handler(handlerThread.getLooper()); + mLogFileManager = logFileManager; + } + + public static ResearchLogger getInstance() { + return sInstance; + } + + public static void init(InputMethodService ims, SharedPreferences prefs) { + sInstance.initInternal(ims, prefs); + } + + public void initInternal(InputMethodService ims, SharedPreferences prefs) { + mIms = ims; + if (mLogFileManager != null) { + mLogFileManager.init(ims); + mLogFileManager.createLogFile(); + } + if (prefs != null) { + sIsLogging = prefs.getBoolean(PREF_USABILITY_STUDY_MODE, false); + } + prefs.registerOnSharedPreferenceChangeListener(this); + } + + /** + * Change to a different logFileManager. Will not allow it to be set to null. + */ + /* package */ void setLogFileManager(ResearchLogger.LogFileManager manager) { + if (manager == null) { + Log.w(TAG, "warning: trying to set null logFileManager. ignoring."); + } else { + mLogFileManager = manager; + } + } + + /** + * Represents a category of logging events that share the same subfield structure. + */ + private static enum LogGroup { + MOTION_EVENT("m"), + KEY("k"), + CORRECTION("c"), + STATE_CHANGE("s"); + + private final String mLogString; + + private LogGroup(String logString) { + mLogString = logString; + } + } + + public void logMotionEvent(final int action, final long eventTime, final int id, + final int x, final int y, final float size, final float pressure) { + final String eventTag; + switch (action) { + case MotionEvent.ACTION_CANCEL: eventTag = "[Cancel]"; break; + case MotionEvent.ACTION_UP: eventTag = "[Up]"; break; + case MotionEvent.ACTION_DOWN: eventTag = "[Down]"; break; + case MotionEvent.ACTION_POINTER_UP: eventTag = "[PointerUp]"; break; + case MotionEvent.ACTION_POINTER_DOWN: eventTag = "[PointerDown]"; break; + case MotionEvent.ACTION_MOVE: eventTag = "[Move]"; break; + case MotionEvent.ACTION_OUTSIDE: eventTag = "[Outside]"; break; + default: eventTag = "[Action" + action + "]"; break; + } + if (!TextUtils.isEmpty(eventTag)) { + StringBuilder sb = new StringBuilder(); + sb.append(eventTag); + sb.append('\t'); sb.append(eventTime); + sb.append('\t'); sb.append(id); + sb.append('\t'); sb.append(x); + sb.append('\t'); sb.append(y); + sb.append('\t'); sb.append(size); + sb.append('\t'); sb.append(pressure); + write(LogGroup.MOTION_EVENT, sb.toString()); + } + } + + public void logKeyEvent(int code, int x, int y) { + final StringBuilder sb = new StringBuilder(); + sb.append(Keyboard.printableCode(code)); + sb.append('\t'); sb.append(x); + sb.append('\t'); sb.append(y); + write(LogGroup.KEY, sb.toString()); + + LatinImeLogger.onPrintAllUsabilityStudyLogs(); + } + + public void logCorrection(String subgroup, String before, String after, int position) { + final StringBuilder sb = new StringBuilder(); + sb.append(subgroup); + sb.append('\t'); sb.append(before); + sb.append('\t'); sb.append(after); + sb.append('\t'); sb.append(position); + write(LogGroup.CORRECTION, sb.toString()); + } + + public void logStateChange(String subgroup, String details) { + write(LogGroup.STATE_CHANGE, subgroup + "\t" + details); + } + + private void write(final LogGroup logGroup, final String log) { + mLoggingHandler.post(new Runnable() { + @Override + public void run() { + final long currentTime = System.currentTimeMillis(); + mDate.setTime(currentTime); + + final String printString = String.format("%s\t%d\t%s\t%s\n", + mDateFormat.format(mDate), currentTime, logGroup.mLogString, log); + if (LatinImeLogger.sDBG) { + Log.d(TAG, "Write: " + '[' + logGroup.mLogString + ']' + log); + } + if (mLogFileManager.append(printString)) { + // success + } else { + if (LatinImeLogger.sDBG) { + Log.w(TAG, "Unable to write to log."); + } + } + } + }); + } + + public void clearAll() { + mLoggingHandler.post(new Runnable() { + @Override + public void run() { + if (LatinImeLogger.sDBG) { + Log.d(TAG, "Delete log file."); + } + mLogFileManager.reset(); + } + }); + } + + @Override + public void onSharedPreferenceChanged(SharedPreferences prefs, String key) { + if (key == null || prefs == null) { + return; + } + sIsLogging = prefs.getBoolean(PREF_USABILITY_STUDY_MODE, false); + } +} diff --git a/java/src/com/android/inputmethod/latin/Utils.java b/java/src/com/android/inputmethod/latin/Utils.java index a3589da0a..be64c2fd8 100644 --- a/java/src/com/android/inputmethod/latin/Utils.java +++ b/java/src/com/android/inputmethod/latin/Utils.java @@ -220,6 +220,7 @@ public class Utils { } public static class UsabilityStudyLogUtils { + // TODO: remove code duplication with ResearchLog class private static final String USABILITY_TAG = UsabilityStudyLogUtils.class.getSimpleName(); private static final String FILENAME = "log.txt"; private static final UsabilityStudyLogUtils sInstance = @@ -262,73 +263,28 @@ public class Utils { } } - /** - * Represents a category of logging events that share the same subfield structure. - */ - public static enum LogGroup { - MOTION_EVENT("m"), - KEY("k"), - CORRECTION("c"), - STATE_CHANGE("s"); - - private final String mLogString; - - private LogGroup(String logString) { - mLogString = logString; - } + public static void writeBackSpace(int x, int y) { + UsabilityStudyLogUtils.getInstance().write("\t" + x + "\t" + y); } - public void writeMotionEvent(final int action, final long eventTime, final int id, - final int x, final int y, final float size, final float pressure) { - final String eventTag; - switch (action) { - case MotionEvent.ACTION_CANCEL: eventTag = "[Cancel]"; break; - case MotionEvent.ACTION_UP: eventTag = "[Up]"; break; - case MotionEvent.ACTION_DOWN: eventTag = "[Down]"; break; - case MotionEvent.ACTION_POINTER_UP: eventTag = "[PointerUp]"; break; - case MotionEvent.ACTION_POINTER_DOWN: eventTag = "[PointerDown]"; break; - case MotionEvent.ACTION_MOVE: eventTag = "[Move]"; break; - case MotionEvent.ACTION_OUTSIDE: eventTag = "[Outside]"; break; - default: eventTag = "[Action" + action + "]"; break; + public void writeChar(char c, int x, int y) { + String inputChar = String.valueOf(c); + switch (c) { + case '\n': + inputChar = ""; + break; + case '\t': + inputChar = ""; + break; + case ' ': + inputChar = ""; + break; } - if (!TextUtils.isEmpty(eventTag)) { - StringBuilder sb = new StringBuilder(); - sb.append(eventTag); - sb.append('\t'); sb.append(eventTime); - sb.append('\t'); sb.append(id); - sb.append('\t'); sb.append(x); - sb.append('\t'); sb.append(y); - sb.append('\t'); sb.append(size); - sb.append('\t'); sb.append(pressure); - write(LogGroup.MOTION_EVENT, sb.toString()); - } - } - - public void writeKeyEvent(int code, int x, int y) { - final StringBuilder sb = new StringBuilder(); - sb.append(Keyboard.printableCode(code)); - sb.append('\t'); sb.append(x); - sb.append('\t'); sb.append(y); - write(LogGroup.KEY, sb.toString()); - - // TODO: replace with a cleaner flush+retrieve mechanism + UsabilityStudyLogUtils.getInstance().write(inputChar + "\t" + x + "\t" + y); LatinImeLogger.onPrintAllUsabilityStudyLogs(); } - public void writeCorrection(String subgroup, String before, String after, int position) { - final StringBuilder sb = new StringBuilder(); - sb.append(subgroup); - sb.append('\t'); sb.append(before); - sb.append('\t'); sb.append(after); - sb.append('\t'); sb.append(position); - write(LogGroup.CORRECTION, sb.toString()); - } - - public void writeStateChange(String subgroup, String details) { - write(LogGroup.STATE_CHANGE, subgroup + "\t" + details); - } - - private void write(final LogGroup logGroup, final String log) { + public void write(final String log) { mLoggingHandler.post(new Runnable() { @Override public void run() { @@ -336,8 +292,8 @@ public class Utils { final long currentTime = System.currentTimeMillis(); mDate.setTime(currentTime); - final String printString = String.format("%s\t%d\t%s\t%s\n", - mDateFormat.format(mDate), currentTime, logGroup.mLogString, log); + final String printString = String.format("%s\t%d\t%s\n", + mDateFormat.format(mDate), currentTime, log); if (LatinImeLogger.sDBG) { Log.d(USABILITY_TAG, "Write: " + log); }