diff --git a/src/com/android/loganalysis/parser/DmesgParser.java b/src/com/android/loganalysis/parser/DmesgParser.java index ce3d389879498d1487081a267d5fce13a954dbb6..63026d402037c11dcdfab05ffb95f9e32ca12d27 100644 --- a/src/com/android/loganalysis/parser/DmesgParser.java +++ b/src/com/android/loganalysis/parser/DmesgParser.java @@ -71,13 +71,22 @@ public class DmesgParser implements IParser { private static final Pattern START_STAGE = Pattern.compile( String.format("%s%s", SERVICE_PREFIX, START_STAGE_PREFIX)); + // Matches: init: processing action (early-init) from (/init.rc:14) + private static final String START_PROCESSING_ACTION_PREFIX = + String.format("processing action \\((?<%s>.*)\\) from.*$", ACTION); + // Matches: init: processing action (early-init) - private static final String START_PROCESSING_ACTION_PREFIX = String.format( - "processing action \\((?<%s>.*)\\) from.*$", ACTION); + private static final String START_PROCESSING_ACTION_PREFIX_LEGACY = + String.format("processing action \\((?<%s>.*)\\).*$", ACTION); + + // Matches: init: processing action (early-init) from (/init.rc:14) + private static final Pattern START_PROCESSING_ACTION = + Pattern.compile(String.format("%s%s", SERVICE_PREFIX, START_PROCESSING_ACTION_PREFIX)); - // Matches: [ 14.942872] init: processing action (early-init) - private static final Pattern START_PROCESSING_ACTION = Pattern.compile( - String.format("%s%s", SERVICE_PREFIX, START_PROCESSING_ACTION_PREFIX)); + // Matches: init: processing action (early-init) + private static final Pattern START_PROCESSING_ACTION_LEGACY = + Pattern.compile( + String.format("%s%s", SERVICE_PREFIX, START_PROCESSING_ACTION_PREFIX_LEGACY)); // Matches: [ 3.791635] ueventd: Coldboot took 0.695055 seconds private static final String STAGE_SUFFIX= String.format( @@ -216,7 +225,8 @@ public class DmesgParser implements IParser { @VisibleForTesting boolean parseActionInfo(String line) { Matcher match = null; - if ((match = matches(START_PROCESSING_ACTION, line)) != null) { + if ((match = matches(START_PROCESSING_ACTION, line)) != null + || (match = matches(START_PROCESSING_ACTION_LEGACY, line)) != null) { DmesgActionInfoItem actionInfoItem = new DmesgActionInfoItem(); actionInfoItem.setActionName(match.group(ACTION)); actionInfoItem.setStartTime((long) (Double.parseDouble( diff --git a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java index 7db2c49d863da08438dd44f4f0385a11fa3fcafa..20665eabe9a3cf41dc37c3fd2fac99f43c5d8f09 100644 --- a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java +++ b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java @@ -38,27 +38,30 @@ public class DmesgParserTest extends TestCase { private static final String BOOT_ANIMATION = "bootanim"; private static final String NETD = "netd"; - private static final String[] LINES = new String[] { - "[ 3.786943] ueventd: Coldboot took 0.701291 seconds", - "[ 22.962730] init: starting service 'bootanim'...", - "[ 23.252321] init: starting service 'netd'...", - "[ 29.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA", - "[ 32.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660", - "[ 35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts", - "[ 39.855818] init: Service 'bootanim' (pid 588) exited with status 0", - "[ 41.665818] init: init first stage started!", - "[ 44.942872] init: processing action (early-init) from (/init.rc:13)", - "[ 47.233446] init: processing action (set_mmap_rnd_bits) from (<Builtin Action>:0)", - "[ 47.240083] init: processing action (set_kptr_restrict) from (<Builtin Action>:0)", - "[ 47.245778] init: processing action (keychord_init) from (<Builtin Action>:0)", - "[ 52.361049] init: processing action (persist.sys.usb.config=* boot) from (<Builtin Action>:0)", - "[ 52.361108] init: processing action (enable_property_trigger) from (<Builtin Action>:0)", - "[ 52.361313] init: processing action (security.perf_harden=1) from (/init.rc:677)", - "[ 52.361495] init: processing action (ro.debuggable=1) from (/init.rc:700)", - "[ 59.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA", - "[ 62.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660", - "[ 65.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts", - "[ 69.855818] init: Service 'bootanim' (pid 588) exited with status 0"}; + private static final String[] LINES = + new String[] { + "[ 3.786943] ueventd: Coldboot took 0.701291 seconds", + "[ 22.962730] init: starting service 'bootanim'...", + "[ 23.252321] init: starting service 'netd'...", + "[ 29.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA", + "[ 32.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660", + "[ 35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts", + "[ 39.855818] init: Service 'bootanim' (pid 588) exited with status 0", + "[ 41.665818] init: init first stage started!", + "[ 44.942872] init: processing action (early-init) from (/init.rc:13)", + "[ 47.233446] init: processing action (set_mmap_rnd_bits) from (<Builtin Action>:0)", + "[ 47.240083] init: processing action (set_kptr_restrict) from (<Builtin Action>:0)", + "[ 47.245778] init: processing action (keychord_init) from (<Builtin Action>:0)", + "[ 52.361049] init: processing action (persist.sys.usb.config=* boot) from (<Builtin Action>:0)", + "[ 52.361108] init: processing action (enable_property_trigger) from (<Builtin Action>:0)", + "[ 52.361313] init: processing action (security.perf_harden=1) from (/init.rc:677)", + "[ 52.361495] init: processing action (ro.debuggable=1) from (/init.rc:700)", + "[ 58.298293] init: processing action (sys.boot_completed=1)", + "[ 59.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA", + "[ 62.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660", + "[ 65.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts", + "[ 69.855818] init: Service 'bootanim' (pid 588) exited with status 0" + }; private static final Map<String, DmesgServiceInfoItem> EXPECTED_SERVICE_INFO_ITEMS = getExpectedServiceInfoItems(); @@ -93,9 +96,9 @@ public class DmesgParserTest extends TestCase { assertEquals("Service info items list size should be 2", 2, dmesgParser.getServiceInfoItems().size()); - assertEquals("Stage info items list size should be 2", 2, + assertEquals("Stage info items list size should be 2",2, dmesgParser.getStageInfoItems().size()); - assertEquals("Action info items list size should be 8", 8, + assertEquals("Action info items list size should be 9",9, dmesgParser.getActionInfoItems().size()); assertEquals(EXPECTED_SERVICE_INFO_ITEMS, actualDmesgItem.getServiceInfoItems()); @@ -115,7 +118,7 @@ public class DmesgParserTest extends TestCase { dmesgParser.getServiceInfoItems().size()); assertEquals("Stage info items list size should be 2", 2, dmesgParser.getStageInfoItems().size()); - assertEquals("Action info items list size should be 8", 8, + assertEquals("Action info items list size should be 9",9, dmesgParser.getActionInfoItems().size()); } } @@ -198,35 +201,35 @@ public class DmesgParserTest extends TestCase { assertEquals(EXPECTED_STAGE_INFO_ITEMS, stageInfoItems); } - /** - * Test processing action start time logs - */ + /** Test processing action start time logs */ public void testCompleteActionInfo() { DmesgParser dmesgParser = new DmesgParser(); for (String line : LINES) { dmesgParser.parseActionInfo(line); } List<DmesgActionInfoItem> actualActionInfoItems = dmesgParser.getActionInfoItems(); - assertEquals(8, actualActionInfoItems.size()); + assertEquals(9, actualActionInfoItems.size()); assertEquals(EXPECTED_ACTION_INFO_ITEMS, actualActionInfoItems); } private static List<DmesgActionInfoItem> getExpectedActionInfoItems() { return Arrays.asList( new DmesgActionInfoItem("early-init", (long) (Double.parseDouble("44942.872"))), - new DmesgActionInfoItem("set_mmap_rnd_bits", - (long) (Double.parseDouble("47233.446"))), - new DmesgActionInfoItem("set_kptr_restrict", - (long) (Double.parseDouble("47240.083"))), + new DmesgActionInfoItem( + "set_mmap_rnd_bits", (long) (Double.parseDouble("47233.446"))), + new DmesgActionInfoItem( + "set_kptr_restrict", (long) (Double.parseDouble("47240.083"))), new DmesgActionInfoItem("keychord_init", (long) (Double.parseDouble("47245.778"))), - new DmesgActionInfoItem("persist.sys.usb.config=* boot", - (long) (Double.parseDouble("52361.049"))), - new DmesgActionInfoItem("enable_property_trigger", - (long) (Double.parseDouble("52361.108"))), - new DmesgActionInfoItem("security.perf_harden=1", - (long) (Double.parseDouble("52361.313"))), - new DmesgActionInfoItem("ro.debuggable=1", - (long) (Double.parseDouble("52361.495")))); + new DmesgActionInfoItem( + "persist.sys.usb.config=* boot", (long) (Double.parseDouble("52361.049"))), + new DmesgActionInfoItem( + "enable_property_trigger", (long) (Double.parseDouble("52361.108"))), + new DmesgActionInfoItem( + "security.perf_harden=1", (long) (Double.parseDouble("52361.313"))), + new DmesgActionInfoItem( + "ro.debuggable=1", (long) (Double.parseDouble("52361.495"))), + new DmesgActionInfoItem( + "sys.boot_completed=1", (long) (Double.parseDouble("58298.293")))); } private static List<DmesgStageInfoItem> getExpectedStageInfoItems() {