• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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                 "[    2.471163] init: Wait for property 'apexd.status=ready' took 403ms",
44                 "[    3.786943] ueventd: Coldboot took 0.701291 seconds",
45                 "[   22.962730] init: starting service 'bootanim'...",
46                 "[   23.252321] init: starting service 'netd'...",
47                 "[   29.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA",
48                 "[   32.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660",
49                 "[   35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts",
50                 "[   39.855818] init: Service 'bootanim' (pid 588) exited with status 0",
51                 "[   41.665818] init: init first stage started!",
52                 "[   44.942872] init: processing action (early-init) from (/init.rc:13)",
53                 "[   47.233446] init: processing action (set_mmap_rnd_bits) from (<Builtin Action>:0)",
54                 "[   47.240083] init: processing action (set_kptr_restrict) from (<Builtin Action>:0)",
55                 "[   47.245778] init: processing action (keychord_init) from (<Builtin Action>:0)",
56                 "[   52.361049] init: processing action (persist.sys.usb.config=* boot) from (<Builtin Action>:0)",
57                 "[   52.361108] init: processing action (enable_property_trigger) from (<Builtin Action>:0)",
58                 "[   52.361313] init: processing action (security.perf_harden=1) from (/init.rc:677)",
59                 "[   52.361495] init: processing action (ro.debuggable=1) from (/init.rc:700)",
60                 "[   58.298293] init: processing action (sys.boot_completed=1)",
61                 "[   59.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA",
62                 "[   62.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660",
63                 "[   65.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts",
64                 "[   69.855818] init: Service 'bootanim' (pid 588) exited with status 0"
65             };
66 
67     private static final Map<String, DmesgServiceInfoItem> EXPECTED_SERVICE_INFO_ITEMS =
68             getExpectedServiceInfoItems();
69 
70     private static final List<DmesgStageInfoItem> EXPECTED_STAGE_INFO_ITEMS =
71             getExpectedStageInfoItems();
72 
73     private static final List<DmesgActionInfoItem> EXPECTED_ACTION_INFO_ITEMS =
74             getExpectedActionInfoItems();
75 
76     /**
77      * Test for empty dmesg logs passed to the DmesgParser
78      */
testEmptyDmesgLog()79     public void testEmptyDmesgLog() throws IOException {
80         String[] lines = new String[] {""};
81         try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(
82                 new ByteArrayInputStream(String.join("\n", lines).getBytes())))) {
83             DmesgParser dmesgParser = new DmesgParser();
84             dmesgParser.parseInfo(bufferedReader);
85             assertEquals("Service info items list should be empty", 0,
86                     dmesgParser.getServiceInfoItems().size());
87         }
88     }
89 
90     /**
91      * Test for complete dmesg logs passed as list of strings
92      */
testCompleteDmesgLog_passedAsList()93     public void testCompleteDmesgLog_passedAsList() {
94 
95         DmesgParser dmesgParser = new DmesgParser();
96         DmesgItem actualDmesgItem = dmesgParser.parse(Arrays.asList(LINES));
97 
98         assertEquals("Service info items list size should be 2", 2,
99                 dmesgParser.getServiceInfoItems().size());
100         assertEquals("Stage info items list size should be 3",3,
101                 dmesgParser.getStageInfoItems().size());
102         assertEquals("Action info items list size should be 9",9,
103                 dmesgParser.getActionInfoItems().size());
104 
105         assertEquals(EXPECTED_SERVICE_INFO_ITEMS, actualDmesgItem.getServiceInfoItems());
106         assertEquals(EXPECTED_STAGE_INFO_ITEMS, actualDmesgItem.getStageInfoItems());
107         assertEquals(EXPECTED_ACTION_INFO_ITEMS, actualDmesgItem.getActionInfoItems());
108     }
109 
110     /**
111      * Test for complete dmesg logs passed as buffered input
112      */
testCompleteDmesgLog_passedAsBufferedInput()113     public void testCompleteDmesgLog_passedAsBufferedInput() throws IOException {
114         try (BufferedReader bufferedReader = new BufferedReader(new InputStreamReader(
115                 new ByteArrayInputStream(String.join("\n", LINES).getBytes())))) {
116             DmesgParser dmesgParser = new DmesgParser();
117             dmesgParser.parseInfo(bufferedReader);
118             assertEquals("Service info items list size should be 2", 2,
119                     dmesgParser.getServiceInfoItems().size());
120             assertEquals("Stage info items list size should be 3", 3,
121                     dmesgParser.getStageInfoItems().size());
122             assertEquals("Action info items list size should be 9",9,
123                     dmesgParser.getActionInfoItems().size());
124         }
125     }
126 
127     /**
128      * Test service which logs both the start and end time
129      */
testCompleteServiceInfo()130     public void testCompleteServiceInfo() {
131         DmesgParser dmesgParser = new DmesgParser();
132         for (String line : LINES) {
133             dmesgParser.parseServiceInfo(line);
134         }
135 
136         assertEquals("There should be two service infos", 2,
137                 dmesgParser.getServiceInfoItems().size());
138         assertEquals(EXPECTED_SERVICE_INFO_ITEMS, dmesgParser.getServiceInfoItems());
139     }
140 
141     /**
142      * Test service which logs only the start time
143      */
testStartServiceInfo()144     public void testStartServiceInfo() {
145         DmesgParser dmesgParser = new DmesgParser();
146         for (String line : LINES) {
147             dmesgParser.parseServiceInfo(line);
148         }
149         List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>(
150                 dmesgParser.getServiceInfoItems().values());
151         assertEquals("There should be exactly two service infos", 2, serviceInfoItems.size());
152         assertEquals("Service name is not bootanim", BOOT_ANIMATION,
153                 serviceInfoItems.get(0).getServiceName());
154         assertEquals("Service name is not netd", NETD, serviceInfoItems.get(1).getServiceName());
155     }
156 
157     /**
158      * Test multiple service info parsed correctly and stored in the same order logged in
159      * the file.
160      */
testMultipleServiceInfo()161     public void testMultipleServiceInfo() {
162         DmesgParser dmesgParser = new DmesgParser();
163         for (String line : LINES) {
164             dmesgParser.parseServiceInfo(line);
165         }
166         assertEquals("There should be exactly two service info", 2,
167                 dmesgParser.getServiceInfoItems().size());
168         assertEquals(EXPECTED_SERVICE_INFO_ITEMS, dmesgParser.getServiceInfoItems());
169     }
170 
171     /**
172      * Test invalid patterns on the start and exit service logs
173      */
testInvalidServiceLogs()174     public void testInvalidServiceLogs() {
175         // Added space at the end of the start and exit of service logs to make it invalid
176         String[] lines = new String[] {
177                 "[   22.962730] init: starting service 'bootanim'...  ",
178                 "[   23.252321] init: starting service 'netd'...  ",
179                 "[   29.331069] ipa-wan ipa_wwan_ioctl:1428 dev(rmnet_data0) register to IPA",
180                 "[   32.182592] ueventd: fixup /sys/devices/virtual/input/poll_delay 0 1004 660",
181                 "[   35.642666] SELinux: initialized (dev fuse, type fuse), uses genfs_contexts",
182                 "[   39.855818] init: Service 'bootanim' (pid 588) exited with status 0  "};
183         DmesgParser dmesgParser = new DmesgParser();
184         for (String line : lines) {
185             dmesgParser.parseServiceInfo(line);
186         }
187         List<DmesgServiceInfoItem> serviceInfoItems = new ArrayList<>(
188                 dmesgParser.getServiceInfoItems().values());
189         assertEquals("No service info should be available", 0, serviceInfoItems.size());
190     }
191 
192     /**
193      * Test init stages' start time logs
194      */
testCompleteStageInfo()195     public void testCompleteStageInfo() {
196         DmesgParser dmesgParser = new DmesgParser();
197         for (String line : LINES) {
198             dmesgParser.parseStageInfo(line);
199         }
200         List<DmesgStageInfoItem> stageInfoItems = dmesgParser.getStageInfoItems();
201         assertEquals(3, stageInfoItems.size());
202         assertEquals(EXPECTED_STAGE_INFO_ITEMS, stageInfoItems);
203     }
204 
205     /** Test processing action start time logs */
testCompleteActionInfo()206     public void testCompleteActionInfo() {
207         DmesgParser dmesgParser = new DmesgParser();
208         for (String line : LINES) {
209             dmesgParser.parseActionInfo(line);
210         }
211         List<DmesgActionInfoItem> actualActionInfoItems = dmesgParser.getActionInfoItems();
212         assertEquals(9, actualActionInfoItems.size());
213         assertEquals(EXPECTED_ACTION_INFO_ITEMS, actualActionInfoItems);
214     }
215 
getExpectedActionInfoItems()216     private static List<DmesgActionInfoItem> getExpectedActionInfoItems() {
217         return Arrays.asList(
218                 new DmesgActionInfoItem("early-init", (long) (Double.parseDouble("44942.872"))),
219                 new DmesgActionInfoItem(
220                         "set_mmap_rnd_bits", (long) (Double.parseDouble("47233.446"))),
221                 new DmesgActionInfoItem(
222                         "set_kptr_restrict", (long) (Double.parseDouble("47240.083"))),
223                 new DmesgActionInfoItem("keychord_init", (long) (Double.parseDouble("47245.778"))),
224                 new DmesgActionInfoItem(
225                         "persist.sys.usb.config=* boot", (long) (Double.parseDouble("52361.049"))),
226                 new DmesgActionInfoItem(
227                         "enable_property_trigger", (long) (Double.parseDouble("52361.108"))),
228                 new DmesgActionInfoItem(
229                         "security.perf_harden=1", (long) (Double.parseDouble("52361.313"))),
230                 new DmesgActionInfoItem(
231                         "ro.debuggable=1", (long) (Double.parseDouble("52361.495"))),
232                 new DmesgActionInfoItem(
233                         "sys.boot_completed=1", (long) (Double.parseDouble("58298.293"))));
234     }
235 
getExpectedStageInfoItems()236     private static List<DmesgStageInfoItem> getExpectedStageInfoItems() {
237         return Arrays.asList(
238                 new DmesgStageInfoItem("init_Wait for property 'apexd.status=ready'", null, 403L),
239                 new DmesgStageInfoItem("ueventd_Coldboot", null, 701L),
240                 new DmesgStageInfoItem("first", 41665L, null));
241     }
242 
getExpectedServiceInfoItems()243     private static Map<String, DmesgServiceInfoItem> getExpectedServiceInfoItems() {
244         Map<String, DmesgServiceInfoItem> serviceInfoItemsMap = new HashMap<>();
245         DmesgServiceInfoItem bootanimServiceInfoItem = new DmesgServiceInfoItem();
246         bootanimServiceInfoItem.setServiceName(BOOT_ANIMATION);
247         bootanimServiceInfoItem.setStartTime(22962L);
248         bootanimServiceInfoItem.setEndTime(69855L);
249 
250         DmesgServiceInfoItem netdServiceInfoItem = new DmesgServiceInfoItem();
251         netdServiceInfoItem.setServiceName(NETD);
252         netdServiceInfoItem.setStartTime(23252L);
253 
254         serviceInfoItemsMap.put(BOOT_ANIMATION, bootanimServiceInfoItem);
255         serviceInfoItemsMap.put(NETD, netdServiceInfoItem);
256 
257         return serviceInfoItemsMap;
258     }
259 
260 }
261