diff --git a/src/com/android/loganalysis/item/TransitionDelayItem.java b/src/com/android/loganalysis/item/TransitionDelayItem.java index 33a1b9331915273d7169ade9d65b051f652253e1..b91f92620ff79e0a3880400bcfcac8385c4b8752 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 c150df89172ca183d87acc83e2b2c4c1b4b8e1ca..b69948d4ce9d2731b51fe089a82c807adcbb9bf3 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 58975d464a068d035e658d9d97fb88e450ebfb66..6e7be2ac5bcd0329763acfa5aa6ab678c892c221 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]",