diff options
author | gopinath <gelanchezhian@google.com> | 2017-05-16 18:36:59 -0700 |
---|---|---|
committer | gopinath <gelanchezhian@google.com> | 2017-05-16 18:47:41 -0700 |
commit | bdcdfc3bd752eb8af8085cdbaf5574076baac2ff (patch) | |
tree | e78f1fe3ae579c0fd2fd7a391a9cf84534df0a2c | |
parent | b2b068af021e41755d43d1285fc16a7dc479abc1 (diff) | |
download | loganalysis-bdcdfc3bd752eb8af8085cdbaf5574076baac2ff.tar.gz |
Accomodate new log format logged in dmesg during boot
b/38045657
Test :
Time: 0.37
OK (253 tests)
Change-Id: If4047e75c65c8d062e789ce03e6c82c2a42d5096
3 files changed, 56 insertions, 16 deletions
diff --git a/src/com/android/loganalysis/item/DmesgStageInfoItem.java b/src/com/android/loganalysis/item/DmesgStageInfoItem.java index a5bfd39..a446090 100644 --- a/src/com/android/loganalysis/item/DmesgStageInfoItem.java +++ b/src/com/android/loganalysis/item/DmesgStageInfoItem.java @@ -30,9 +30,11 @@ public class DmesgStageInfoItem extends GenericItem { public static final String STAGE_NAME = "STAGE_NAME"; /** Constant for JSON output */ public static final String STAGE_START_TIME = "STAGE_START_TIME"; + /** Constant for JSON output */ + public static final String STAGE_DURATION = "STAGE_DURATION"; private static final Set<String> ATTRIBUTES = new HashSet<String>(Arrays.asList( - STAGE_NAME, STAGE_START_TIME)); + STAGE_NAME, STAGE_START_TIME, STAGE_DURATION)); /** * The constructor for {@link DmesgStageInfoItem}. @@ -44,10 +46,11 @@ public class DmesgStageInfoItem extends GenericItem { /** * The constructor for {@link DmesgStageInfoItem}. */ - public DmesgStageInfoItem(String name, Long startTime) { + public DmesgStageInfoItem(String name, Long startTime, Long duration) { super(ATTRIBUTES); setAttribute(STAGE_NAME, name); setAttribute(STAGE_START_TIME, startTime); + setAttribute(STAGE_DURATION, duration); } /** @@ -78,10 +81,24 @@ public class DmesgStageInfoItem extends GenericItem { setAttribute(STAGE_START_TIME, startTime); } + /** + * Get the duration in msecs + */ + public Long getDuration() { + return (Long) getAttribute(STAGE_DURATION); + } + + /** + * Set the duration in msecs + */ + public void setDuration(Long duration) { + setAttribute(STAGE_DURATION, duration); + } + @Override public String toString() { return "StageInfoItem [getStageName()=" + getStageName() + ", getStartTime()=" - + getStartTime() + "]"; + + getStartTime() + ", getDuration()=" + getDuration() + "]"; } } diff --git a/src/com/android/loganalysis/parser/DmesgParser.java b/src/com/android/loganalysis/parser/DmesgParser.java index bd0d8e4..ce3d389 100644 --- a/src/com/android/loganalysis/parser/DmesgParser.java +++ b/src/com/android/loganalysis/parser/DmesgParser.java @@ -20,6 +20,7 @@ import com.android.loganalysis.item.DmesgActionInfoItem; import com.android.loganalysis.item.DmesgItem; import com.android.loganalysis.item.DmesgServiceInfoItem; import com.android.loganalysis.item.DmesgStageInfoItem; + import com.google.common.annotations.VisibleForTesting; import java.io.BufferedReader; @@ -39,15 +40,22 @@ public class DmesgParser implements IParser { private static final String TIMESTAMP = "TIMESTAMP"; private static final String STAGE = "STAGE"; private static final String ACTION = "ACTION"; + private static final String DURATION = "DURATION"; + private static final String UEVENTD = "ueventd"; + // Matches: [ 14.822691] init: private static final String SERVICE_PREFIX = String.format("^\\[\\s+(?<%s>.*)\\] init:\\s+", TIMESTAMP); + // Matches: [ 3.791635] ueventd: + private static final String UEVENTD_PREFIX = String.format("^\\[\\s+(?<%s>.*)\\] ueventd:\\s+", + TIMESTAMP); + // Matches: starting service 'ueventd'... private static final String START_SERVICE_SUFFIX = String.format("starting service " + "\\'(?<%s>.*)\\'...", SERVICENAME); // Matches: Service 'ueventd' (pid 439) exited with status 0 private static final String EXIT_SERVICE_SUFFIX = String.format("Service \\'(?<%s>.*)\\'\\s+" - + "\\((?<PID>.*)\\) exited with status 0", SERVICENAME); + + "\\((?<PID>.*)\\) exited with status 0.*", SERVICENAME); private static final Pattern START_SERVICE = Pattern.compile( String.format("%s%s", SERVICE_PREFIX, START_SERVICE_SUFFIX)); @@ -65,12 +73,18 @@ public class DmesgParser implements IParser { // Matches: init: processing action (early-init) private static final String START_PROCESSING_ACTION_PREFIX = String.format( - "processing action \\((?<%s>.*)\\)", ACTION); + "processing action \\((?<%s>.*)\\) from.*$", ACTION); // 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: [ 3.791635] ueventd: Coldboot took 0.695055 seconds + private static final String STAGE_SUFFIX= String.format( + "(?<%s>.*)\\s+took\\s+(?<%s>.*)\\s+seconds$", STAGE, DURATION); + private static final Pattern UEVENTD_STAGE_INFO = Pattern.compile( + String.format("%s%s", UEVENTD_PREFIX, STAGE_SUFFIX)); + private DmesgItem mDmesgItem = new DmesgItem(); @@ -163,7 +177,8 @@ public class DmesgParser implements IParser { /** * Parse init stages log from each {@code line} of dmesg log and - * store the stage name and start time in a {@link DmesgStageInfoItem} object + * store the stage name, start time and duration if available in a + * {@link DmesgStageInfoItem} object * * @param individual line of the dmesg log * @return {@code true}, if the {@code line} indicates start of a boot stage, @@ -180,6 +195,13 @@ public class DmesgParser implements IParser { mDmesgItem.addStageInfoItem(stageInfoItem); return true; } + if((match = matches(UEVENTD_STAGE_INFO, line)) != null) { + DmesgStageInfoItem stageInfoItem = new DmesgStageInfoItem(); + stageInfoItem.setStageName(String.format("%s_%s", UEVENTD, match.group(STAGE))); + stageInfoItem.setDuration((long) (Double.parseDouble( + match.group(DURATION)) * 1000)); + mDmesgItem.addStageInfoItem(stageInfoItem); + } return false; } diff --git a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java index 2206733..7db2c49 100644 --- a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java +++ b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java @@ -39,6 +39,7 @@ 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", @@ -46,15 +47,14 @@ public class DmesgParserTest extends TestCase { "[ 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!", - "[ 42.425056] init: init second stage started!", - "[ 44.942872] init: processing action (early-init)", - "[ 47.233446] init: processing action (set_mmap_rnd_bits)", - "[ 47.240083] init: processing action (set_kptr_restrict)", - "[ 47.245778] init: processing action (keychord_init)", - "[ 52.361049] init: processing action (persist.sys.usb.config=* boot)", - "[ 52.361108] init: processing action (enable_property_trigger)", - "[ 52.361313] init: processing action (security.perf_harden=1)", - "[ 52.361495] init: processing action (ro.debuggable=1)", + "[ 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", @@ -231,7 +231,8 @@ public class DmesgParserTest extends TestCase { private static List<DmesgStageInfoItem> getExpectedStageInfoItems() { return Arrays.asList( - new DmesgStageInfoItem("first", 41665L), new DmesgStageInfoItem("second", 42425L)); + new DmesgStageInfoItem("ueventd_Coldboot", null, 701L), + new DmesgStageInfoItem("first", 41665L, null)); } private static Map<String, DmesgServiceInfoItem> getExpectedServiceInfoItems() { |