Home | History | Annotate | Download | only in parser
      1 /*
      2  * Copyright (C) 2016 The Android Open Source Project
      3  *
      4  * Licensed under the Apache License, Version 2.0 (the "License");
      5  * you may not use this file except in compliance with the License.
      6  * You may obtain a copy of the License at
      7  *
      8  *      http://www.apache.org/licenses/LICENSE-2.0
      9  *
     10  * Unless required by applicable law or agreed to in writing, software
     11  * distributed under the License is distributed on an "AS IS" BASIS,
     12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
     13  * See the License for the specific language governing permissions and
     14  * limitations under the License.
     15  */
     16 
     17 package com.android.loganalysis.parser;
     18 
     19 import com.android.loganalysis.item.DmesgActionInfoItem;
     20 import com.android.loganalysis.item.DmesgItem;
     21 import com.android.loganalysis.item.DmesgServiceInfoItem;
     22 import com.android.loganalysis.item.DmesgStageInfoItem;
     23 import java.io.BufferedReader;
     24 import java.io.ByteArrayInputStream;
     25 import java.io.IOException;
     26 import java.io.InputStreamReader;
     27 import java.util.ArrayList;
     28 import java.util.Arrays;
     29 import java.util.HashMap;
     30 import java.util.List;
     31 import java.util.Map;
     32 import junit.framework.TestCase;
     33 
     34 /**
     35  * Unit tests for {@link DmesgParser}.
     36  */
     37 public class DmesgParserTest extends TestCase {
     38 
     39     private static final String BOOT_ANIMATION = "bootanim";
     40     private static final String NETD = "netd";
     41     private static final String[] LINES =
     42             new String[] {
     43                 "[    3.786943] ueventd: Coldboot took 0.701291 seconds",
     44                 "[   22.962730] init: starting service 'bootanim'...",
     45                 "[   23.252321] init: starting service 'netd'...",
     46                 "[   29.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA",
     47                 "[   32.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660",
     48                 "[   35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts",
     49                 "[   39.855818] init: Service 'bootanim' (pid 588) exited with status 0",
     50                 "[   41.665818] init: init first stage started!",
     51                 "[   44.942872] init: processing action (early-init) from (/init.rc:13)",
     52                 "[   47.233446] init: processing action (set_mmap_rnd_bits) from (<Builtin Action>:0)",
     53                 "[   47.240083] init: processing action (set_kptr_restrict) from (<Builtin Action>:0)",
     54                 "[   47.245778] init: processing action (keychord_init) from (<Builtin Action>:0)",
     55                 "[   52.361049] init: processing action (persist.sys.usb.config=* boot) from (<Builtin Action>:0)",
     56                 "[   52.361108] init: processing action (enable_property_trigger) from (<Builtin Action>:0)",
     57                 "[   52.361313] init: processing action (security.perf_harden=1) from (/init.rc:677)",
     58                 "[   52.361495] init: processing action (ro.debuggable=1) from (/init.rc:700)",
     59                 "[   58.298293] init: processing action (sys.boot_completed=1)",
     60                 "[   59.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA",
     61                 "[   62.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660",
     62                 "[   65.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts",
     63                 "[   69.855818] init: Service 'bootanim' (pid 588) exited with status 0"
     64             };
     65 
     66     private static final Map<String, DmesgServiceInfoItem> EXPECTED_SERVICE_INFO_ITEMS =
     67             getExpectedServiceInfoItems();
     68 
     69     private static final List<DmesgStageInfoItem> EXPECTED_STAGE_INFO_ITEMS =
     70             getExpectedStageInfoItems();
     71 
     72     private static final List<DmesgActionInfoItem> EXPECTED_ACTION_INFO_ITEMS =
     73             getExpectedActionInfoItems();
     74 
     75     /**
     76      * Test for empty dmesg logs passed to the DmesgParser
     77      */
     78     public void testEmptyDmesgLog() throws IOException {
     79         String[] lines = new String[] {""};
     80         try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(
     81                 new ByteArrayInputStream(String.join("\n", lines).getBytes())))) {
     82             DmesgParser dmesgParser = new DmesgParser();
     83             dmesgParser.parseInfo(bufferedReader);
     84             assertEquals("Service info items list should be empty", 0,
     85                     dmesgParser.getServiceInfoItems().size());
     86         }
     87     }
     88 
     89     /**
     90      * Test for complete dmesg logs passed as list of strings
     91      */
     92     public void testCompleteDmesgLog_passedAsList() {
     93 
     94         DmesgParser dmesgParser = new DmesgParser();
     95         DmesgItem actualDmesgItem = dmesgParser.parse(Arrays.asList(LINES));
     96 
     97         assertEquals("Service info items list size should be 2", 2,
     98                 dmesgParser.getServiceInfoItems().size());
     99         assertEquals("Stage info items list size should be 2",2,
    100                 dmesgParser.getStageInfoItems().size());
    101         assertEquals("Action info items list size should be 9",9,
    102                 dmesgParser.getActionInfoItems().size());
    103 
    104         assertEquals(EXPECTED_SERVICE_INFO_ITEMS, actualDmesgItem.getServiceInfoItems());
    105         assertEquals(EXPECTED_STAGE_INFO_ITEMS, actualDmesgItem.getStageInfoItems());
    106         assertEquals(EXPECTED_ACTION_INFO_ITEMS, actualDmesgItem.getActionInfoItems());
    107     }
    108 
    109     /**
    110      * Test for complete dmesg logs passed as buffered input
    111      */
    112     public void testCompleteDmesgLog_passedAsBufferedInput() throws IOException {
    113         try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(
    114                 new ByteArrayInputStream(String.join("\n", LINES).getBytes())))) {
    115             DmesgParser dmesgParser = new DmesgParser();
    116             dmesgParser.parseInfo(bufferedReader);
    117             assertEquals("Service info items list size should be 2", 2,
    118                     dmesgParser.getServiceInfoItems().size());
    119             assertEquals("Stage info items list size should be 2", 2,
    120                     dmesgParser.getStageInfoItems().size());
    121             assertEquals("Action info items list size should be 9",9,
    122                     dmesgParser.getActionInfoItems().size());
    123         }
    124     }
    125 
    126     /**
    127      * Test service which logs both the start and end time
    128      */
    129     public void testCompleteServiceInfo() {
    130         DmesgParser dmesgParser = new DmesgParser();
    131         for (String line : LINES) {
    132             dmesgParser.parseServiceInfo(line);
    133         }
    134 
    135         assertEquals("There should be two service infos", 2,
    136                 dmesgParser.getServiceInfoItems().size());
    137         assertEquals(EXPECTED_SERVICE_INFO_ITEMS, dmesgParser.getServiceInfoItems());
    138     }
    139 
    140     /**
    141      * Test service which logs only the start time
    142      */
    143     public void testStartServiceInfo() {
    144         DmesgParser dmesgParser = new DmesgParser();
    145         for (String line : LINES) {
    146             dmesgParser.parseServiceInfo(line);
    147         }
    148         List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>(
    149                 dmesgParser.getServiceInfoItems().values());
    150         assertEquals("There should be exactly two service infos", 2, serviceInfoItems.size());
    151         assertEquals("Service name is not bootanim", BOOT_ANIMATION,
    152                 serviceInfoItems.get(0).getServiceName());
    153         assertEquals("Service name is not netd", NETD, serviceInfoItems.get(1).getServiceName());
    154     }
    155 
    156     /**
    157      * Test multiple service info parsed correctly and stored in the same order logged in
    158      * the file.
    159      */
    160     public void testMultipleServiceInfo() {
    161         DmesgParser dmesgParser = new DmesgParser();
    162         for (String line : LINES) {
    163             dmesgParser.parseServiceInfo(line);
    164         }
    165         assertEquals("There should be exactly two service info", 2,
    166                 dmesgParser.getServiceInfoItems().size());
    167         assertEquals(EXPECTED_SERVICE_INFO_ITEMS, dmesgParser.getServiceInfoItems());
    168     }
    169 
    170     /**
    171      * Test invalid patterns on the start and exit service logs
    172      */
    173     public void testInvalidServiceLogs() {
    174         // Added space at the end of the start and exit of service logs to make it invalid
    175         String[] lines = new String[] {
    176                 "[   22.962730] init: starting service 'bootanim'...  ",
    177                 "[   23.252321] init: starting service 'netd'...  ",
    178                 "[   29.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA",
    179                 "[   32.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660",
    180                 "[   35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts",
    181                 "[   39.855818] init: Service 'bootanim' (pid 588) exited with status 0  "};
    182         DmesgParser dmesgParser = new DmesgParser();
    183         for (String line : lines) {
    184             dmesgParser.parseServiceInfo(line);
    185         }
    186         List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>(
    187                 dmesgParser.getServiceInfoItems().values());
    188         assertEquals("No service info should be available", 0, serviceInfoItems.size());
    189     }
    190 
    191     /**
    192      * Test init stages' start time logs
    193      */
    194     public void testCompleteStageInfo() {
    195         DmesgParser dmesgParser = new DmesgParser();
    196         for (String line : LINES) {
    197             dmesgParser.parseStageInfo(line);
    198         }
    199         List<DmesgStageInfoItem> stageInfoItems = dmesgParser.getStageInfoItems();
    200         assertEquals(2, stageInfoItems.size());
    201         assertEquals(EXPECTED_STAGE_INFO_ITEMS, stageInfoItems);
    202     }
    203 
    204     /** Test processing action start time logs */
    205     public void testCompleteActionInfo() {
    206         DmesgParser dmesgParser = new DmesgParser();
    207         for (String line : LINES) {
    208             dmesgParser.parseActionInfo(line);
    209         }
    210         List<DmesgActionInfoItem> actualActionInfoItems = dmesgParser.getActionInfoItems();
    211         assertEquals(9, actualActionInfoItems.size());
    212         assertEquals(EXPECTED_ACTION_INFO_ITEMS, actualActionInfoItems);
    213     }
    214 
    215     private static List<DmesgActionInfoItem> getExpectedActionInfoItems() {
    216         return Arrays.asList(
    217                 new DmesgActionInfoItem("early-init", (long) (Double.parseDouble("44942.872"))),
    218                 new DmesgActionInfoItem(
    219                         "set_mmap_rnd_bits", (long) (Double.parseDouble("47233.446"))),
    220                 new DmesgActionInfoItem(
    221                         "set_kptr_restrict", (long) (Double.parseDouble("47240.083"))),
    222                 new DmesgActionInfoItem("keychord_init", (long) (Double.parseDouble("47245.778"))),
    223                 new DmesgActionInfoItem(
    224                         "persist.sys.usb.config=* boot", (long) (Double.parseDouble("52361.049"))),
    225                 new DmesgActionInfoItem(
    226                         "enable_property_trigger", (long) (Double.parseDouble("52361.108"))),
    227                 new DmesgActionInfoItem(
    228                         "security.perf_harden=1", (long) (Double.parseDouble("52361.313"))),
    229                 new DmesgActionInfoItem(
    230                         "ro.debuggable=1", (long) (Double.parseDouble("52361.495"))),
    231                 new DmesgActionInfoItem(
    232                         "sys.boot_completed=1", (long) (Double.parseDouble("58298.293"))));
    233     }
    234 
    235     private static List<DmesgStageInfoItem> getExpectedStageInfoItems() {
    236         return Arrays.asList(
    237                 new DmesgStageInfoItem("ueventd_Coldboot", null, 701L),
    238                 new DmesgStageInfoItem("first", 41665L, null));
    239     }
    240 
    241     private static Map<String, DmesgServiceInfoItem> getExpectedServiceInfoItems() {
    242         Map<String, DmesgServiceInfoItem> serviceInfoItemsMap = new HashMap<>();
    243         DmesgServiceInfoItem bootanimServiceInfoItem = new DmesgServiceInfoItem();
    244         bootanimServiceInfoItem.setServiceName(BOOT_ANIMATION);
    245         bootanimServiceInfoItem.setStartTime(22962L);
    246         bootanimServiceInfoItem.setEndTime(69855L);
    247 
    248         DmesgServiceInfoItem netdServiceInfoItem = new DmesgServiceInfoItem();
    249         netdServiceInfoItem.setServiceName(NETD);
    250         netdServiceInfoItem.setStartTime(23252L);
    251 
    252         serviceInfoItemsMap.put(BOOT_ANIMATION, bootanimServiceInfoItem);
    253         serviceInfoItemsMap.put(NETD, netdServiceInfoItem);
    254 
    255         return serviceInfoItemsMap;
    256     }
    257 
    258 }
    259