Merge "Add parser to track the latency info printed from sysui"

4 files changed, 204 insertions, 57 deletions

diff --git a/src/com/android/loganalysis/item/LatencyItem.java b/src/com/android/loganalysis/item/LatencyItem.java
new file mode 100644
index 0000000..66b6b33
--- /dev/null
+++ b/src/com/android/loganalysis/item/LatencyItem.java
@@ -0,0 +1,43 @@
+package com.android.loganalysis.item;
+
+import java.util.Arrays;
+import java.util.HashSet;
+import java.util.Set;
+
+/**
+ * An {@link IItem} used to LatencyInfo.
+ */
+public class LatencyItem extends GenericItem {
+
+    /** Constant for JSON output */
+    public static final String ACTION_ID = "ACTION_ID";
+    /** Constant for JSON output */
+    public static final String DELAY = "DELAY";
+    /** Constant for JSON output */
+
+    private static final Set<String> ATTRIBUTES = new HashSet<String>(Arrays.asList(
+            ACTION_ID, DELAY));
+
+    /**
+     * The constructor for {@link LatencyItem}.
+     */
+    public LatencyItem() {
+        super(ATTRIBUTES);
+    }
+
+    public int getActionId() {
+        return (int) getAttribute(ACTION_ID);
+    }
+
+    public void setActionId(int actionId) {
+        setAttribute(ACTION_ID, actionId);
+    }
+
+    public long getDelay() {
+        return (long) getAttribute(DELAY);
+    }
+
+    public void setDelay(long delay) {
+        setAttribute(DELAY, delay);
+    }
+}
diff --git a/src/com/android/loganalysis/parser/EventsLogParser.java b/src/com/android/loganalysis/parser/EventsLogParser.java
index 068feeb..a15abf8 100644
--- a/src/com/android/loganalysis/parser/EventsLogParser.java
+++ b/src/com/android/loganalysis/parser/EventsLogParser.java
@@ -17,10 +17,11 @@
 package com.android.loganalysis.parser;
 
 import com.android.loganalysis.item.IItem;
+import com.android.loganalysis.item.LatencyItem;
 import com.android.loganalysis.item.TransitionDelayItem;
 
-import java.io.IOException;
 import java.io.BufferedReader;
+import java.io.IOException;
 import java.util.ArrayList;
 import java.util.List;
 import java.util.regex.Matcher;
@@ -31,24 +32,31 @@ import java.util.regex.Pattern;
  */
 public class EventsLogParser implements IParser {
 
+    // 08-21 17:53:53.876 1053 2135
+    private static final String EVENTS_PREFIX = "^\\d{2}-\\d{2} \\d{2}:\\d{2}"
+            + ":\\d{2}.\\d{3}\\s+\\d+\\s+\\d+ ";
     // 08-21 17:53:53.876 1053 2135 I am_restart_activity:
     // [0,188098346,127,com.google.android.gm/.ConversationListActivityGmail]
-    private static final Pattern ACTIVITY_RESTART = Pattern.compile("^\\d{2}-\\d{2} \\d{2}:\\d{2}"
-            + ":\\d{2}.\\d{3}\\s+\\d+\\s+\\d+ I am_restart_activity: "
-            + "\\[\\d+\\,\\d+\\,\\d+\\,(?<componentname>.*)\\]$");
-    // 08-21 17:57:15.363 1053 2095 I am_resume_activity:
+    private static final Pattern ACTIVITY_RESTART = Pattern.compile(
+            String.format("%s%s", EVENTS_PREFIX, "I am_restart_activity: "
+                    + "\\[\\d+\\,\\d+\\,\\d+\\,(?<componentname>.*)\\]$"));
+    // 08-21 17:53:53.876 1053 2135 I am_resume_activity:
     // [0,228277756,132,com.google.android.gm/.ConversationListActivityGmail]
-    private static final Pattern ACTIVITY_RESUME = Pattern.compile("^\\d{2}-\\d{2} \\d{2}:\\d{2}"
-            + ":\\d{2}.\\d{3}\\s+\\d+\\s+\\d+ I am_resume_activity: "
-            + "\\[\\d+\\,\\d+\\,\\d+\\,(?<componentname>.*)\\]$");
-    // 08-21 17:53:53.893 1053 1115 I sysui_action: [321,74]
-    private static final Pattern STARTING_WINDOW_DELAY = Pattern.compile("^\\d{2}-\\d{2} \\d{2}:"
-            + "\\d{2}:\\d{2}.\\d{3}\\s+\\d+\\s+\\d+ I sysui_action: \\[321,(?<startdelay>.*)\\]$");
-    // 08-21 17:54:16.672 1053 1115 I sysui_action: [319,99]
-    private static final Pattern TRANSITION_DELAY = Pattern
-            .compile("^\\d{2}-\\d{2} \\d{2}:"
-                    + "\\d{2}:\\d{2}.\\d{3}\\s+\\d+\\s+\\d+ I sysui_action: \\[319,"
-                    + "(?<transitdelay>.*)\\]$");
+    private static final Pattern ACTIVITY_RESUME = Pattern.compile(
+            String.format("%s%s", EVENTS_PREFIX, "I am_resume_activity: "
+                    + "\\[\\d+\\,\\d+\\,\\d+\\,(?<componentname>.*)\\]$"));
+    // 08-21 17:53:53.876 1053 2135 I sysui_action: [321,74]
+    private static final Pattern STARTING_WINDOW_DELAY = Pattern.compile(
+            String.format("%s%s", EVENTS_PREFIX, "I sysui_action: \\[321,"
+                    + "(?<startdelay>.*)\\]$"));
+    // 08-21 17:53:53.876 1053 2135 I sysui_action: [319,99]
+    private static final Pattern TRANSITION_DELAY = Pattern.compile(
+            String.format("%s%s", EVENTS_PREFIX, "I sysui_action: \\[319,"
+                    + "(?<transitdelay>.*)\\]$"));
+    // 08-21 17:53:53.876 1053 2135 I sysui_latency: [1,50]
+    private static final Pattern ACTION_LATENCY = Pattern.compile(
+            String.format("%s%s", EVENTS_PREFIX, "I sysui_latency: \\[(?<action>.*),"
+                    + "(?<delay>.*)\\]$"));
 
     @Override
     public IItem parse(List<String> lines) {
@@ -71,7 +79,7 @@ public class EventsLogParser implements IParser {
         boolean isRecentStartWindowDelay = false;
         while ((line = input.readLine()) != null) {
             Matcher match = null;
-            if (((match = matches(ACTIVITY_RESTART, line))) != null ||
+            if ((match = matches(ACTIVITY_RESTART, line)) != null ||
                     ((match = matches(ACTIVITY_RESUME, line)) != null)) {
                 componentNameStack.add(match.group("componentname"));
                 isRecentStartWindowDelay = false;
@@ -98,6 +106,28 @@ public class EventsLogParser implements IParser {
     }
 
     /**
+     * Method to parse the latency information from the events log
+     *
+     * @param input
+     * @return
+     * @throws IOException
+     */
+    public List<LatencyItem> parseLatencyInfo(BufferedReader input) throws IOException {
+        List<LatencyItem> latencyItems = new ArrayList<LatencyItem>();
+        String line;
+        while ((line = input.readLine()) != null) {
+            Matcher match = null;
+            if (((match = matches(ACTION_LATENCY, line))) != null) {
+                LatencyItem latencyItem = new LatencyItem();
+                latencyItem.setActionId(Integer.parseInt(match.group("action")));
+                latencyItem.setDelay(Long.parseLong(match.group("delay")));
+                latencyItems.add(latencyItem);
+            }
+        }
+        return latencyItems;
+    }
+
+    /**
      * Checks whether {@code line} matches the given {@link Pattern}.
      *
      * @return The resulting {@link Matcher} obtained by matching the {@code line} against
diff --git a/tests/src/com/android/loganalysis/UnitTests.java b/tests/src/com/android/loganalysis/UnitTests.java
index 638c2f7..ac890e2 100644
--- a/tests/src/com/android/loganalysis/UnitTests.java
+++ b/tests/src/com/android/loganalysis/UnitTests.java
@@ -30,6 +30,7 @@ import com.android.loganalysis.parser.AbstractSectionParserTest;
 import com.android.loganalysis.parser.AnrParserTest;
 import com.android.loganalysis.parser.BugreportParserTest;
 import com.android.loganalysis.parser.CompactMemInfoParserTest;
+import com.android.loganalysis.parser.EventsLogParserTest;
 import com.android.loganalysis.parser.InterruptParserTest;
 import com.android.loganalysis.parser.JavaCrashParserTest;
 import com.android.loganalysis.parser.KernelLogParserTest;
@@ -81,6 +82,7 @@ public class UnitTests extends TestSuite {
         addTestSuite(AnrParserTest.class);
         addTestSuite(BugreportParserTest.class);
         addTestSuite(CompactMemInfoParserTest.class);
+        addTestSuite(EventsLogParserTest.class);
         addTestSuite(InterruptParserTest.class);
         addTestSuite(JavaCrashParserTest.class);
         addTestSuite(KernelLogParserTest.class);
diff --git a/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java b/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java
index 092473e..735ae8a 100644
--- a/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java
+++ b/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java
@@ -16,16 +16,16 @@
 
 package com.android.loganalysis.parser;
 
+import com.android.loganalysis.item.LatencyItem;
 import com.android.loganalysis.item.TransitionDelayItem;
-import com.android.loganalysis.parser.EventsLogParser;
 
-import java.io.BufferedWriter;
 import java.io.BufferedReader;
+import java.io.BufferedWriter;
 import java.io.File;
-import java.io.FileWriter;
 import java.io.FileInputStream;
-import java.io.InputStreamReader;
+import java.io.FileWriter;
 import java.io.IOException;
+import java.io.InputStreamReader;
 import java.util.Arrays;
 import java.util.List;
 
@@ -45,7 +45,7 @@ public class EventsLogParserTest extends TestCase {
         List<String> lines = Arrays.asList("");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list should be empty", transitionItems.size() == 0);
+        assertEquals("Transition Delay items list should be empty", 0,transitionItems.size());
     }
 
     /**
@@ -61,28 +61,30 @@ public class EventsLogParserTest extends TestCase {
                         "08-25 12:56:15.852  1152  8968 I wm_stack_removed: 1");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list should be empty", transitionItems.size() == 0);
+        assertEquals("Transition Delay items list should be empty", 0,
+                transitionItems.size());
     }
 
     /**
      * Test for Cold launch transition delay info
      */
     public void testColdLaunchTransitionDelay() throws IOException {
-        List<String> lines = Arrays.asList("08-25 13:01:19.412  1152  9031 I am_restart_activity: [0,85290699,38,com.google.android.gm/.ConversationListActivityGmail]",
+        List<String> lines = Arrays
+                .asList("08-25 13:01:19.412  1152  9031 I am_restart_activity: [0,85290699,38,com.google.android.gm/.ConversationListActivityGmail]",
                         "08-25 13:01:19.437  1152  1226 I sysui_action: [321,85]",
                         "08-25 13:01:19.437  1152  1226 I sysui_action: [320,1]",
                         "08-25 13:01:19.437  1152  1226 I sysui_action: [319,85]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list should have one item",
-                transitionItems.size() == 1);
-        assertTrue("Component name not parsed correctly",
-                transitionItems.get(0).getComponentName().equals(
-                        "com.google.android.gm/.ConversationListActivityGmail"));
-        assertTrue("Cold launch info is not set correctly",
-                transitionItems.get(0).getStartingWindowDelay() == 85);
-        assertTrue("Hot launch info is set which is not expected",
-                transitionItems.get(0).getTransitionDelay() == -1);
+        assertEquals("Transition Delay items list should have one item", 1,
+                transitionItems.size());
+        assertEquals("Component name not parsed correctly",
+                "com.google.android.gm/.ConversationListActivityGmail",
+                transitionItems.get(0).getComponentName());
+        assertEquals("Cold launch info is not set correctly", 85,
+                transitionItems.get(0).getStartingWindowDelay());
+        assertEquals("Hot launch info is set which is not expected", -1,
+                transitionItems.get(0).getTransitionDelay());
     }
 
     /**
@@ -96,15 +98,15 @@ public class EventsLogParserTest extends TestCase {
                         "08-25 13:02:04.755  1152  1226 I sysui_action: [319,37]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list shopuld have one item",
-                transitionItems.size() == 1);
-        assertTrue("Component name not parsed correctly",
-                transitionItems.get(0).getComponentName().equals(
-                        "com.google.android.gm/.ConversationListActivityGmail"));
-        assertTrue("Cold launch info is set which is not expected",
-                transitionItems.get(0).getStartingWindowDelay() == -1);
-        assertTrue("Hot launch info is not set correctly",
-                transitionItems.get(0).getTransitionDelay() == 37);
+        assertEquals("Transition Delay items list shopuld have one item", 1,
+                transitionItems.size());
+        assertEquals("Component name not parsed correctly",
+                "com.google.android.gm/.ConversationListActivityGmail",
+                transitionItems.get(0).getComponentName());
+        assertEquals("Cold launch info is set which is not expected", -1,
+                transitionItems.get(0).getStartingWindowDelay());
+        assertEquals("Hot launch info is not set correctly", 37,
+                transitionItems.get(0).getTransitionDelay());
     }
 
     /**
@@ -127,12 +129,12 @@ public class EventsLogParserTest extends TestCase {
                         "08-25 13:02:04.755  1152  1226 I sysui_action: [319,37]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list should have two items",
-                transitionItems.size() == 2);
-        assertTrue("Cold launch transition delay is not the first item",
-                (transitionItems.get(0).getStartingWindowDelay() == 85));
-        assertTrue("Hot launch transition delay is not the second item",
-                (transitionItems.get(1).getTransitionDelay() == 37));
+        assertEquals("Transition Delay items list should have two items", 2,
+                transitionItems.size());
+        assertEquals("Cold launch transition delay is not the first item", 85,
+                transitionItems.get(0).getStartingWindowDelay());
+        assertEquals("Hot launch transition delay is not the second item", 37,
+                transitionItems.get(1).getTransitionDelay());
     }
 
     /**
@@ -157,14 +159,14 @@ public class EventsLogParserTest extends TestCase {
                         "08-25 13:03:35.569  1152  1226 I sysui_action: [319,92]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list should have two items",
-                transitionItems.size() == 2);
-        assertTrue("Gmail is not the first transition delay item",
-                transitionItems.get(0).getComponentName().equals(
-                        "com.google.android.gm/.ConversationListActivityGmail"));
-        assertTrue("Maps is not the second transition delay item",
-                transitionItems.get(1).getComponentName().equals(
-                        "com.google.android.apps.maps/com.google.android.maps.MapsActivity"));
+        assertEquals("Transition Delay items list should have two items", 2,
+                transitionItems.size());
+        assertEquals("Gmail is not the first transition delay item",
+                "com.google.android.gm/.ConversationListActivityGmail",
+                transitionItems.get(0).getComponentName());
+        assertEquals("Maps is not the second transition delay item",
+                "com.google.android.apps.maps/com.google.android.maps.MapsActivity",
+                transitionItems.get(1).getComponentName());
     }
 
     /**
@@ -187,7 +189,77 @@ public class EventsLogParserTest extends TestCase {
                         "08-25 13:02:04.755  1152  1226 I sysui_action: [319,37]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertTrue("Transition Delay items list should be empty", transitionItems.size() == 0);
+        assertEquals("Transition Delay items list should be empty", 0,
+                transitionItems.size());
+    }
+
+    /**
+     * Test for valid latency item
+     */
+    public void testValidLatencyInfo() throws IOException {
+        List<String> lines = Arrays
+                .asList("08-25 13:01:19.412  1152  9031 I am_restart_activity: [com.google.android.gm/.ConversationListActivityGmail,0,85290699,38]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [321,85]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [320,1]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [319,85]",
+                        "08-25 12:56:15.850  1152  8968 I am_focused_stack: [0,0,1,appDied setFocusedActivity]",
+                        "09-19 11:53:16.893  1080  1160 I sysui_latency: [1,50]");
+        List<LatencyItem> latencyItems = (new EventsLogParser()).
+                parseLatencyInfo(readInputBuffer(getTempFile(lines)));
+        assertEquals("One latency item should present in the list", 1, latencyItems.size());
+        assertEquals("Action Id is not correct", 1, latencyItems.get(0).getActionId());
+        assertEquals("Delay is not correct", 50L, latencyItems.get(0).getDelay());
+    }
+
+    /**
+     * Test for empty delay info
+     */
+    public void testInvalidLatencyInfo() throws IOException {
+        List<String> lines = Arrays
+                .asList("08-25 13:01:19.412  1152  9031 I am_restart_activity: [com.google.android.gm/.ConversationListActivityGmail,0,85290699,38]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [321,85]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [320,1]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [319,85]",
+                        "08-25 12:56:15.850  1152  8968 I am_focused_stack: [0,0,1,appDied setFocusedActivity]",
+                        "09-19 11:53:16.893  1080  1160 I sysui_latency: [1]");
+        List<LatencyItem> latencyItems = (new EventsLogParser()).
+                parseLatencyInfo(readInputBuffer(getTempFile(lines)));
+        assertEquals("Latency items list should be empty", 0, latencyItems.size());
+    }
+
+    /**
+     * Test for empty latency info
+     */
+    public void testEmptyLatencyInfo() throws IOException {
+        List<String> lines = Arrays
+                .asList("08-25 13:01:19.412  1152  9031 I am_restart_activity: [com.google.android.gm/.ConversationListActivityGmail,0,85290699,38]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [321,85]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [320,1]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [319,85]",
+                        "08-25 12:56:15.850  1152  8968 I am_focused_stack: [0,0,1,appDied setFocusedActivity]",
+                        "09-19 11:53:16.893  1080  1160 I sysui_latency: []");
+        List<LatencyItem> latencyItems = (new EventsLogParser()).
+                parseLatencyInfo(readInputBuffer(getTempFile(lines)));
+        assertEquals("Latency items list should be empty", 0, latencyItems.size());
+    }
+
+
+    /**
+     * Test for order of the latency items
+     */
+    public void testLatencyInfoOrder() throws IOException {
+        List<String> lines = Arrays
+                .asList("09-19 11:53:16.893  1080  1160 I sysui_latency: [1,50]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [321,85]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [320,1]",
+                        "08-25 13:01:19.437  1152  1226 I sysui_action: [319,85]",
+                        "08-25 12:56:15.850  1152  8968 I am_focused_stack: [0,0,1,appDied setFocusedActivity]",
+                        "09-19 11:53:16.893  1080  1160 I sysui_latency: [2,100]");
+        List<LatencyItem> latencyItems = (new EventsLogParser()).
+                parseLatencyInfo(readInputBuffer(getTempFile(lines)));
+        assertEquals("Latency list should have 2 items", 2, latencyItems.size());
+        assertEquals("First latency id is not 1", 1, latencyItems.get(0).getActionId());
+        assertEquals("Second latency id is not 2", 2, latencyItems.get(1).getActionId());
     }
 
     /**