Add parser to extract the init services time from dmesg logs

Tests: 5 Tests passed!
Bug: 32019616

Change-Id: I9bb3a724ef32d30efcdef0297564884e2cafdfcb

src/com/android/loganalysis/item/ServiceInfoItem.java

+/*
+ * Copyright (C) 2016 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 service info logged in dmesg
+ */
+public class ServiceInfoItem extends GenericItem {
+
+    /** Constant for JSON output */
+    public static final String SERVICE_NAME = "SERVICE_NAME";
+    /** Constant for JSON output */
+    public static final String SERVICE_START_TIME = "SERVICE_START_TIME";
+    /** Constant for JSON output */
+    public static final String SERVICE_END_TIME = "SERVICE_END_TIME";
+    /** Constant for JSON output */
+    public static final String SERVICE_DURATION = "SERVICE_DURATION";
+
+    private static final Set<String> ATTRIBUTES = new HashSet<String>(Arrays.asList(
+            SERVICE_NAME, SERVICE_START_TIME, SERVICE_END_TIME));
+
+    /**
+     * The constructor for {@link ServiceInfoItem}.
+     */
+    public ServiceInfoItem() {
+        super(ATTRIBUTES);
+    }
+
+    /**
+     * Get the name of the service
+     */
+    public String getServiceName() {
+        return (String) getAttribute(SERVICE_NAME);
+    }
+
+    /**
+     * Set the name of the service
+     */
+    public void setServiceName(String serviceName) {
+        setAttribute(SERVICE_NAME, serviceName);
+    }
+
+    /**
+     * Get the start time in msecs
+     */
+    public Long getStartTime() {
+        return (Long) getAttribute(SERVICE_START_TIME);
+    }
+
+    /**
+     * Set the start time in msecs
+     */
+    public void setStartTime(Long startTime) {
+        setAttribute(SERVICE_START_TIME, startTime);
+    }
+
+    /**
+     * Get the end time in msecs
+     */
+    public Long getEndTime() {
+        return (Long) getAttribute(SERVICE_END_TIME);
+    }
+
+    /**
+     * Set the end time in msecs
+     */
+    public void setEndTime(Long endTime) {
+        setAttribute(SERVICE_END_TIME, endTime);
+    }
+
+    /**
+     * Get the service duration in msecs If the start or end time is not present then return -1
+     */
+    public Long getServiceDuration() {
+        if (null != getAttribute(SERVICE_END_TIME) && null != getAttribute(SERVICE_START_TIME)) {
+            return getEndTime() - getStartTime();
+        }
+        return -1L;
+    }
+
+}

src/com/android/loganalysis/parser/DmesgParser.java

+/*
+ * Copyright (C) 2016 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.IItem;
+import com.android.loganalysis.item.ServiceInfoItem;
+
+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;
+import java.util.regex.Pattern;
+
+
+/**
+ * Parse the dmesg logs. </p>
+ */
+public class DmesgParser implements IParser {
+
+    private static final String SERVICENAME = "SERVICENAME";
+    private static final String TIMESTAMP = "TIMESTAMP";
+    // Matches: [ 14.822691] init:
+    private static final String SERVICE_PREFIX = String.format("^\\[\\s+(?<%s>.*)\\] init:\\s+",
+            TIMESTAMP);
+    // Matches: starting service 'ueventd'...
+    private static final String START_SERVICE_SUFFIX = String.format("starting service "
+            + "\\'(?<%s>.*)\\'...", SERVICENAME);
+    // Matches: Service 'ueventd' (pid 439) exited with status 0
+    private static final String EXIT_SERVICE_SUFFIX = String.format("Service \\'(?<%s>.*)\\'\\s+"
+            + "\\((?<PID>.*)\\) exited with status 0", SERVICENAME);
+
+    private static final Pattern START_SERVICE = Pattern.compile(
+            String.format("%s%s", SERVICE_PREFIX, START_SERVICE_SUFFIX));
+    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>();
+
+    @Override
+    public IItem parse(List<String> lines) {
+        throw new UnsupportedOperationException("Method has not been implemented in lieu"
+                + " of others");
+    }
+
+    /**
+     * 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.
+     *
+     * @param input dmesg logs
+     * @return list of ServiceInfoItems which contains service start and end time
+     * @throws IOException
+     */
+    public List<ServiceInfoItem> parseServiceInfo(BufferedReader input)
+            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(
+                        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 new ArrayList<ServiceInfoItem>(getServiceInfoItems().values());
+    }
+
+    /**
+     * Checks whether {@code line} matches the given {@link Pattern}.
+     *
+     * @return The resulting {@link Matcher} obtained by matching the {@code line} against
+     *         {@code pattern}, or null if the {@code line} does not match.
+     */
+    private static Matcher matches(Pattern pattern, String line) {
+        Matcher ret = pattern.matcher(line);
+        return ret.matches() ? ret : null;
+    }
+
+    public Map<String, ServiceInfoItem> getServiceInfoItems() {
+        return mServiceInfoItems;
+    }
+
+    public void setServiceInfoItems(Map<String, ServiceInfoItem> serviceInfoItems) {
+        this.mServiceInfoItems = serviceInfoItems;
+    }
+
+}

tests/src/com/android/loganalysis/UnitTests.java

@@ -31,8 +31,9 @@ import com.android.loganalysis.parser.AbstractSectionParserTest;
 import com.android.loganalysis.parser.AnrParserTest;
 import com.android.loganalysis.parser.BugreportParserTest;
 import com.android.loganalysis.parser.CompactMemInfoParserTest;
-import com.android.loganalysis.parser.EventsLogParserTest;
+import com.android.loganalysis.parser.DmesgParserTest;
 import com.android.loganalysis.parser.DvmLockSampleParserTest;
+import com.android.loganalysis.parser.EventsLogParserTest;
 import com.android.loganalysis.parser.InterruptParserTest;
 import com.android.loganalysis.parser.JavaCrashParserTest;
 import com.android.loganalysis.parser.KernelLogParserTest;
@@ -85,6 +86,7 @@ public class UnitTests extends TestSuite {
         addTestSuite(AnrParserTest.class);
         addTestSuite(BugreportParserTest.class);
         addTestSuite(CompactMemInfoParserTest.class);
+        addTestSuite(DmesgParserTest.class);
         addTestSuite(EventsLogParserTest.class);
         addTestSuite(DvmLockSampleParserTest.class);
         addTestSuite(InterruptParserTest.class);

tests/src/com/android/loganalysis/parser/DmesgParserTest.java

+/*
+ * Copyright (C) 2016 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.ServiceInfoItem;
+
+import java.io.BufferedReader;
+import java.io.BufferedWriter;
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.FileWriter;
+import java.io.IOException;
+import java.io.InputStreamReader;
+import java.util.Arrays;
+import java.util.List;
+
+import junit.framework.TestCase;
+
+/**
+ * Unit tests for {@link DmesgParser}.
+ */
+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();
+    }
+
+    /**
+     * Test service which logs both the start and end time
+     */
+    public void testCompleteServiceInfo() throws IOException {
+        List<String> lines = Arrays.asList(
+                "[   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());
+        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 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();
+    }
+
+    /**
+     * Test service which logs only the start time
+     */
+    public void testStartServiceInfo() throws IOException {
+        List<String> lines = Arrays.asList(
+                "[   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();
+    }
+
+    /**
+     * 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(
+                "[   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());
+        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 {
+        // Added space at the end of the start and exit of service logs to make it invalid
+        List<String> lines = Arrays.asList(
+                "[   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();
+    }
+
+    /**
+     * Write list of strings to file and use it for testing.
+     */
+    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();
+        }
+        out.close();
+        return mTempFile;
+    }
+
+    /**
+     * Reader to read the input from the given temp file
+     */
+    public BufferedReader readInputBuffer(File tempFile) throws IOException {
+        return (new BufferedReader(new InputStreamReader(new FileInputStream(tempFile))));
+    }
+
+}