summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorandroid-build-team Robot <android-build-team-robot@google.com>2020-04-28 20:26:06 +0000
committerandroid-build-team Robot <android-build-team-robot@google.com>2020-04-28 20:26:06 +0000
commite4e3aa1e56bd8c2b5a78aabdc0f45a5ef7603bd7 (patch)
tree2eaec95c1eeacb580684b882ed0a3dff03949b4c
parentcaa9272daf4aceb35fa6408cc42f09056ec914b4 (diff)
parenteec32327da28db6f5e599a4ab76f7c93995896ef (diff)
downloadloganalysis-android10-mainline-tzdata-release.tar.gz
Change-Id: I629eced313880cd70da53f3b94e7073ad81135ed
-rw-r--r--.classpath2
-rw-r--r--src/com/android/loganalysis/item/DmesgActionInfoItem.java28
-rw-r--r--src/com/android/loganalysis/item/GenericTimingItem.java79
-rw-r--r--src/com/android/loganalysis/item/SystemServicesTimingItem.java84
-rw-r--r--src/com/android/loganalysis/parser/DmesgParser.java19
-rw-r--r--src/com/android/loganalysis/parser/TimingsLogParser.java246
-rw-r--r--tests/src/com/android/loganalysis/UnitTests.java2
-rw-r--r--tests/src/com/android/loganalysis/parser/DmesgParserTest.java25
-rw-r--r--tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java354
9 files changed, 33 insertions, 806 deletions
diff --git a/.classpath b/.classpath
index 02b371d..ca81bde 100644
--- a/.classpath
+++ b/.classpath
@@ -4,6 +4,6 @@
<classpathentry kind="con" path="org.eclipse.jdt.launching.JRE_CONTAINER"/>
<classpathentry kind="con" path="org.eclipse.jdt.junit.JUNIT_CONTAINER/3"/>
<classpathentry exported="true" kind="var" path="TRADEFED_ROOT/prebuilts/misc/common/json/json-prebuilt.jar"/>
- <classpathentry kind="var" path="TRADEFED_ROOT/out/soong/.intermediates/external/guava/guava-jre/linux_glibc_common/combined/guava-jre.jar"/>
+ <classpathentry kind="var" path="TRADEFED_ROOT/out/soong/.intermediates/external/guava/guava/linux_glibc_common/combined/guava.jar"/>
<classpathentry kind="output" path="bin"/>
</classpath>
diff --git a/src/com/android/loganalysis/item/DmesgActionInfoItem.java b/src/com/android/loganalysis/item/DmesgActionInfoItem.java
index 482b426..ac73b8e 100644
--- a/src/com/android/loganalysis/item/DmesgActionInfoItem.java
+++ b/src/com/android/loganalysis/item/DmesgActionInfoItem.java
@@ -27,14 +27,12 @@ import java.util.Set;
public class DmesgActionInfoItem extends GenericItem {
/** Constant for JSON output */
- public static final String SOURCE_NAME = "SOURCE_NAME";
- /** Constant for JSON output */
public static final String ACTION_NAME = "ACTION_NAME";
/** Constant for JSON output */
public static final String ACTION_START_TIME = "ACTION_START_TIME";
private static final Set<String> ATTRIBUTES = new HashSet<String>(Arrays.asList(
- SOURCE_NAME, ACTION_NAME, ACTION_START_TIME));
+ ACTION_NAME, ACTION_START_TIME));
/**
* The constructor for {@link DmesgActionInfoItem}.
@@ -46,28 +44,13 @@ public class DmesgActionInfoItem extends GenericItem {
/**
* The constructor for {@link DmesgActionInfoItem}.
*/
- public DmesgActionInfoItem(String source, String name, Long startTime) {
+ public DmesgActionInfoItem(String name, Long startTime) {
super(ATTRIBUTES);
- setAttribute(SOURCE_NAME, source);
setAttribute(ACTION_NAME, name);
setAttribute(ACTION_START_TIME, startTime);
}
/**
- * Get the name of the source
- */
- public String getSourceName() {
- return (String) getAttribute(SOURCE_NAME);
- }
-
- /**
- * Set the name of the source
- */
- public void setSourceName(String sourceName) {
- setAttribute(SOURCE_NAME, sourceName);
- }
-
- /**
* Get the name of the action
*/
public String getActionName() {
@@ -97,11 +80,8 @@ public class DmesgActionInfoItem extends GenericItem {
@Override
public String toString() {
- return "ActionInfoItem ["
- + "getSourceName()=" + getSourceName()
- + ", getActionName()=" + getActionName()
- + ", getStartTime()=" + getStartTime()
- + "]";
+ return "ActionInfoItem [getActionName()=" + getActionName() + ", getStartTime()="
+ + getStartTime() + "]";
}
}
diff --git a/src/com/android/loganalysis/item/GenericTimingItem.java b/src/com/android/loganalysis/item/GenericTimingItem.java
deleted file mode 100644
index 088d15b..0000000
--- a/src/com/android/loganalysis/item/GenericTimingItem.java
+++ /dev/null
@@ -1,79 +0,0 @@
-/*
- * Copyright (C) 2019 The Android Open Source Project
- *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License
- */
-
-package com.android.loganalysis.item;
-
-import java.util.Arrays;
-import java.util.HashSet;
-import java.util.Set;
-
-public class GenericTimingItem extends GenericItem {
- /** Constant for JSON output */
- public static final String NAME = "NAME";
- /** Constant for JSON output */
- public static final String START_TIME = "START_TIME";
- /** Constant for JSON output */
- public static final String END_TIME = "END_TIME";
-
- private static final Set<String> ATTRIBUTES =
- new HashSet<>(Arrays.asList(NAME, END_TIME, START_TIME));
-
- public GenericTimingItem() {
- super(ATTRIBUTES);
- }
-
- protected GenericTimingItem(Set<String> attributes) {
- super(getAllAttributes(attributes));
- }
-
- /** Get the name of the generic timing item */
- public String getName() {
- return (String) getAttribute(NAME);
- }
-
- /** Set the name of the generic timing item */
- public void setName(String name) {
- setAttribute(NAME, name);
- }
-
- /** Get the duration value for the generic timing, it is timestamp in milliseconds */
- public Double getDuration() {
- return (Double) getAttribute(END_TIME) - (Double) getAttribute(START_TIME);
- }
-
- /** Get the start time value for the generic timing, it is timestamp in milliseconds */
- public Double getStartTime() {
- return (Double) getAttribute(START_TIME);
- }
-
- /** Get the end time value for the generic timing, it is timestamp in milliseconds */
- public Double getEndTime() {
- return (Double) getAttribute(END_TIME);
- }
-
- /** Set the start and end time value for the generic timing, it is timestamp in milliseconds */
- public void setStartAndEnd(double startTime, double endTime) {
- setAttribute(START_TIME, startTime);
- setAttribute(END_TIME, endTime);
- }
-
- /** Combine an array of attributes with the internal list of attributes. */
- private static Set<String> getAllAttributes(Set<String> attributes) {
- Set<String> allAttributes = new HashSet<String>(ATTRIBUTES);
- allAttributes.addAll(attributes);
- return allAttributes;
- }
-}
diff --git a/src/com/android/loganalysis/item/SystemServicesTimingItem.java b/src/com/android/loganalysis/item/SystemServicesTimingItem.java
deleted file mode 100644
index 79671a2..0000000
--- a/src/com/android/loganalysis/item/SystemServicesTimingItem.java
+++ /dev/null
@@ -1,84 +0,0 @@
-/*
- * Copyright (C) 2019 The Android Open Source Project
- *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License
- */
-
-package com.android.loganalysis.item;
-
-import java.util.Arrays;
-import java.util.HashSet;
-import java.util.Set;
-
-/**
- * An {@link IItem} used to store timing information for system services like System Server, Zygote,
- * System UI, BootAnimation e.t.c.
- */
-public class SystemServicesTimingItem extends GenericItem {
- /** Constant for JSON output */
- public static final String COMPONENT = "COMPONENT";
- /** Constant for JSON output */
- public static final String SUBCOMPONENT = "SUBCOMPONENT";
- /** Constant for JSON output */
- public static final String DURATION = "DURATION";
- /** Constant for JSON output */
- public static final String START_TIME = "START_TIME";
-
- private static final Set<String> ATTRIBUTES =
- new HashSet<>(Arrays.asList(COMPONENT, SUBCOMPONENT, DURATION, START_TIME));
-
- /** Constructor for {@link SystemServicesTimingItem} */
- public SystemServicesTimingItem() {
- super(ATTRIBUTES);
- }
-
- /** Get the component name for system services timing */
- public String getComponent() {
- return (String) getAttribute(COMPONENT);
- }
-
- /** Set the component name for system service timing */
- public void setComponent(String component) {
- setAttribute(COMPONENT, component);
- }
-
- /** Get the sub-component name for system service timing */
- public String getSubcomponent() {
- return (String) getAttribute(SUBCOMPONENT);
- }
-
- /** Set the sub-component name for system service timing */
- public void setSubcomponent(String subcomponent) {
- setAttribute(SUBCOMPONENT, subcomponent);
- }
-
- /** Get the duration value for system service timing */
- public Double getDuration() {
- return (Double) getAttribute(DURATION);
- }
-
- /** Set the duration value for system service timing */
- public void setDuration(double duration) {
- setAttribute(DURATION, duration);
- }
-
- /** Get the start time value for system service timing */
- public Double getStartTime() {
- return (Double) getAttribute(START_TIME);
- }
-
- /** Set the start time value for system service timing */
- public void setStartTime(double startTime) {
- setAttribute(START_TIME, startTime);
- }
-}
diff --git a/src/com/android/loganalysis/parser/DmesgParser.java b/src/com/android/loganalysis/parser/DmesgParser.java
index 4b4d333..be292ff 100644
--- a/src/com/android/loganalysis/parser/DmesgParser.java
+++ b/src/com/android/loganalysis/parser/DmesgParser.java
@@ -40,7 +40,6 @@ 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 SOURCE = "SOURCE";
private static final String DURATION = "DURATION";
private static final String UEVENTD = "ueventd";
private static final String INIT = "init";
@@ -75,13 +74,21 @@ public class DmesgParser implements IParser {
// Matches: init: processing action (early-init) from (/init.rc:14)
private static final String START_PROCESSING_ACTION_PREFIX =
- String.format("processing action \\((?<%s>[^)]*)\\)( from \\((?<%s>.*)\\)|.*)$",
- ACTION, SOURCE);
+ String.format("processing action \\((?<%s>.*)\\) from.*$", ACTION);
+
+ // Matches: init: processing action (early-init)
+ 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: 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(
"(?<%s>.*)\\s+took\\s+(?<%s>.*)\\s+seconds$", STAGE, DURATION);
@@ -235,11 +242,9 @@ 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();
- if (match.group(SOURCE) != null) {
- actionInfoItem.setSourceName(match.group(SOURCE));
- }
actionInfoItem.setActionName(match.group(ACTION));
actionInfoItem.setStartTime((long) (Double.parseDouble(
match.group(TIMESTAMP)) * 1000));
diff --git a/src/com/android/loganalysis/parser/TimingsLogParser.java b/src/com/android/loganalysis/parser/TimingsLogParser.java
deleted file mode 100644
index ee3535f..0000000
--- a/src/com/android/loganalysis/parser/TimingsLogParser.java
+++ /dev/null
@@ -1,246 +0,0 @@
-/*
- * Copyright (C) 2019 The Android Open Source Project
- *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License
- */
-
-package com.android.loganalysis.parser;
-
-
-import com.android.loganalysis.item.GenericTimingItem;
-import com.android.loganalysis.item.IItem;
-import com.android.loganalysis.item.SystemServicesTimingItem;
-
-import java.io.BufferedReader;
-import java.io.IOException;
-import java.text.DateFormat;
-import java.text.ParseException;
-import java.text.SimpleDateFormat;
-import java.util.ArrayList;
-import java.util.HashMap;
-import java.util.HashSet;
-import java.util.List;
-import java.util.Map;
-import java.util.Set;
-import java.util.regex.Matcher;
-import java.util.regex.Pattern;
-
-/**
- * An {@link IParser} to parse boot metrics from logcat. It currently assumes "threadtime" format of
- * logcat. It will parse duration metrics for some system services like System Server, Zygote,
- * System UI, e.t.c.
- *
- */
-public class TimingsLogParser implements IParser {
-
- private static final String SYSTEM_SERVICES_TIME_PREFIX =
- "^\\d*-\\d*\\s*\\d*:\\d*:\\d*.\\d*\\s*"
- + "\\d*\\s*\\d*\\s*D\\s*(?<componentname>.*):\\s*(?<subname>\\S*)\\s*";
- private static final String SYSTEM_SERVICES_TIME_SUFFIX = ":\\s*(?<time>.*)ms\\s*$";
-
- /** Used to parse time info from logcat lines */
- private static final DateFormat DEFAULT_TIME_FORMAT =
- new SimpleDateFormat("yyyy-MM-dd HH:mm:ss.SSS");
-
- /**
- * Year is not important in timing info. Always use Unix time starting year for timestamp
- * conversion with simplicity
- */
- private static final String DEFAULT_YEAR = "1970";
-
- /**
- * Match the line with system services duration info like:
- *
- * <p>03-10 21:43:40.328 1005 1005 D SystemServerTiming:
- * StartKeyAttestationApplicationIdProviderService took to complete: 3474ms
- */
- private static final Pattern SYSTEM_SERVICES_DURATION =
- Pattern.compile(
- String.format(
- "%stook to complete%s",
- SYSTEM_SERVICES_TIME_PREFIX, SYSTEM_SERVICES_TIME_SUFFIX));
- /**
- * Match the line with system services start time info like:
- *
- * <p>01-10 01:25:57.249 989 989 D BootAnimation: BootAnimationStartTiming start time: 8343ms
- */
- private static final Pattern SYSTEM_SERVICES_START_TIME =
- Pattern.compile(
- String.format(
- "%sstart time%s",
- SYSTEM_SERVICES_TIME_PREFIX, SYSTEM_SERVICES_TIME_SUFFIX));
-
- private List<DurationPattern> durationPatterns = new ArrayList<>();
-
- private static class DurationPattern {
- String mName;
- Pattern mStartTimePattern;
- Pattern mEndTimePattern;
-
- DurationPattern(String name, Pattern startTimePattern, Pattern endTimePattern) {
- mName = name;
- mStartTimePattern = startTimePattern;
- mEndTimePattern = endTimePattern;
- }
- }
-
- @Override
- public IItem parse(List<String> lines) {
- throw new UnsupportedOperationException(
- "Method has not been implemented in lieu of others");
- }
-
- /**
- * Add a pair of patterns matching the start and end signals in logcat for a duration metric
- *
- * @param name the name of the duration metric, it should be unique
- * @param startTimePattern the pattern matches the logcat line indicating start of duration
- * @param endTimePattern the pattern matches the logcat line indicating end of duration
- */
- public void addDurationPatternPair(
- String name, Pattern startTimePattern, Pattern endTimePattern) {
- DurationPattern durationPattern =
- new DurationPattern(name, startTimePattern, endTimePattern);
- durationPatterns.add(durationPattern);
- }
-
- /** Cleanup added duration patterns */
- public void clearDurationPatterns() {
- durationPatterns.clear();
- }
-
- /**
- * Parse logcat lines with the added duration patterns and generate a list of {@link
- * GenericTimingItem} representing the duration items. Note, a duration pattern could have zero
- * or multiple matches
- *
- * @param input logcat lines
- * @return list of {@link GenericTimingItem}
- * @throws IOException
- */
- public List<GenericTimingItem> parseGenericTimingItems(BufferedReader input)
- throws IOException {
- List<GenericTimingItem> items = new ArrayList<>();
- String line;
- //Timing items that are partially matched after captured start time
- Map<String, Double> pendingItems = new HashMap<>();
- while ((line = input.readLine()) != null) {
- items.addAll(parseGenericTimingItem(line, pendingItems));
- }
- return items;
- }
-
- /**
- * Parse a particular logcat line to get duration items. One line could have be matched by
- * multiple patterns
- *
- * @param line logcat line
- * @param pendingItems timing items that are half-matched with only start time.
- * @return list of {@link GenericTimingItem}
- */
- private List<GenericTimingItem> parseGenericTimingItem(
- String line, Map<String, Double> pendingItems) {
- List<GenericTimingItem> items = new ArrayList<>();
- for (DurationPattern durationPattern : durationPatterns) {
- Matcher matcher = durationPattern.mStartTimePattern.matcher(line);
- if (matcher.find()) {
- double startTimeMillis = parseTime(line);
- pendingItems.put(durationPattern.mName, startTimeMillis);
- continue;
- }
- matcher = durationPattern.mEndTimePattern.matcher(line);
- if (matcher.find()) {
- double endTimeMillis = parseTime(line);
- Double startTimeMillis = pendingItems.get(durationPattern.mName);
- if (startTimeMillis != null) {
- GenericTimingItem newItem = new GenericTimingItem();
- newItem.setName(durationPattern.mName);
- newItem.setStartAndEnd(startTimeMillis, endTimeMillis);
- items.add(newItem);
- pendingItems.remove(durationPattern.mName);
- }
- }
- }
- return items;
- }
-
- /**
- * Get timestamp of current logcat line based on DEFAULT_YEAR
- *
- * @param line logcat line
- * @return timestamp
- */
- private double parseTime(String line) {
- String timeStr = String.format("%s-%s", DEFAULT_YEAR, line);
- try {
- return DEFAULT_TIME_FORMAT.parse(timeStr).getTime();
- } catch (ParseException e) {
- throw new RuntimeException(e);
- }
- }
-
- /**
- * A method that parses the logcat input for system services timing information. It will ignore
- * duplicated log lines and will keep multiple values for the same timing metric generated at
- * different time in the log
- *
- * @param input Logcat input as a {@link BufferedReader}
- * @return a list of {@link SystemServicesTimingItem}
- * @throws IOException
- */
- public List<SystemServicesTimingItem> parseSystemServicesTimingItems(BufferedReader input)
- throws IOException {
- Set<String> matchedLines = new HashSet<>();
- List<SystemServicesTimingItem> items = new ArrayList<>();
- String line;
- while ((line = input.readLine()) != null) {
- if (matchedLines.contains(line)) {
- continue;
- }
- SystemServicesTimingItem item = parseSystemServicesTimingItem(line);
- if (item == null) {
- continue;
- }
- items.add(item);
- matchedLines.add(line);
- }
- return items;
- }
-
- /**
- * Parse a particular log line to see if it matches the system service timing pattern and return
- * a {@link SystemServicesTimingItem} if matches, otherwise return null.
- *
- * @param line a single log line
- * @return a {@link SystemServicesTimingItem}
- */
- private SystemServicesTimingItem parseSystemServicesTimingItem(String line) {
- Matcher matcher = SYSTEM_SERVICES_DURATION.matcher(line);
- boolean durationMatched = matcher.matches();
- if (!durationMatched) {
- matcher = SYSTEM_SERVICES_START_TIME.matcher(line);
- }
- if (!matcher.matches()) {
- return null;
- }
- SystemServicesTimingItem item = new SystemServicesTimingItem();
- item.setComponent(matcher.group("componentname").trim());
- item.setSubcomponent(matcher.group("subname").trim());
- if (durationMatched) {
- item.setDuration(Double.parseDouble(matcher.group("time")));
- } else {
- item.setStartTime(Double.parseDouble(matcher.group("time")));
- }
- return item;
- }
-}
diff --git a/tests/src/com/android/loganalysis/UnitTests.java b/tests/src/com/android/loganalysis/UnitTests.java
index 35359ba..68d5bf6 100644
--- a/tests/src/com/android/loganalysis/UnitTests.java
+++ b/tests/src/com/android/loganalysis/UnitTests.java
@@ -37,7 +37,6 @@ import com.android.loganalysis.parser.BatteryDischargeStatsInfoParserTest;
import com.android.loganalysis.parser.BatteryStatsDetailedInfoParserTest;
import com.android.loganalysis.parser.BatteryStatsSummaryInfoParserTest;
import com.android.loganalysis.parser.BatteryUsageParserTest;
-import com.android.loganalysis.parser.TimingsLogParserTest;
import com.android.loganalysis.parser.BugreportParserTest;
import com.android.loganalysis.parser.CompactMemInfoParserTest;
import com.android.loganalysis.parser.CpuInfoParserTest;
@@ -125,7 +124,6 @@ import org.junit.runners.Suite.SuiteClasses;
BatteryStatsDetailedInfoParserTest.class,
BatteryStatsSummaryInfoParserTest.class,
BatteryUsageParserTest.class,
- TimingsLogParserTest.class,
BugreportParserTest.class,
CompactMemInfoParserTest.class,
CpuInfoParserTest.class,
diff --git a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java
index 4362c7a..7cdbd36 100644
--- a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java
+++ b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java
@@ -215,15 +215,22 @@ public class DmesgParserTest extends TestCase {
private static List<DmesgActionInfoItem> getExpectedActionInfoItems() {
return Arrays.asList(
- new DmesgActionInfoItem("/init.rc:13", "early-init", 44942L),
- new DmesgActionInfoItem("<Builtin Action>:0", "set_mmap_rnd_bits", 47233L),
- new DmesgActionInfoItem("<Builtin Action>:0", "set_kptr_restrict", 47240L),
- new DmesgActionInfoItem("<Builtin Action>:0", "keychord_init", 47245L),
- new DmesgActionInfoItem("<Builtin Action>:0", "persist.sys.usb.config=* boot", 52361L),
- new DmesgActionInfoItem("<Builtin Action>:0", "enable_property_trigger", 52361L),
- new DmesgActionInfoItem("/init.rc:677", "security.perf_harden=1", 52361L),
- new DmesgActionInfoItem("/init.rc:700", "ro.debuggable=1", 52361L),
- new DmesgActionInfoItem(null, "sys.boot_completed=1", 58298L));
+ 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("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(
+ "sys.boot_completed=1", (long) (Double.parseDouble("58298.293"))));
}
private static List<DmesgStageInfoItem> getExpectedStageInfoItems() {
diff --git a/tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java b/tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java
deleted file mode 100644
index 48881ea..0000000
--- a/tests/src/com/android/loganalysis/parser/TimingsLogParserTest.java
+++ /dev/null
@@ -1,354 +0,0 @@
-/*
- * Copyright (C) 2019 The Android Open Source Project
- *
- * Licensed under the Apache License, Version 2.0 (the "License");
- * you may not use this file except in compliance with the License.
- * You may obtain a copy of the License at
- *
- * http://www.apache.org/licenses/LICENSE-2.0
- *
- * Unless required by applicable law or agreed to in writing, software
- * distributed under the License is distributed on an "AS IS" BASIS,
- * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
- * See the License for the specific language governing permissions and
- * limitations under the License
- */
-
-package com.android.loganalysis.parser;
-
-import com.android.loganalysis.item.GenericTimingItem;
-import com.android.loganalysis.item.SystemServicesTimingItem;
-
-import junit.framework.TestCase;
-
-import java.io.BufferedReader;
-import java.io.ByteArrayInputStream;
-import java.io.IOException;
-import java.io.InputStream;
-import java.io.InputStreamReader;
-import java.util.List;
-import java.util.regex.Pattern;
-
-/** Unit Test for {@link TimingsLogParser} */
-public class TimingsLogParserTest extends TestCase {
-
- private TimingsLogParser mParser;
-
- public TimingsLogParserTest() {
- mParser = new TimingsLogParser();
- }
-
- public void testParseGenericTiming_noPattern() throws IOException {
- // Test when input is empty
- String log = "";
- List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(0, items.size());
- // Test when input is not empty
- log =
- String.join(
- "\n",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface",
- "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support",
- "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0",
- "01-17 01:22:59.966 0 0 I init : processing action (sys.boot_completed=1) from (/init.rc:796)");
- items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(0, items.size());
- }
-
- public void testParseGenericTiming_multiplePattern_oneOccurrenceEach() throws IOException {
- String log =
- String.join(
- "\n",
- "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface",
- "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support",
- "01-17 01:22:43.634 0 0 I init : starting service 'zygote'...",
- "01-17 01:22:48.634 0 0 I init : 'zygote' started",
- "01-17 01:22:53.392 0 0 I init : starting service 'fake service'",
- "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0",
- "01-17 01:22:60.334 0 0 I init : 'fake service' started",
- "01-17 01:22:61.362 938 1111 I ActivityManager: my app started",
- "01-17 01:22:61.977 938 1111 I ActivityManager: my app displayed");
-
- mParser.addDurationPatternPair(
- "BootToAnimEnd",
- Pattern.compile("Linux version"),
- Pattern.compile("Service 'bootanim'"));
- mParser.addDurationPatternPair(
- "ZygoteStartTime",
- Pattern.compile("starting service 'zygote'"),
- Pattern.compile("'zygote' started"));
- mParser.addDurationPatternPair(
- "FakeServiceStartTime",
- Pattern.compile("starting service 'fake service'"),
- Pattern.compile("'fake service' started"));
- mParser.addDurationPatternPair(
- "BootToAppStart",
- Pattern.compile("Linux version"),
- Pattern.compile("my app displayed"));
- mParser.addDurationPatternPair(
- "AppStartTime",
- Pattern.compile("my app started"),
- Pattern.compile("my app displayed"));
- mParser.addDurationPatternPair(
- "ZygoteToApp",
- Pattern.compile("'zygote' started"),
- Pattern.compile("my app started"));
- List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(6, items.size());
- // 1st item
- assertEquals("ZygoteStartTime", items.get(0).getName());
- assertEquals(5000.0, items.get(0).getDuration());
- // 2nd item
- assertEquals("BootToAnimEnd", items.get(1).getName());
- assertEquals(20320.0, items.get(1).getDuration());
- // 3rd item
- assertEquals("FakeServiceStartTime", items.get(2).getName());
- assertEquals(6942.0, items.get(2).getDuration());
- // 4th item
- assertEquals("ZygoteToApp", items.get(3).getName());
- assertEquals(12728.0, items.get(3).getDuration());
- // 5th item
- assertEquals("BootToAppStart", items.get(4).getName());
- assertEquals(22474.0, items.get(4).getDuration());
- // 6th item
- assertEquals("AppStartTime", items.get(5).getName());
- assertEquals(615.0, items.get(5).getDuration());
- }
-
- public void testParseGenericTiming_multiplePattern_someNotMatched() throws IOException {
- String log =
- String.join(
- "\n",
- "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface",
- "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support",
- "01-17 01:22:43.634 0 0 I init : starting service 'zygote'...",
- "01-17 01:22:48.634 0 0 I init : 'zygote' started",
- "01-17 01:22:53.392 0 0 I init : starting service 'fake service'",
- "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0",
- "01-17 01:22:60.334 0 0 I init : 'fake service' started",
- "01-17 01:22:61.362 938 1111 I ActivityManager: my app started",
- "01-17 01:22:61.977 938 1111 I ActivityManager: my app displayed");
-
- mParser.addDurationPatternPair(
- "BootToAnimEnd",
- Pattern.compile("Linux version"),
- Pattern.compile("Service 'bootanim'"));
- mParser.addDurationPatternPair(
- "ZygoteStartTime",
- Pattern.compile("starting service 'zygote'"),
- Pattern.compile("End line no there"));
- mParser.addDurationPatternPair(
- "FakeServiceStartTime",
- Pattern.compile("Start line not there"),
- Pattern.compile("'fake service' started"));
- mParser.addDurationPatternPair(
- "AppStartTime",
- Pattern.compile("Start line not there"),
- Pattern.compile("End line not there"));
-
- List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(1, items.size());
- assertEquals("BootToAnimEnd", items.get(0).getName());
- }
-
- public void testParseGenericTiming_clearExistingPatterns() throws IOException {
- String log =
- String.join(
- "\n",
- "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)",
- "01-17 01:22:53.392 0 0 I init : starting service 'fake service'",
- "01-17 01:22:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0",
- "01-17 01:22:60.334 0 0 I init : 'fake service' started",
- "01-17 01:22:61.362 938 1111 I ActivityManager: my app started",
- "01-17 01:22:61.977 938 1111 I ActivityManager: my app displayed");
- mParser.addDurationPatternPair(
- "BootToAnimEnd",
- Pattern.compile("Linux version"),
- Pattern.compile("Service 'bootanim'"));
- List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(1, items.size());
-
- mParser.clearDurationPatterns();
- items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(0, items.size());
- }
-
- public void testParseGenericTiming_multiplePattern_multipleOccurrence() throws IOException {
- String log =
- String.join(
- "\n",
- "01-17 01:22:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface",
- "01-17 01:22:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option",
- "01-17 01:22:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support",
- "01-17 01:22:43.634 0 0 I init : starting service 'zygote'...",
- "01-17 01:22:48.634 0 0 I init : 'zygote' started",
- "01-17 01:22:53.392 0 0 I init : starting service 'fake service'",
- "01-17 01:22:59.823 0 0 I init : 'bootanim' not reported",
- "01-17 01:22:60.334 0 0 I init : 'fake service' started",
- "01-17 01:32:39.503 0 0 I : Linux version 4.4.177 (Kernel Boot Started)",
- "01-17 01:32:39.513 0 0 I CPU features: detected feature: GIC system register CPU interface",
- "01-17 01:32:39.513 0 0 I CPU features: kernel page table isolation forced ON by command line option",
- "01-17 01:32:39.513 0 0 I CPU features: detected feature: 32-bit EL0 Support",
- "01-17 01:32:43.634 0 0 I init : starting service 'zygote'...",
- "01-17 01:32:48.634 0 0 I init : 'zygote' started",
- "01-17 01:32:53.392 0 0 I init : starting service 'a different service'",
- "01-17 01:32:59.823 0 0 I init : Service 'bootanim' (pid 1030) exited with status 0",
- "01-17 01:32:60.334 0 0 I init : 'fake service' started",
- "01-17 01:32:61.362 938 1111 I ActivityManager: my app started",
- "01-17 01:32:61.977 938 1111 I ActivityManager: my app displayed");
-
- mParser.addDurationPatternPair(
- "BootToAnimEnd",
- Pattern.compile("Linux version"),
- Pattern.compile("Service 'bootanim'"));
- mParser.addDurationPatternPair(
- "ZygoteStartTime",
- Pattern.compile("starting service 'zygote'"),
- Pattern.compile("'zygote' started"));
- mParser.addDurationPatternPair(
- "FakeServiceStartTime",
- Pattern.compile("starting service 'fake service'"),
- Pattern.compile("'fake service' started"));
- mParser.addDurationPatternPair(
- "AppStartTime",
- Pattern.compile("my app started"),
- Pattern.compile("my app displayed"));
- List<GenericTimingItem> items = mParser.parseGenericTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(5, items.size());
- // 1st item
- assertEquals("ZygoteStartTime", items.get(0).getName());
- assertEquals(5000.0, items.get(0).getDuration());
- // 2nd item
- assertEquals("FakeServiceStartTime", items.get(1).getName());
- assertEquals(6942.0, items.get(1).getDuration());
- // 3rd item
- assertEquals("ZygoteStartTime", items.get(2).getName());
- assertEquals(5000.0, items.get(2).getDuration());
- // 4th item
- assertEquals("BootToAnimEnd", items.get(3).getName());
- assertEquals(20320.0, items.get(3).getDuration());
- // 5th item
- assertEquals("AppStartTime", items.get(4).getName());
- assertEquals(615.0, items.get(4).getDuration());
- }
-
- public void testParseGenericTiming_wrongTimeFormat() throws IOException {
- String log =
- String.join(
- "\n",
- "1234252.234 0 0 I : Linux version 4.4.177 (Kernel Boot Started)",
- "1234259.342 0 0 I CPU features: detected feature: GIC system register CPU interface");
- mParser.addDurationPatternPair(
- "BootToAnimEnd",
- Pattern.compile("Linux version"),
- Pattern.compile("Service 'bootanim'"));
- try {
- List<GenericTimingItem> items =
- mParser.parseGenericTimingItems(createBufferedReader(log));
- } catch (RuntimeException e) {
- assertTrue(
- "Test should report ParseException",
- e.getCause().toString().startsWith("java.text.ParseException"));
- return;
- }
- fail("Test should throw ParseException");
- }
-
- /** Test that system services duration can be parsed as expected */
- public void testParseSystemServicesTiming_system_services_duration() throws IOException {
- String log =
- String.join(
- "\n",
- "01-10 01:25:57.675 981 981 D SystemServerTiming: StartWatchdog took to complete: 38ms",
- "01-10 01:25:57.675 981 981 I SystemServer: Reading configuration...",
- "01-10 01:25:57.675 981 981 I SystemServer: ReadingSystemConfig",
- "01-10 01:25:57.676 981 981 D SystemServerTiming: ReadingSystemConfig took to complete: 0.53ms",
- "01-10 01:25:57.676 981 981 D SystemServerTiming: ReadingSystemConfig took to complete: 0.53ms", // Parser should skip duplicated log line
- "01-10 01:25:57.677 465 465 I snet_event_log: [121035042,-1,]",
- "01-10 01:25:57.678 900 900 I FakeComponent: FakeSubcomponent wrong format took to complete: 10ms",
- "01-10 01:25:57.678 900 900 I FakeComponent: FakeSubcomponent took to complete: 20s",
- "01-10 01:25:57.680 981 981 D SystemServerTiming: StartInstaller took to complete: 5ms wrong format",
- "01-10 01:25:57.682 981 981 D SystemServerTiming: DeviceIdentifiersPolicyService took to complete: 2ms",
- "01-10 01:25:57.682 981 981 D SystemServerTiming: DeviceIdentifiersPolicyService took to complete: 2ms",
- "06-06 19:23:54.410 1295 1295 D OtherService : StartTestStack took to complete: 7ms",
- "06-06 19:23:55.410 129 129 D FakeService : Validtook to complete: 8ms",
- "06-06 19:23:56.410 981 981 D SystemServerTiming: StartWatchdog took to complete: 38ms"); //Parser should parse the same metric at a different time
-
- List<SystemServicesTimingItem> items =
- mParser.parseSystemServicesTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(6, items.size());
- assertEquals("SystemServerTiming", items.get(0).getComponent());
- assertEquals(38.0, items.get(0).getDuration());
- assertNull(items.get(0).getStartTime());
- assertEquals("ReadingSystemConfig", items.get(1).getSubcomponent());
- assertEquals(0.53, items.get(1).getDuration());
- assertNull(items.get(1).getStartTime());
- assertEquals("DeviceIdentifiersPolicyService", items.get(2).getSubcomponent());
- assertEquals("OtherService", items.get(3).getComponent());
- assertEquals("StartTestStack", items.get(3).getSubcomponent());
- assertEquals(7.0, items.get(3).getDuration());
- assertEquals("FakeService", items.get(4).getComponent());
- assertEquals("Valid", items.get(4).getSubcomponent());
- assertEquals(8.0, items.get(4).getDuration());
- assertNull(items.get(4).getStartTime());
- assertEquals("SystemServerTiming", items.get(5).getComponent());
- assertEquals("StartWatchdog", items.get(5).getSubcomponent());
- assertEquals(38.0, items.get(5).getDuration());
- }
-
- /** Test that system services start time can be parsed as expected */
- public void testParseSystemServicesTiming_system_services_start_time() throws IOException {
- String log =
- String.join(
- "\n",
- "01-10 01:24:45.536 1079 1079 D BootAnimation: BootAnimationStartTiming start time: 8611ms",
- "01-10 01:24:45.537 1079 1079 D BootAnimation: BootAnimationPreloadTiming start time: 8611ms",
- "01-10 01:24:45.556 874 1021 I ServiceManager: Waiting for service 'package_native' on '/dev/binder'...",
- "01-10 01:24:45.561 466 466 I snet_event_log: [121035042,-1,]",
- "01-10 01:24:45.583 1080 1080 I SystemServer: InitBeforeStartServices start time: 2345ms wrong format",
- "01-10 01:25:24.095 1014 1111 D BootAnimation: BootAnimationShownTiming start time: 9191s",
- "06-06 19:23:49.299 603 603 E qdmetadata: Unknown paramType 2",
- "06-06 19:23:49.299 603 603 I FakeComponent : wrong subcomponent start time: 234ms",
- "06-06 19:23:49.299 603 603 D FakeComponent: Subcomponent start time 234ms",
- "06-06 19:23:49.299 1079 1079 D BootAnimation: BootAnimationStopTiming start time: 24839ms",
- "06-06 19:23:59.299 179 179 D FakeService : Validstart time: 34839ms");
-
- List<SystemServicesTimingItem> items =
- mParser.parseSystemServicesTimingItems(createBufferedReader(log));
- assertNotNull(items);
- assertEquals(4, items.size());
- assertEquals("BootAnimation", items.get(0).getComponent());
- assertEquals("BootAnimationStartTiming", items.get(0).getSubcomponent());
- assertEquals(8611.0, items.get(0).getStartTime());
- assertNull(items.get(0).getDuration());
- assertEquals("BootAnimationPreloadTiming", items.get(1).getSubcomponent());
- assertEquals("BootAnimation", items.get(2).getComponent());
- assertEquals("BootAnimationStopTiming", items.get(2).getSubcomponent());
- assertEquals(24839.0, items.get(2).getStartTime());
- assertNull(items.get(2).getDuration());
- assertEquals("FakeService", items.get(3).getComponent());
- assertEquals("Valid", items.get(3).getSubcomponent());
- assertEquals(34839.0, items.get(3).getStartTime());
- assertNull(items.get(3).getDuration());
- }
-
- private BufferedReader createBufferedReader(String input) {
- InputStream inputStream = new ByteArrayInputStream(input.getBytes());
- InputStreamReader reader = new InputStreamReader(inputStream);
- return new BufferedReader(reader);
- }
-}