Fix AppTransition parser.

Log format has changed recently for cold launch and hot launch.
Change parser to handle the new format and improve the existing
test cases.

Bug : b/62423763
Tests : OK (11 tests)

Change-Id: I6a34b7215778004d09d9dd14ff9cafc0ed30c885

3 files changed, 112 insertions, 77 deletions

diff --git a/src/com/android/loganalysis/item/TransitionDelayItem.java b/src/com/android/loganalysis/item/TransitionDelayItem.java
index 33a1b93..b91f926 100644
--- a/src/com/android/loganalysis/item/TransitionDelayItem.java
+++ b/src/com/android/loganalysis/item/TransitionDelayItem.java
@@ -30,9 +30,11 @@ public class TransitionDelayItem extends GenericItem {
     public static final String START_WINDOW_DELAY = "START_WINDOW_DELAY";
     /** Constant for JSON output */
     public static final String TRANSITION_DELAY = "TRANSITION_DELAY";
+    /** Constant for JSON output */
+    public static final String DATE_TIME = "DATE_TIME";
 
     private static final Set<String> ATTRIBUTES = new HashSet<String>(Arrays.asList(
-            COMPONENT_NAME, START_WINDOW_DELAY, TRANSITION_DELAY));
+            COMPONENT_NAME, START_WINDOW_DELAY, TRANSITION_DELAY, DATE_TIME));
 
     /**
      * The constructor for {@link TransitionDelayItem}.
@@ -49,20 +51,32 @@ public class TransitionDelayItem extends GenericItem {
         setAttribute(COMPONENT_NAME, componentName);
     }
 
-    public long getStartingWindowDelay() {
-        return (long) getAttribute(START_WINDOW_DELAY);
+    public Long getStartingWindowDelay() {
+        return getAttribute(START_WINDOW_DELAY) != null ? (Long) getAttribute(START_WINDOW_DELAY)
+                : null;
     }
 
     public void setStartingWindowDelay(long startingWindowDelay) {
         setAttribute(START_WINDOW_DELAY, startingWindowDelay);
     }
 
-    public long getTransitionDelay() {
-        return (long) getAttribute(TRANSITION_DELAY);
+    public Long getTransitionDelay() {
+        return (Long) getAttribute(TRANSITION_DELAY);
     }
 
     public void setTransitionDelay(long transitionDelay) {
         setAttribute(TRANSITION_DELAY, transitionDelay);
     }
 
+    /**
+     * @return date and time (MM-DD HH:MM:SS.mmm) in string format parsed from events log
+     *         and used in AUPT test.
+     */
+    public String getDateTime() {
+        return (String) getAttribute(DATE_TIME);
+    }
+
+    public void setDateTime(String dateTime) {
+        setAttribute(DATE_TIME, dateTime);
+    }
 }
diff --git a/src/com/android/loganalysis/parser/EventsLogParser.java b/src/com/android/loganalysis/parser/EventsLogParser.java
index c150df8..b69948d 100644
--- a/src/com/android/loganalysis/parser/EventsLogParser.java
+++ b/src/com/android/loganalysis/parser/EventsLogParser.java
@@ -23,7 +23,9 @@ import com.android.loganalysis.item.TransitionDelayItem;
 import java.io.BufferedReader;
 import java.io.IOException;
 import java.util.ArrayList;
+import java.util.HashMap;
 import java.util.List;
+import java.util.Map;
 import java.util.regex.Matcher;
 import java.util.regex.Pattern;
 
@@ -32,28 +34,26 @@ 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+ ";
-
-    // 01-01 01:38:44.863  1037  1111 I sysui_multi_action:
-    // [319,64,321,64,322,99,325,5951,757,761,758,9,759,4,806,com.google.android.gm,871,
-    // com.google.android.gm.welcome.WelcomeTourActivity,905,0]
-    private static final Pattern TRANSITION_STARTING_DELAY = Pattern.compile(
-            String.format("%s%s", EVENTS_PREFIX, "I sysui_multi_action: \\[319,(.*),321,(.*)"
-                    + ",322,(.*),806,(.*),871,(.*),904.*\\]$"));
-
-    // 01-01 01:38:44.863  1037  1111 I sysui_multi_action:
-    // [319,64,322,99,325,5951,757,761,758,9,759,4,806,com.google.android.gm,871,
-    // com.google.android.gm.welcome.WelcomeTourActivity,905,0]
-    private static final Pattern TRANSITION_DELAY = Pattern.compile(
-            String.format("%s%s", EVENTS_PREFIX, "I sysui_multi_action: \\[319,(.*),322,(.*)"
-                    + ",806,(.*),871,(.*),905.*\\]$"));
+    // 09-18 23:56:19.376 1140 1221 I sysui_multi_action:
+    // [319,51,321,50,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,
+    // com.android.calculator2.Calculator,905,0,945,41]
+    private static final Pattern SYSUI_TRANSITION_INFO_PATTERN = Pattern.compile(
+            "^(?<date>[0-9-]*)\\s+(?<time>[0-9:.]*)\\s+\\d+\\s+\\d+ I sysui_multi_action:"
+                    + " \\[(?<transitioninfo>.*)\\]$");
 
     // 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>.*)\\]$"));
+    private static final Pattern ACTION_LATENCY = Pattern.compile("^(?<date>[0-9-]*)\\s+"
+            + "(?<time>[0-9:.]*)\\s+\\d+\\s+\\d+ I sysui_latency: \\[(?<action>.*),"
+            + "(?<delay>.*)\\]$");
+
+    private static final String DATE = "date";
+    private static final String TIME = "time";
+    private static final String TRANSITION_INFO = "transitioninfo";
+    private static final String PACKAGE_KEY = "806";
+    private static final String ACTIVITY_KEY = "871";
+    private static final String TRANSITION_DELAY_KEY = "319";
+    private static final String STARTING_WINDOW_DELAY_KEY = "321";
+    private static final String COLD_LAUNCH_KEY = "945";
 
     @Override
     public IItem parse(List<String> lines) {
@@ -62,37 +62,63 @@ public class EventsLogParser implements IParser {
     }
 
     /**
-     * Method to parse the transition delay information from the events log
-     *
+     * Parse the transition delay information from the events log.
      * @param input
-     * @return
+     * @return list of transition delay items.
      * @throws IOException
      */
     public List<TransitionDelayItem> parseTransitionDelayInfo(BufferedReader input)
             throws IOException {
         List<TransitionDelayItem> transitionDelayItems = new ArrayList<TransitionDelayItem>();
         String line;
+        Matcher match = null;
         while ((line = input.readLine()) != null) {
-            Matcher match = null;
-            if (((match = matches(TRANSITION_STARTING_DELAY, line)) != null)) {
-                TransitionDelayItem delayItem = new TransitionDelayItem();
-                delayItem.setComponentName(match.group(4) + "/" + match.group(5));
-                delayItem.setTransitionDelay(Long.parseLong(match.group(1)));
-                delayItem.setStartingWindowDelay(Long.parseLong(match.group(2)));
-                transitionDelayItems.add(delayItem);
-            } else if (((match = matches(TRANSITION_DELAY, line)) != null)) {
-                TransitionDelayItem delayItem = new TransitionDelayItem();
-                delayItem.setComponentName(match.group(3) + "/" + match.group(4));
-                delayItem.setTransitionDelay(Long.parseLong(match.group(1)));
-                transitionDelayItems.add(delayItem);
+            if ((match = matches(SYSUI_TRANSITION_INFO_PATTERN, line)) != null) {
+                Map<String, String> transitionInfoMap = getTransitionInfoMap(
+                        match.group(TRANSITION_INFO));
+                if (transitionInfoMap.containsKey(TRANSITION_DELAY_KEY)) {
+                    TransitionDelayItem delayItem = new TransitionDelayItem();
+                    if (null != transitionInfoMap.get(PACKAGE_KEY)
+                            && null != transitionInfoMap.get(ACTIVITY_KEY)
+                            && null != transitionInfoMap.get(TRANSITION_DELAY_KEY)) {
+                        delayItem.setComponentName(transitionInfoMap.get(PACKAGE_KEY) + "/"
+                                + transitionInfoMap.get(ACTIVITY_KEY));
+                        delayItem.setTransitionDelay(Long.parseLong(transitionInfoMap
+                                .get(TRANSITION_DELAY_KEY)));
+                        delayItem.setDateTime(String.format("%s %s", match.group(DATE),
+                                match.group(TIME)));
+                    }
+                    if (transitionInfoMap.containsKey(COLD_LAUNCH_KEY)) {
+                        if (null != transitionInfoMap.get(STARTING_WINDOW_DELAY_KEY)) {
+                            delayItem.setStartingWindowDelay(Long.parseLong(transitionInfoMap
+                                    .get(STARTING_WINDOW_DELAY_KEY)));
+                        }
+                    }
+                    transitionDelayItems.add(delayItem);
+                }
             }
         }
         return transitionDelayItems;
     }
 
     /**
+     * Split the transition info string in to key, values and return a map.
+     * @param transitionInfo transition info map in hey value format.
+     * @return
+     */
+    public Map<String, String> getTransitionInfoMap(String transitionInfo) {
+        String[] transitionSplit = transitionInfo.split(",");
+        Map<String, String> transitionInfoMap = new HashMap<>();
+        if (transitionSplit.length % 2 == 0) {
+            for (int i = 0; i < transitionSplit.length; i = i + 2) {
+                transitionInfoMap.put(transitionSplit[i], transitionSplit[i + 1]);
+            }
+        }
+        return transitionInfoMap;
+    }
+
+    /**
      * Method to parse the latency information from the events log
-     *
      * @param input
      * @return
      * @throws IOException
diff --git a/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java b/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java
index 58975d4..6e7be2a 100644
--- a/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java
+++ b/tests/src/com/android/loganalysis/parser/EventsLogParserTest.java
@@ -73,43 +73,45 @@ public class EventsLogParserTest extends TestCase {
     /**
      * Test for Cold launch transition delay and starting window delay info
      */
-    public void testValidTransitionDelay() throws IOException {
+    public void testValidColdTransitionDelay() throws IOException {
         List<String> lines = Arrays
-                .asList("01-02 08:12:10.849   934   986 I sysui_multi_action: [319,42,321,59,322,208,325,84100,757,761,758,9,759,4,806,com.google.android.apps.maps,871,com.google.android.maps.MapsActivity,904,com.google.android.apps.nexuslauncher,905,0]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_trigger_nav_btn,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_source_app,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,804,799,overview_source_app_index,801,8,802,1]");
+                .asList("09-18 23:56:19.376  1140  1221 I sysui_multi_action: [319,51,321,50,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,904,com.google.android.apps.nexuslauncher,905,0,945,41]",
+                        "09-18 23:56:19.376  1140  1221 I sysui_multi_action: [319,51,321,50,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,905,0,945,41]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertEquals("Transition Delay items list should have one item", 1,
+        assertEquals("Startinng Window Delay items list should have two item", 2,
                 transitionItems.size());
         assertEquals("Component name not parsed correctly",
-                "com.google.android.apps.maps/com.google.android.maps.MapsActivity",
+                "com.google.android.calculator/com.android.calculator2.Calculator",
                 transitionItems.get(0).getComponentName());
-        assertEquals("Transition delay is not parsed correctly", 42,
+        assertEquals("Transition delay is not parsed correctly", Long.valueOf(51),
                 transitionItems.get(0).getTransitionDelay());
-        assertEquals("Starting window delay is not parsed correctly", 59,
+        assertEquals("Starting window delay is not parsed correctly", Long.valueOf(50),
                 transitionItems.get(0).getStartingWindowDelay());
+        assertEquals("Date and time is not parsed correctly", "09-18 23:56:19.376",
+                transitionItems.get(0).getDateTime());
     }
 
     /**
-     * Test for only transition delay in hot launch
+     * Test for Hot launch transition delay and starting window delay info
      */
-    public void testOnlyTransitionDelay() throws IOException {
+    public void testValidHotTransitionDelay() throws IOException {
         List<String> lines = Arrays
-                .asList("01-02 08:12:10.849   934   986 I sysui_multi_action: [319,42,322,208,325,84100,757,761,758,9,759,4,806,com.google.android.apps.maps,871,com.google.android.maps.MapsActivity,905,0]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_trigger_nav_btn,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_source_app,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,804,799,overview_source_app_index,801,8,802,1]");
+                .asList("09-18 23:56:19.376  1140  1221 I sysui_multi_action: [319,51,321,50,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,904,com.google.android.apps.nexuslauncher,905,0]",
+                        "09-18 23:56:19.376  1140  1221 I sysui_multi_action: [319,51,321,50,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,905,0]",
+                        "09-19 02:26:30.182  1143  1196 I sysui_multi_action: [319,87,322,75,325,212,757,761,758,9,759,2,806,com.google.android.apps.nexuslauncher,871,com.google.android.apps.nexuslauncher.NexusLauncherActivity,904,com.google.android.apps.nexuslauncher,905,0]",
+                        "09-19 02:26:30.182  1143  1196 I sysui_multi_action: [319,87,322,75,325,212,757,761,758,9,759,2,806,com.google.android.apps.nexuslauncher,871,com.google.android.apps.nexuslauncher.NexusLauncherActivity,905,0]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
-        assertEquals("Transition Delay items list should have one item", 1,
+        assertEquals("Transition Delay items list should have four item", 4,
                 transitionItems.size());
         assertEquals("Component name not parsed correctly",
-                "com.google.android.apps.maps/com.google.android.maps.MapsActivity",
+                "com.google.android.calculator/com.android.calculator2.Calculator",
                 transitionItems.get(0).getComponentName());
-        assertEquals("Transition delay is not parsed correctly", 42,
+        assertEquals("Transition delay is not parsed correctly", Long.valueOf(51),
                 transitionItems.get(0).getTransitionDelay());
+        assertEquals("Date is not parsed correctly", "09-18 23:56:19.376",
+                transitionItems.get(0).getDateTime());
     }
 
     /**
@@ -117,20 +119,16 @@ public class EventsLogParserTest extends TestCase {
      */
     public void testTransitionDelayOrder() throws IOException {
         List<String> lines = Arrays
-                .asList("01-02 08:12:10.849   934   986 I sysui_multi_action: [319,42,321,59,322,208,325,84100,757,761,758,9,759,4,806,com.google.android.apps.maps,871,com.google.android.maps.MapsActivity,904,com.google.android.apps.nexuslauncher,905,0]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_trigger_nav_btn,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_source_app,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,804,799,overview_source_app_index,801,8,802,1]",
-                        "01-02 08:12:42.187   934   986 I sysui_multi_action: [319,61,321,46,322,159,325,84131,757,761,758,9,759,4,806,com.google.android.apps.maps,871,com.google.android.maps.MapsActivity,904,com.google.android.apps.nexuslauncher,905,0]",
-                        "01-02 08:12:42.450  1446  1446 I sysui_multi_action: [757,224,758,2]");
+                .asList("09-18 23:56:19.376  1140  1221 I sysui_multi_action: [319,51,321,59,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,904,com.google.android.apps.nexuslauncher,905,0,945,41]",
+                        "09-18 23:59:18.380  1140  1221 I sysui_multi_action: [319,55,321,65,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,905,0,945,41]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
         assertEquals("Transition Delay items list should have two items", 2,
                 transitionItems.size());
-        assertEquals("Transition delay for the first item is not set correct", 42,
-                transitionItems.get(0).getTransitionDelay());
-        assertEquals("Transition delay for the second item is not set correct", 61,
-                transitionItems.get(1).getTransitionDelay());
+        assertEquals("Transition delay for the first item is not set correct", Long.valueOf(59),
+                transitionItems.get(0).getStartingWindowDelay());
+        assertEquals("Transition delay for the second item is not set correct", Long.valueOf(65),
+                transitionItems.get(1).getStartingWindowDelay());
     }
 
     /**
@@ -138,12 +136,8 @@ public class EventsLogParserTest extends TestCase {
      */
     public void testDifferentAppTransitionDelay() throws IOException {
         List<String> lines = Arrays
-                .asList("01-02 08:11:58.691   934   986 I sysui_multi_action: [319,48,321,37,322,82,325,84088,757,761,758,9,759,4,806,com.google.android.calculator,871,com.android.calculator2.Calculator,904,com.google.android.apps.nexuslauncher,905,0]",
-                        "01-02 08:12:03.639   934   970 I sysui_multi_action: [757,803,799,window_time_0,802,5]",
-                        "01-02 08:12:10.849   934   986 I sysui_multi_action: [319,42,321,59,322,208,325,84100,757,761,758,9,759,4,806,com.google.android.apps.maps,871,com.google.android.maps.MapsActivity,904,com.google.android.apps.nexuslauncher,905,0]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_trigger_nav_btn,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_source_app,802,1]",
-                        "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,804,799,overview_source_app_index,801,8,802,1]");
+                .asList("09-18 23:56:19.376  1140  1221 I sysui_multi_action: [319,51,321,50,322,190,325,670,757,761,758,7,759,1,806,com.google.android.calculator,871,com.android.calculator2.Calculator,904,com.google.android.apps.nexuslauncher,905,0]",
+                        "09-19 02:26:30.182  1143  1196 I sysui_multi_action: [319,87,322,75,325,212,757,761,758,9,759,2,806,com.google.android.apps.nexuslauncher,871,com.google.android.apps.nexuslauncher.NexusLauncherActivity,904,com.google.android.apps.nexuslauncher,905,0]");
         List<TransitionDelayItem> transitionItems = (new EventsLogParser()).
                 parseTransitionDelayInfo(readInputBuffer(getTempFile(lines)));
         assertEquals("Transition Delay items list should have two items", 2,
@@ -152,7 +146,8 @@ public class EventsLogParserTest extends TestCase {
                 "com.google.android.calculator/com.android.calculator2.Calculator",
                 transitionItems.get(0).getComponentName());
         assertEquals("Maps is not the second transition delay item",
-                "com.google.android.apps.maps/com.google.android.maps.MapsActivity",
+                "com.google.android.apps.nexuslauncher/"
+                + "com.google.android.apps.nexuslauncher.NexusLauncherActivity",
                 transitionItems.get(1).getComponentName());
     }
 
@@ -161,7 +156,7 @@ public class EventsLogParserTest extends TestCase {
      */
     public void testInvalidTransitionPattern() throws IOException {
         List<String> lines = Arrays
-                .asList("01-02 08:11:58.691   934   986 I sysui_multi_action: [319,48,322,82,325,84088,757,761,758,9,759,4,807,com.google.android.calculator,871,com.android.calculator2.Calculator,905,0]",
+                .asList("01-02 08:11:58.691   934   986 I sysui_multi_action: a[319,48,322,82,325,84088,757,761,758,9,759,4,807,com.google.android.calculator,871,com.android.calculator2.Calculator,905,0]",
                         "01-02 08:12:03.639   934   970 I sysui_multi_action: [757,803,799,window_time_0,802,5]",
                         "01-02 08:12:10.849   934   986 I sysui_multi_action: 319,42,321,59,322,208,325,84100,757,761,758,9,759,4,806,com.google.android.apps.maps,871,com.google.android.maps.MapsActivity,905,0]",
                         "01-02 08:12:16.895  1446  1446 I sysui_multi_action: [757,803,799,overview_trigger_nav_btn,802,1]",