Skip to content
Snippets Groups Projects
Commit 7e8dea6d authored by TreeHugger Robot's avatar TreeHugger Robot Committed by Android (Google) Code Review
Browse files

Merge "Accomodate new log format logged in dmesg during boot"

parents 5cf5cfd8 bdcdfc3b
Branches
No related tags found
No related merge requests found
......@@ -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() + "]";
}
}
......@@ -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;
}
......
......@@ -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() {
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Please register or to comment