diff --git a/src/com/android/loganalysis/item/DmesgItem.java b/src/com/android/loganalysis/item/DmesgItem.java new file mode 100644 index 0000000000000000000000000000000000000000..de70145f522e1383dcc93d5fa2a818b7b779f09a --- /dev/null +++ b/src/com/android/loganalysis/item/DmesgItem.java @@ -0,0 +1,83 @@ +/* + * 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.ArrayList; +import java.util.Collections; +import java.util.HashMap; +import java.util.List; +import java.util.Map; + +/** + * An {@link IItem} used to store different infos logged in dmesg. + */ +public class DmesgItem extends GenericItem { + + private Map<String, DmesgServiceInfoItem> mServiceInfoItems = new HashMap<>(); + + private List<DmesgStageInfoItem> mStageInfoItems = new ArrayList<>(); + + private List<DmesgActionInfoItem> mActionInfoItems = new ArrayList<>(); + + public DmesgItem() { + super(Collections.emptySet()); + } + + /** + * @return the serviceInfoItems + */ + public Map<String, DmesgServiceInfoItem> getServiceInfoItems() { + return mServiceInfoItems; + } + + /** + * @param key to identify service info item + * @param serviceInfoItem to add + */ + public void addServiceInfoItem(String key, DmesgServiceInfoItem serviceInfoItem) { + mServiceInfoItems.put(key, serviceInfoItem); + } + + /** + * @return stageInfoItems + */ + public List<DmesgStageInfoItem> getStageInfoItems() { + return mStageInfoItems; + } + + /** + * @param stageInfoItem to be added to the list + */ + public void addStageInfoItem(DmesgStageInfoItem stageInfoItem) { + mStageInfoItems.add(stageInfoItem); + } + + /** + * @return actionInfoItems + */ + public List<DmesgActionInfoItem> getActionInfoItems() { + return mActionInfoItems; + } + + /** + * @param actionInfoItem to be added to the list + */ + public void addActionInfoItem(DmesgActionInfoItem actionInfoItem) { + mActionInfoItems.add(actionInfoItem); + } + +} diff --git a/src/com/android/loganalysis/parser/DmesgParser.java b/src/com/android/loganalysis/parser/DmesgParser.java index 9cb11cdde8aaa3c1db15c51ff8a9fccc930cb493..ba802cf792b4b8953554e63da11c7659d00a45eb 100644 --- a/src/com/android/loganalysis/parser/DmesgParser.java +++ b/src/com/android/loganalysis/parser/DmesgParser.java @@ -17,16 +17,14 @@ package com.android.loganalysis.parser; 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.android.loganalysis.item.IItem; import com.google.common.annotations.VisibleForTesting; import java.io.BufferedReader; import java.io.IOException; -import java.util.ArrayList; -import java.util.HashMap; import java.util.List; import java.util.Map; import java.util.regex.Matcher; @@ -76,15 +74,19 @@ public class DmesgParser implements IParser { 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<>(); + private DmesgItem mDmesgItem = new DmesgItem(); + + /** + * {@inheritDoc} + */ @Override - public IItem parse(List<String> lines) { - throw new UnsupportedOperationException("Method has not been implemented in lieu" - + " of others"); + public DmesgItem parse(List<String> lines) { + for (String line : lines) { + parse(line); + } + + return mDmesgItem; } /** @@ -96,18 +98,38 @@ public class DmesgParser implements IParser { * @param input dmesg log * @throws IOException */ - public void parseInfo(BufferedReader bufferedLog) throws IOException { + public DmesgItem parseInfo(BufferedReader bufferedLog) throws IOException { String line; while ((line = bufferedLog.readLine()) != null) { - if (parseServiceInfo(line)) { - continue; - } - if (parseStageInfo(line)) { - continue; - } - if (parseActionInfo(line)) { - continue; - } + parse(line); + } + + return mDmesgItem; + } + + /** + * <p> + * Parse single line of the dmesg log to retrieve the duration of the service calls or start + * times of different boot stages or start times of actions taken based on the info contained in + * the line. + * </p> + * <p> + * Besides, while parsing these informations are stored in the intermediate + * {@link DmesgServiceInfoItem}, {@link DmesgStageInfoItem} and {@link DmesgActionInfoItem} + * objects + * </p> + * + * @param line individual line of the dmesg log + */ + private void parse(String line) { + if (parseServiceInfo(line)) { + return; + } + if (parseStageInfo(line)) { + return; + } + if (parseActionInfo(line)) { + return; } } @@ -158,7 +180,7 @@ public class DmesgParser implements IParser { stageInfoItem.setStageName(match.group(STAGE)); stageInfoItem.setStartTime((long) (Double.parseDouble( match.group(TIMESTAMP)) * 1000)); - mStageInfoItems.add(stageInfoItem); + mDmesgItem.addStageInfoItem(stageInfoItem); return true; } return false; @@ -180,7 +202,7 @@ public class DmesgParser implements IParser { actionInfoItem.setActionName(match.group(ACTION)); actionInfoItem.setStartTime((long) (Double.parseDouble( match.group(TIMESTAMP)) * 1000)); - mActionInfoItems.add(actionInfoItem); + mDmesgItem.addActionInfoItem(actionInfoItem); return true; } return false; @@ -198,19 +220,21 @@ public class DmesgParser implements IParser { } public Map<String, DmesgServiceInfoItem> getServiceInfoItems() { - return mServiceInfoItems; + return mDmesgItem.getServiceInfoItems(); } public void setServiceInfoItems(Map<String, DmesgServiceInfoItem> serviceInfoItems) { - this.mServiceInfoItems = serviceInfoItems; + for(String key : serviceInfoItems.keySet()) { + mDmesgItem.addServiceInfoItem(key, serviceInfoItems.get(key)); + } } public List<DmesgStageInfoItem> getStageInfoItems() { - return mStageInfoItems; + return mDmesgItem.getStageInfoItems(); } public List<DmesgActionInfoItem> getActionInfoItems() { - return mActionInfoItems; + return mDmesgItem.getActionInfoItems(); } } diff --git a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java index 3b71720532bcf92fbc80d67e00c82504cb12a68c..4b043e133216aa2c02e6b7f30d4bb4c78eb72890 100644 --- a/tests/src/com/android/loganalysis/parser/DmesgParserTest.java +++ b/tests/src/com/android/loganalysis/parser/DmesgParserTest.java @@ -17,6 +17,7 @@ package com.android.loganalysis.parser; 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 java.io.BufferedReader; @@ -25,7 +26,9 @@ import java.io.IOException; import java.io.InputStreamReader; import java.util.ArrayList; import java.util.Arrays; +import java.util.HashMap; import java.util.List; +import java.util.Map; import junit.framework.TestCase; /** @@ -35,6 +38,36 @@ 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[] { + "[ 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)", + "[ 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(); + + private static final List<DmesgStageInfoItem> EXPECTED_STAGE_INFO_ITEMS = + getExpectedStageInfoItems(); + + private static final List<DmesgActionInfoItem> EXPECTED_ACTION_INFO_ITEMS = + getExpectedActionInfoItems(); /** * Test for empty dmesg logs passed to the DmesgParser @@ -51,33 +84,31 @@ public class DmesgParserTest extends TestCase { } /** - * Test for complete dmesg logs + * Test for complete dmesg logs passed as list of strings */ - 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"}; + public void testCompleteDmesgLog_passedAsList() { + + DmesgParser dmesgParser = new DmesgParser(); + DmesgItem actualDmesgItem = dmesgParser.parse(Arrays.asList(LINES)); + + 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()); + + assertEquals(EXPECTED_SERVICE_INFO_ITEMS, actualDmesgItem.getServiceInfoItems()); + assertEquals(EXPECTED_STAGE_INFO_ITEMS, actualDmesgItem.getStageInfoItems()); + assertEquals(EXPECTED_ACTION_INFO_ITEMS, actualDmesgItem.getActionInfoItems()); + } + + /** + * Test for complete dmesg logs passed as buffered input + */ + public void testCompleteDmesgLog_passedAsBufferedInput() throws IOException { try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader( - new ByteArrayInputStream(String.join("\n", lines).getBytes())))) { + new ByteArrayInputStream(String.join("\n", LINES).getBytes())))) { DmesgParser dmesgParser = new DmesgParser(); dmesgParser.parseInfo(bufferedReader); assertEquals("Service info items list size should be 2", 2, @@ -93,52 +124,30 @@ public class DmesgParserTest extends TestCase { * Test service which logs both the start and end time */ 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"}; DmesgParser dmesgParser = new DmesgParser(); - for (String line : lines) { + 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", - Long.valueOf(22962), - serviceInfoItems.get(0).getStartTime()); - assertEquals( - "Service end time is not correct", - Long.valueOf(39855), - serviceInfoItems.get(0).getEndTime()); - assertEquals( - "Service duration is nott correct", - Long.valueOf(16893), - serviceInfoItems.get(0).getServiceDuration()); + + assertEquals("There should be two service infos", 2, + dmesgParser.getServiceInfoItems().size()); + assertEquals(EXPECTED_SERVICE_INFO_ITEMS, dmesgParser.getServiceInfoItems()); } /** * Test service which logs only the start time */ 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"}; DmesgParser dmesgParser = new DmesgParser(); - for (String line : lines) { + 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()); + assertEquals("There should be exactly two service infos", 2, serviceInfoItems.size()); + assertEquals("Service name is not bootanim", BOOT_ANIMATION, + serviceInfoItems.get(0).getServiceName()); + assertEquals("Service name is not netd", NETD, serviceInfoItems.get(1).getServiceName()); } /** @@ -146,24 +155,13 @@ public class DmesgParserTest extends TestCase { * the file. */ 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"}; DmesgParser dmesgParser = new DmesgParser(); - for (String line : lines) { + 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()); + assertEquals("There should be exactly two service info", 2, + dmesgParser.getServiceInfoItems().size()); + assertEquals(EXPECTED_SERVICE_INFO_ITEMS, dmesgParser.getServiceInfoItems()); } /** @@ -191,61 +189,60 @@ public class DmesgParserTest extends TestCase { * Test init stages' start time logs */ 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) { + for (String line : LINES) { dmesgParser.parseStageInfo(line); } List<DmesgStageInfoItem> stageInfoItems = dmesgParser.getStageInfoItems(); assertEquals(2, stageInfoItems.size()); - assertEquals(Arrays.asList(firstStageInfoItem, secondStageInfoItem), stageInfoItems); + assertEquals(EXPECTED_STAGE_INFO_ITEMS, stageInfoItems); } /** * Test processing action start time logs */ 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) { + for (String line : LINES) { dmesgParser.parseActionInfo(line); } List<DmesgActionInfoItem> actualActionInfoItems = dmesgParser.getActionInfoItems(); assertEquals(5, actualActionInfoItems.size()); - assertEquals(expectedActionInfoItems, actualActionInfoItems); + 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("keychord_init", (long) (Double.parseDouble("47245.778"))), + new DmesgActionInfoItem("enable_property_trigger", + (long) (Double.parseDouble("52361.108")))); + } + + private static List<DmesgStageInfoItem> getExpectedStageInfoItems() { + return Arrays.asList( + new DmesgStageInfoItem("first", 41665L), new DmesgStageInfoItem("second", 42425L)); + } + + private static Map<String, DmesgServiceInfoItem> getExpectedServiceInfoItems() { + Map<String, DmesgServiceInfoItem> serviceInfoItemsMap = new HashMap<>(); + DmesgServiceInfoItem bootanimServiceInfoItem = new DmesgServiceInfoItem(); + bootanimServiceInfoItem.setServiceName(BOOT_ANIMATION); + bootanimServiceInfoItem.setStartTime(22962L); + bootanimServiceInfoItem.setEndTime(69855L); + + DmesgServiceInfoItem netdServiceInfoItem = new DmesgServiceInfoItem(); + netdServiceInfoItem.setServiceName(NETD); + netdServiceInfoItem.setStartTime(23252L); + + serviceInfoItemsMap.put(BOOT_ANIMATION, bootanimServiceInfoItem); + serviceInfoItemsMap.put(NETD, netdServiceInfoItem); + + return serviceInfoItemsMap; } }