diff options
author | Shankhoneer Chakrovarty <shankh@google.com> | 2017-02-21 14:46:08 -0800 |
---|---|---|
committer | Shankhoneer Chakrovarty <shankh@google.com> | 2017-02-24 12:01:00 -0800 |
commit | fd5106da20d44fb307aa9d6c37c14cc7dbacbe86 (patch) | |
tree | b52a0ec12b66327aa34f3a894657e023f042725d | |
parent | bd097c98fff4ad8c2a3dc8367b580dfdd0702c77 (diff) | |
download | loganalysis-fd5106da20d44fb307aa9d6c37c14cc7dbacbe86.tar.gz |
Improved dmesg parser
The improved parser captures info on:
1. boot stage
2. action processing time
BUG:35469489
Change-Id: Ice32079b96373d18036296097a140d5bc0d2ec33
-rw-r--r-- | src/com/android/loganalysis/item/DmesgActionInfoItem.java | 87 | ||||
-rw-r--r-- | src/com/android/loganalysis/item/DmesgServiceInfoItem.java (renamed from src/com/android/loganalysis/item/ServiceInfoItem.java) | 8 | ||||
-rw-r--r-- | src/com/android/loganalysis/item/DmesgStageInfoItem.java | 87 | ||||
-rw-r--r-- | src/com/android/loganalysis/parser/DmesgParser.java | 155 | ||||
-rw-r--r-- | tests/src/com/android/loganalysis/parser/DmesgParserTest.java | 231 |
5 files changed, 458 insertions, 110 deletions
diff --git a/src/com/android/loganalysis/item/DmesgActionInfoItem.java b/src/com/android/loganalysis/item/DmesgActionInfoItem.java new file mode 100644 index 0000000..ac73b8e --- /dev/null +++ b/src/com/android/loganalysis/item/DmesgActionInfoItem.java @@ -0,0 +1,87 @@ +/* + * Copyright (C) 2017 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 action info logged in dmesg + * For example: [ 14.942872] init: processing action (early-init) + */ +public class DmesgActionInfoItem extends GenericItem { + + /** 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( + ACTION_NAME, ACTION_START_TIME)); + + /** + * The constructor for {@link DmesgActionInfoItem}. + */ + public DmesgActionInfoItem() { + super(ATTRIBUTES); + } + + /** + * The constructor for {@link DmesgActionInfoItem}. + */ + public DmesgActionInfoItem(String name, Long startTime) { + super(ATTRIBUTES); + setAttribute(ACTION_NAME, name); + setAttribute(ACTION_START_TIME, startTime); + } + + /** + * Get the name of the action + */ + public String getActionName() { + return (String) getAttribute(ACTION_NAME); + } + + /** + * Set the name of the action + */ + public void setActionName(String stageName) { + setAttribute(ACTION_NAME, stageName); + } + + /** + * Get the start time in msecs + */ + public Long getStartTime() { + return (Long) getAttribute(ACTION_START_TIME); + } + + /** + * Set the start time in msecs + */ + public void setStartTime(Long startTime) { + setAttribute(ACTION_START_TIME, startTime); + } + + @Override + public String toString() { + return "ActionInfoItem [getActionName()=" + getActionName() + ", getStartTime()=" + + getStartTime() + "]"; + } + +} diff --git a/src/com/android/loganalysis/item/ServiceInfoItem.java b/src/com/android/loganalysis/item/DmesgServiceInfoItem.java index 62a89f5..832cd1a 100644 --- a/src/com/android/loganalysis/item/ServiceInfoItem.java +++ b/src/com/android/loganalysis/item/DmesgServiceInfoItem.java @@ -21,9 +21,9 @@ import java.util.HashSet; import java.util.Set; /** - * An {@link IItem} used to store service info logged in dmesg + * An {@link IItem} used to store service info logged in dmesg. */ -public class ServiceInfoItem extends GenericItem { +public class DmesgServiceInfoItem extends GenericItem { /** Constant for JSON output */ public static final String SERVICE_NAME = "SERVICE_NAME"; @@ -38,9 +38,9 @@ public class ServiceInfoItem extends GenericItem { SERVICE_NAME, SERVICE_START_TIME, SERVICE_END_TIME)); /** - * The constructor for {@link ServiceInfoItem}. + * The constructor for {@link DmesgServiceInfoItem}. */ - public ServiceInfoItem() { + public DmesgServiceInfoItem() { super(ATTRIBUTES); } diff --git a/src/com/android/loganalysis/item/DmesgStageInfoItem.java b/src/com/android/loganalysis/item/DmesgStageInfoItem.java new file mode 100644 index 0000000..a5bfd39 --- /dev/null +++ b/src/com/android/loganalysis/item/DmesgStageInfoItem.java @@ -0,0 +1,87 @@ +/* + * Copyright (C) 2017 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 stage info logged in dmesg. + * For example: [ 14.425056] init: init second stage started! + */ +public class DmesgStageInfoItem extends GenericItem { + + /** Constant for JSON output */ + public static final String STAGE_NAME = "STAGE_NAME"; + /** Constant for JSON output */ + public static final String STAGE_START_TIME = "STAGE_START_TIME"; + + private static final Set<String> ATTRIBUTES = new HashSet<String>(Arrays.asList( + STAGE_NAME, STAGE_START_TIME)); + + /** + * The constructor for {@link DmesgStageInfoItem}. + */ + public DmesgStageInfoItem() { + super(ATTRIBUTES); + } + + /** + * The constructor for {@link DmesgStageInfoItem}. + */ + public DmesgStageInfoItem(String name, Long startTime) { + super(ATTRIBUTES); + setAttribute(STAGE_NAME, name); + setAttribute(STAGE_START_TIME, startTime); + } + + /** + * Get the name of the stage + */ + public String getStageName() { + return (String) getAttribute(STAGE_NAME); + } + + /** + * Set the name of the stage + */ + public void setStageName(String stageName) { + setAttribute(STAGE_NAME, stageName); + } + + /** + * Get the start time in msecs + */ + public Long getStartTime() { + return (Long) getAttribute(STAGE_START_TIME); + } + + /** + * Set the start time in msecs + */ + public void setStartTime(Long startTime) { + setAttribute(STAGE_START_TIME, startTime); + } + + @Override + public String toString() { + return "StageInfoItem [getStageName()=" + getStageName() + ", getStartTime()=" + + getStartTime() + "]"; + } + +} diff --git a/src/com/android/loganalysis/parser/DmesgParser.java b/src/com/android/loganalysis/parser/DmesgParser.java index 51fb2e2..8bca919 100644 --- a/src/com/android/loganalysis/parser/DmesgParser.java +++ b/src/com/android/loganalysis/parser/DmesgParser.java @@ -16,11 +16,14 @@ package com.android.loganalysis.parser; +import com.android.loganalysis.item.DmesgActionInfoItem; import com.android.loganalysis.item.IItem; -import com.android.loganalysis.item.ServiceInfoItem; - +import com.google.common.annotations.VisibleForTesting; +import com.android.loganalysis.item.DmesgServiceInfoItem; +import com.android.loganalysis.item.DmesgStageInfoItem; import java.io.BufferedReader; import java.io.IOException; +import java.rmi.server.ServerCloneException; import java.util.ArrayList; import java.util.HashMap; import java.util.List; @@ -36,6 +39,8 @@ public class DmesgParser implements IParser { private static final String SERVICENAME = "SERVICENAME"; private static final String TIMESTAMP = "TIMESTAMP"; + private static final String STAGE = "STAGE"; + private static final String ACTION = "ACTION"; // Matches: [ 14.822691] init: private static final String SERVICE_PREFIX = String.format("^\\[\\s+(?<%s>.*)\\] init:\\s+", TIMESTAMP); @@ -51,7 +56,29 @@ public class DmesgParser implements IParser { private static final Pattern EXIT_SERVICE = Pattern.compile( String.format("%s%s", SERVICE_PREFIX, EXIT_SERVICE_SUFFIX)); - private Map<String, ServiceInfoItem> mServiceInfoItems = new HashMap<String, ServiceInfoItem>(); + // Matches: init first stage started! + // Matches: init second stage started! + private static final String START_STAGE_PREFIX = String.format("init (?<%s>.*) stage started!", + STAGE); + + // Matches: [ 13.647997] init: init first stage started! + private static final Pattern START_STAGE = Pattern.compile( + String.format("%s%s", SERVICE_PREFIX, START_STAGE_PREFIX)); + + // Matches: init: processing action (early-init) + // must not match: init: processing action (vold.decrypt=trigger_restart_framework) + private static final String START_PROCESSING_ACTION_PREFIX = String.format( + "processing action \\((?<%s>[^=]+)\\)", ACTION); + + // Matches: [ 14.942872] init: processing action (early-init) + // Does not match: [ 22.361049] init: processing action (persist.sys.usb.config=* boot) + private static final Pattern START_PROCESSING_ACTION = Pattern.compile( + String.format("%s%s", SERVICE_PREFIX, START_PROCESSING_ACTION_PREFIX)); + + private Map<String, DmesgServiceInfoItem> mServiceInfoItems = + new HashMap<String, DmesgServiceInfoItem>(); + private List<DmesgStageInfoItem> mStageInfoItems = new ArrayList<>(); + private List<DmesgActionInfoItem> mActionInfoItems = new ArrayList<>(); @Override public IItem parse(List<String> lines) { @@ -60,34 +87,102 @@ public class DmesgParser implements IParser { } /** - * Parse init services start time and end time from dmesg logs and store the duration it took to - * complete the service if the end time stamp is available. + * Parse the kernel log till EOF to retrieve the duration of the service calls, start times of + * different boot stages and actions taken. Besides, while parsing these informations are stored + * in the intermediate {@link DmesgServiceInfoItem}, {@link DmesgStageInfoItem} and + * {@link DmesgActionInfoItem} objects * - * @param input dmesg logs - * @return list of ServiceInfoItems which contains service start and end time + * @param input dmesg log * @throws IOException */ - public List<ServiceInfoItem> parseServiceInfo(BufferedReader input) - throws IOException { + public void parseInfo(BufferedReader bufferedLog) throws IOException { String line; - while ((line = input.readLine()) != null) { - Matcher match = null; - if ((match = matches(START_SERVICE, line)) != null) { - ServiceInfoItem serviceItem = new ServiceInfoItem(); - serviceItem.setServiceName(match.group(SERVICENAME)); - serviceItem.setStartTime((long) (Double.parseDouble( + while ((line = bufferedLog.readLine()) != null) { + if (parseServiceInfo(line)) { + continue; + } + if (parseStageInfo(line)) { + continue; + } + if (parseActionInfo(line)) { + continue; + } + } + } + + /** + * Parse init services {@code start time} and {@code end time} from each {@code line} of dmesg + * log and store the {@code duration} it took to complete the service if the end time stamp is + * available in {@link DmesgServiceInfoItem}. + * + * @param individual line of the dmesg log + * @return {@code true}, if the {@code line} indicates start or end of a service, + * {@code false}, otherwise + */ + @VisibleForTesting + boolean parseServiceInfo(String line) { + Matcher match = null; + if ((match = matches(START_SERVICE, line)) != null) { + DmesgServiceInfoItem serviceItem = new DmesgServiceInfoItem(); + serviceItem.setServiceName(match.group(SERVICENAME)); + serviceItem.setStartTime((long) (Double.parseDouble( + match.group(TIMESTAMP)) * 1000)); + getServiceInfoItems().put(match.group(SERVICENAME), serviceItem); + return true; + } else if ((match = matches(EXIT_SERVICE, line)) != null) { + if (getServiceInfoItems().containsKey(match.group(SERVICENAME))) { + DmesgServiceInfoItem serviceItem = getServiceInfoItems().get( + match.group(SERVICENAME)); + serviceItem.setEndTime((long) (Double.parseDouble( match.group(TIMESTAMP)) * 1000)); - getServiceInfoItems().put(match.group(SERVICENAME), serviceItem); - } else if ((match = matches(EXIT_SERVICE, line)) != null) { - if (getServiceInfoItems().containsKey(match.group(SERVICENAME))) { - ServiceInfoItem serviceItem = getServiceInfoItems().get( - match.group(SERVICENAME)); - serviceItem.setEndTime((long) (Double.parseDouble( - match.group(TIMESTAMP)) * 1000)); - } } + return true; + } + return false; + } + + /** + * Parse init stages log from each {@code line} of dmesg log and + * store the stage name and start time 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, + * {@code false}, otherwise + */ + @VisibleForTesting + boolean parseStageInfo(String line) { + Matcher match = null; + if ((match = matches(START_STAGE, line)) != null) { + DmesgStageInfoItem stageInfoItem = new DmesgStageInfoItem(); + stageInfoItem.setStageName(match.group(STAGE)); + stageInfoItem.setStartTime((long) (Double.parseDouble( + match.group(TIMESTAMP)) * 1000)); + mStageInfoItems.add(stageInfoItem); + return true; } - return new ArrayList<ServiceInfoItem>(getServiceInfoItems().values()); + return false; + } + + /** + * Parse action from each {@code line} of dmesg log and store the action name and start time + * in {@link DmesgActionInfoItem} object + * + * @param individual {@code line} of the dmesg log + * @return {@code true}, if {@code line} indicates starting of processing of action + * {@code false}, otherwise + */ + @VisibleForTesting + boolean parseActionInfo(String line) { + Matcher match = null; + if ((match = matches(START_PROCESSING_ACTION, line)) != null) { + DmesgActionInfoItem actionInfoItem = new DmesgActionInfoItem(); + actionInfoItem.setActionName(match.group(ACTION)); + actionInfoItem.setStartTime((long) (Double.parseDouble( + match.group(TIMESTAMP)) * 1000)); + mActionInfoItems.add(actionInfoItem); + return true; + } + return false; } /** @@ -101,12 +196,20 @@ public class DmesgParser implements IParser { return ret.matches() ? ret : null; } - public Map<String, ServiceInfoItem> getServiceInfoItems() { + public Map<String, DmesgServiceInfoItem> getServiceInfoItems() { return mServiceInfoItems; } - public void setServiceInfoItems(Map<String, ServiceInfoItem> serviceInfoItems) { + public void setServiceInfoItems(Map<String, DmesgServiceInfoItem> serviceInfoItems) { this.mServiceInfoItems = serviceInfoItems; } + public List<DmesgStageInfoItem> getStageInfoItems() { + return mStageInfoItems; + } + + public List<DmesgActionInfoItem> getActionInfoItems() { + return mActionInfoItems; + } + } diff --git a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java index 9374c41..de3850a 100644 --- a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java +++ b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java @@ -16,18 +16,16 @@ package com.android.loganalysis.parser; -import com.android.loganalysis.item.ServiceInfoItem; - +import com.android.loganalysis.item.DmesgActionInfoItem; +import com.android.loganalysis.item.DmesgServiceInfoItem; +import com.android.loganalysis.item.DmesgStageInfoItem; import java.io.BufferedReader; -import java.io.BufferedWriter; -import java.io.File; -import java.io.FileInputStream; -import java.io.FileWriter; +import java.io.ByteArrayInputStream; import java.io.IOException; import java.io.InputStreamReader; +import java.util.ArrayList; import java.util.Arrays; import java.util.List; - import junit.framework.TestCase; /** @@ -37,140 +35,213 @@ public class DmesgParserTest extends TestCase { private static final String BOOT_ANIMATION = "bootanim"; private static final String NETD = "netd"; - private static final String DMESG_LOG = "dmesg_logs"; - - private File mTempFile = null; /** * Test for empty dmesg logs passed to the DmesgParser */ public void testEmptyDmesgLog() throws IOException { - List<String> lines = Arrays.asList(""); - File testFile = getTempFile(lines); - BufferedReader bufferedReader = new BufferedReader(readInputBuffer(testFile)); - List<ServiceInfoItem> serviceItems = (new DmesgParser()). - parseServiceInfo(bufferedReader); - assertEquals("Service info items list should be empty", 0, serviceItems.size()); - bufferedReader.close(); - testFile.delete(); + String[] lines = new String[] {""}; + try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader( + new ByteArrayInputStream(String.join("\n", lines).getBytes())))) { + DmesgParser dmesgParser = new DmesgParser(); + dmesgParser.parseInfo(bufferedReader); + assertEquals("Service info items list should be empty", 0, + dmesgParser.getServiceInfoItems().size()); + } + } + + /** + * Test for complete dmesg logs + */ + public void testCompleteDmesgLog() throws IOException { + String[] lines = new String[] { + "[ 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!", + "[ 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)", + "[ 52.962730] init: starting service 'bootanim'...", + "[ 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"}; + try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader( + new ByteArrayInputStream(String.join("\n", lines).getBytes())))) { + DmesgParser dmesgParser = new DmesgParser(); + dmesgParser.parseInfo(bufferedReader); + assertEquals("Service info items list size should be 2", 2, + dmesgParser.getServiceInfoItems().size()); + assertEquals("Stage info items list size should be 2", 2, + dmesgParser.getStageInfoItems().size()); + assertEquals("Action info items list size should be 5", 5, + dmesgParser.getActionInfoItems().size()); + } } /** * Test service which logs both the start and end time */ - public void testCompleteServiceInfo() throws IOException { - List<String> lines = Arrays.asList( + public void testCompleteServiceInfo() { + String[] lines = new String[] { "[ 22.962730] init: starting service 'bootanim'...", "[ 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"); - File testFile = getTempFile(lines); - BufferedReader bufferedReader = new BufferedReader(readInputBuffer(testFile)); - List<ServiceInfoItem> serviceInfoItems = (new DmesgParser()). - parseServiceInfo(bufferedReader); - assertEquals("There should be atleast one service info", 1, - serviceInfoItems.size()); + "[ 39.855818] init: Service 'bootanim' (pid 588) exited with status 0"}; + DmesgParser dmesgParser = new DmesgParser(); + for (String line : lines) { + dmesgParser.parseServiceInfo(line); + } + List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>( + dmesgParser.getServiceInfoItems().values()); + assertEquals("There should be atleast one service info", 1, serviceInfoItems.size()); assertEquals("Service name is not boot anim", BOOT_ANIMATION, serviceInfoItems.get(0).getServiceName()); - assertEquals("Service start time is not correct", new Long(22962), serviceInfoItems.get(0) - .getStartTime()); + assertEquals("Service start time is not correct", new Long(22962), + serviceInfoItems.get(0) + .getStartTime()); assertEquals("Service end time is not correct", new Long(39855), serviceInfoItems.get(0) .getEndTime()); - assertEquals("Service duration is nott correct", new Long(16893), serviceInfoItems.get(0) - .getServiceDuration()); - bufferedReader.close(); - testFile.delete(); + assertEquals("Service duration is nott correct", new Long(16893), + serviceInfoItems.get(0) + .getServiceDuration()); } /** * Test service which logs only the start time */ - public void testStartServiceInfo() throws IOException { - List<String> lines = Arrays.asList( + public void testStartServiceInfo() { + String[] lines = new String[] { "[ 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"); - File testFile = getTempFile(lines); - BufferedReader bufferedReader = new BufferedReader(readInputBuffer(testFile)); - List<ServiceInfoItem> serviceInfoItems = (new DmesgParser()). - parseServiceInfo(bufferedReader); - assertEquals("There should be exactly one service info", 1, - serviceInfoItems.size()); - assertEquals("Service name is not netd", NETD, - serviceInfoItems.get(0).getServiceName()); - bufferedReader.close(); - testFile.delete(); + "[ 35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts"}; + DmesgParser dmesgParser = new DmesgParser(); + for (String line : lines) { + dmesgParser.parseServiceInfo(line); + } + List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>( + dmesgParser.getServiceInfoItems().values()); + assertEquals("There should be exactly one service info", 1, serviceInfoItems.size()); + assertEquals("Service name is not netd", NETD, serviceInfoItems.get(0).getServiceName()); } /** * Test multiple service info parsed correctly and stored in the same order logged in * the file. */ - public void testMultipleServiceInfo() throws IOException { - List<String> lines = Arrays.asList( + public void testMultipleServiceInfo() { + String[] lines = new String[] { "[ 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/inputpoll_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"); - File testFile = getTempFile(lines); - BufferedReader bufferedReader = new BufferedReader(readInputBuffer(testFile)); - List<ServiceInfoItem> serviceInfoItems = (new DmesgParser()). - parseServiceInfo(bufferedReader); - assertEquals("There should be exactly two service info", 2, - serviceInfoItems.size()); + "[ 39.855818] init: Service 'bootanim' (pid 588) exited with status 0"}; + DmesgParser dmesgParser = new DmesgParser(); + for (String line : lines) { + dmesgParser.parseServiceInfo(line); + } + List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>( + dmesgParser.getServiceInfoItems().values()); + assertEquals("There should be exactly two service info", 2, serviceInfoItems.size()); assertEquals("First service name is not boot anim", BOOT_ANIMATION, serviceInfoItems.get(0).getServiceName()); assertEquals("Second service name is not netd", NETD, serviceInfoItems.get(1).getServiceName()); - bufferedReader.close(); - testFile.delete(); } /** * Test invalid patterns on the start and exit service logs */ - public void testInvalidServiceLogs() throws IOException { + public void testInvalidServiceLogs() { // Added space at the end of the start and exit of service logs to make it invalid - List<String> lines = Arrays.asList( + String[] lines = new String[] { "[ 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 "); - File testFile = getTempFile(lines); - BufferedReader bufferedReader = new BufferedReader(readInputBuffer(testFile)); - List<ServiceInfoItem> serviceInfoItems = (new DmesgParser()). - parseServiceInfo(bufferedReader); - assertEquals("No service info should be available", 0, - serviceInfoItems.size()); - bufferedReader.close(); - testFile.delete(); + "[ 39.855818] init: Service 'bootanim' (pid 588) exited with status 0 "}; + DmesgParser dmesgParser = new DmesgParser(); + for (String line : lines) { + dmesgParser.parseServiceInfo(line); + } + List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>( + dmesgParser.getServiceInfoItems().values()); + assertEquals("No service info should be available", 0, serviceInfoItems.size()); } /** - * Write list of strings to file and use it for testing. + * Test init stages' start time logs */ - public File getTempFile(List<String> sampleEventsLogs) throws IOException { - mTempFile = File.createTempFile(DMESG_LOG, ".txt"); - BufferedWriter out = new BufferedWriter(new FileWriter(mTempFile)); - for (String line : sampleEventsLogs) { - out.write(line); - out.newLine(); + public void testCompleteStageInfo() { + String[] lines = new String[] { + "[ 22.962730] init: starting service 'bootanim'...", + "[ 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!", + "[ 42.425056] init: init second stage started!"}; + DmesgStageInfoItem firstStageInfoItem = new DmesgStageInfoItem("first", + (long) (Double.parseDouble("41665.818"))); + DmesgStageInfoItem secondStageInfoItem = new DmesgStageInfoItem("second", + (long) (Double.parseDouble("42425.056"))); + DmesgParser dmesgParser = new DmesgParser(); + for (String line : lines) { + dmesgParser.parseStageInfo(line); } - out.close(); - return mTempFile; + List<DmesgStageInfoItem> stageInfoItems = dmesgParser.getStageInfoItems(); + assertEquals(2, stageInfoItems.size()); + assertEquals(Arrays.asList(firstStageInfoItem, secondStageInfoItem), stageInfoItems); } /** - * Reader to read the input from the given temp file + * Test processing action start time logs */ - public BufferedReader readInputBuffer(File tempFile) throws IOException { - return (new BufferedReader(new InputStreamReader(new FileInputStream(tempFile)))); + public void testCompleteActionInfo() { + String[] lines = new String[] { + "[ 14.942872] init: processing action (early-init)", + "[ 17.233446] init: processing action (set_mmap_rnd_bits)", + "[ 17.240083] init: processing action (set_kptr_restrict)", + "[ 17.245778] init: processing action (keychord_init)", + "[ 22.361049] init: processing action (persist.sys.usb.config=* boot)", + "[ 22.361108] init: processing action (enable_property_trigger)", + "[ 22.361313] init: processing action (security.perf_harden=1)", + "[ 22.361495] init: processing action (ro.debuggable=1)", + "[ 22.962730] init: starting service 'bootanim'...", + "[ 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"}; + List<DmesgActionInfoItem> expectedActionInfoItems = Arrays.asList( + new DmesgActionInfoItem("early-init", (long) (Double.parseDouble("14942.872"))), + new DmesgActionInfoItem("set_mmap_rnd_bits", + (long) (Double.parseDouble("17233.446"))), + new DmesgActionInfoItem("set_kptr_restrict", + (long) (Double.parseDouble("17240.083"))), + new DmesgActionInfoItem("keychord_init", (long) (Double.parseDouble("17245.778"))), + new DmesgActionInfoItem("enable_property_trigger", + (long) (Double.parseDouble("22361.108")))); + DmesgParser dmesgParser = new DmesgParser(); + for (String line : lines) { + dmesgParser.parseActionInfo(line); + } + List<DmesgActionInfoItem> actualActionInfoItems = dmesgParser.getActionInfoItems(); + assertEquals(5, actualActionInfoItems.size()); + assertEquals(expectedActionInfoItems, actualActionInfoItems); } } |