Skip to content
Snippets Groups Projects
Commit 2dbbf0c3 authored by Xin Li's avatar Xin Li
Browse files

DO NOT MERGE: Merge Oreo MR1 into master 

Exempt-From-Owner-Approval: Changes already landed internally
Change-Id: I450f5043f1e5136f35c4f60c1bb68e46464d5e16
parents d4dcae82 9856063f
No related branches found
No related tags found
No related merge requests found
Hide whitespace changes
Inline Side-by-side
src/com/android/loganalysis/parser/DmesgParser.java
+ 16
− 6
View file @ 2dbbf0c3
......@@ -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(
......
tests/src/com/android/loganalysis/parser/BugreportParserTest.java
+ 73
− 0
View file @ 2dbbf0c3
......@@ -490,6 +490,79 @@ public class BugreportParserTest extends TestCase {
assertNull(bugreport.getSystemLog().getAnrs().get(0).getTrace());
}
/**
* Add a test that ensures that the "new" style of stack dumping works. Traces aren't written to
* a global trace file. Instead, each ANR event is written to a separate trace file (note the
* "/data/anr/anr_4376042170248254515" instead of "/data/anr/traces.txt").
*/
public void testAnrTraces_not_global_traceFile() {
List<String> lines =
Arrays.asList(
"========================================================",
"== dumpstate: 2017-06-12 16:46:29",
"========================================================",
"------ SYSTEM LOG (logcat -v threadtime -v printable -v uid -d *:v) ------",
"--------- beginning of main ",
"02-18 04:26:31.829 logd 468 468 W auditd : type=2000 audit(0.0:1): initialized",
"02-18 04:26:33.783 logd 468 468 I auditd : type=1403 audit(0.0:2): policy loaded auid=4294967295 ses=4294967295",
"02-18 04:26:33.783 logd 468 468 W auditd : type=1404 audit(0.0:3): enforcing=1 old_enforcing=0 auid=4294967295 ses=4294967295",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: ANR in com.example.android.helloactivity (com.example.android.helloactivity/.HelloActivity)",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: PID: 7176",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: Reason: Input dispatching timed out (Waiting because no window has focus but there is a focused application that may eventually add a window when it finishes starting up.)",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: Load: 6.85 / 7.07 / 5.31",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: CPU usage from 235647ms to 0ms ago (2017-06-12 16:41:49.415 to 2017-06-12 16:45:45.062):",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: 7.7% 1848/com.ustwo.lwp: 4% user + 3.7% kernel / faults: 157 minor",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: 7.7% 2536/com.google.android.googlequicksearchbox:search: 5.6% user + 2.1% kernel / faults: 195 minor",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: 7.2% 1050/system_server: 4.5% user + 2.6% kernel / faults: 27117 minor ",
"06-12 16:45:47.426 1000 1050 1124 E ActivityManager: 5.3% 489/surfaceflinger: 2.9% user + 2.3% kernel / faults: 15 minor ",
"",
"------ VM TRACES AT LAST ANR (/data/anr/anr_4376042170248254515: 2017-06-12 16:45:47) ------",
"",
"----- pid 7176 at 2017-06-12 16:45:45 -----",
"Cmd line: com.example.android.helloactivity",
"",
"DALVIK THREADS:",
"(mutexes: tll=0 tsl=0 tscl=0 ghl=0)",
"",
"\"main\" daemon prio=5 tid=5 Waiting",
" | group=\"system\" sCount=1 dsCount=0 flags=1 obj=0x140805e8 self=0x7caf4bf400",
" | sysTid=7184 nice=4 cgrp=default sched=0/0 handle=0x7c9b4e44f0",
" | state=S schedstat=( 507031 579062 19 ) utm=0 stm=0 core=3 HZ=100",
" | stack=0x7c9b3e2000-0x7c9b3e4000 stackSize=1037KB",
" | held mutexes=",
" at java.lang.Object.wait(Native method)",
" - waiting on <0x0281f7b7> (a java.lang.Class<java.lang.ref.ReferenceQueue>)",
" at java.lang.Daemons$ReferenceQueueDaemon.runInternal(Daemons.java:178)",
" - locked <0x0281f7b7> (a java.lang.Class<java.lang.ref.ReferenceQueue>)",
" at java.lang.Daemons$Daemon.run(Daemons.java:103)",
" at java.lang.Thread.run(Thread.java:764)",
"",
"----- end 7176 -----");
// NOTE: The parser only extracts the main thread from the traces.
List<String> expectedStack =
Arrays.asList(
"\"main\" daemon prio=5 tid=5 Waiting",
" | group=\"system\" sCount=1 dsCount=0 flags=1 obj=0x140805e8 self=0x7caf4bf400",
" | sysTid=7184 nice=4 cgrp=default sched=0/0 handle=0x7c9b4e44f0",
" | state=S schedstat=( 507031 579062 19 ) utm=0 stm=0 core=3 HZ=100",
" | stack=0x7c9b3e2000-0x7c9b3e4000 stackSize=1037KB",
" | held mutexes=",
" at java.lang.Object.wait(Native method)",
" - waiting on <0x0281f7b7> (a java.lang.Class<java.lang.ref.ReferenceQueue>)",
" at java.lang.Daemons$ReferenceQueueDaemon.runInternal(Daemons.java:178)",
" - locked <0x0281f7b7> (a java.lang.Class<java.lang.ref.ReferenceQueue>)",
" at java.lang.Daemons$Daemon.run(Daemons.java:103)",
" at java.lang.Thread.run(Thread.java:764)");
BugreportItem bugreport = new BugreportParser().parse(lines);
assertNotNull(bugreport.getSystemLog());
assertEquals(1, bugreport.getSystemLog().getAnrs().size());
assertEquals(
ArrayUtil.join("\n", expectedStack),
bugreport.getSystemLog().getAnrs().get(0).getTrace());
}
/**
* Test that missing sections in bugreport are set to {@code null}, not empty {@link IItem}s.
*/
......
tests/src/com/android/loganalysis/parser/DmesgParserTest.java
+ 43
− 40
View file @ 2dbbf0c3
......@@ -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() {
......
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment