1 /*
2  * Copyright (C) 2017 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 android.bootstats.cts;
18 
19 import static com.google.common.truth.Truth.assertThat;
20 
21 import com.android.internal.logging.nano.MetricsProto.MetricsEvent;
22 import com.android.os.AtomsProto.Atom;
23 import com.android.tradefed.device.ITestDevice;
24 import com.android.tradefed.testtype.DeviceJUnit4ClassRunner;
25 import com.android.tradefed.testtype.IDeviceTest;
26 
27 import org.junit.Assert;
28 import org.junit.Assume;
29 import org.junit.Test;
30 import org.junit.runner.RunWith;
31 
32 import java.util.LinkedList;
33 
34 
35 /**
36  * Set of tests that verify statistics collection during boot.
37  */
38 @RunWith(DeviceJUnit4ClassRunner.class)
39 public class BootStatsHostTest implements IDeviceTest {
40 
41     private static final long MAX_WAIT_TIME_MS = 100000;
42     private static final long WAIT_SLEEP_MS = 100;
43 
44     private static int[] ATOMS_EXPECTED = {
45             Atom.BOOT_TIME_EVENT_DURATION_REPORTED_FIELD_NUMBER,
46             Atom.BOOT_TIME_EVENT_ELAPSED_TIME_REPORTED_FIELD_NUMBER
47     };
48 
49     private ITestDevice mDevice;
50 
51     @Test
testBootStats()52     public void testBootStats() throws Exception {
53         final int apiLevel = getDevice().getApiLevel();
54         Assume.assumeFalse("Skipping test because boot time metrics were introduced"
55                 + " in Android 8.0. Current API Level " + apiLevel,
56                 apiLevel < 26 /* Build.VERSION_CODES.O */);
57 
58         if (apiLevel <= 29 /* Build.VERSION_CODES.Q */) {
59             testBootStatsForApiLevel29AndBelow();
60             return;
61         }
62 
63         // Clear buffer to make it easier to find new logs
64         getDevice().executeShellCommand("logcat --buffer=events --clear");
65 
66         // reboot device
67         getDevice().rebootUntilOnline();
68 
69         LinkedList<String> expectedAtomHeaders = new LinkedList<>();
70         // example format: Atom 239->(total count)5, (error count)0
71         for (int atom : ATOMS_EXPECTED) {
72             expectedAtomHeaders.add("Atom " + atom + "->(total count)");
73         }
74         long timeoutMs = System.currentTimeMillis() + MAX_WAIT_TIME_MS;
75         while (System.currentTimeMillis() < timeoutMs) {
76             LinkedList<String> notExistingAtoms = checkAllExpectedAtoms(expectedAtomHeaders);
77             if (notExistingAtoms.isEmpty()) {
78                 return;
79             }
80             Thread.sleep(WAIT_SLEEP_MS);
81         }
82         assertThat(checkAllExpectedAtoms(expectedAtomHeaders)).isEmpty();
83     }
84 
85     /** Check all atoms are available and return atom headers not available */
checkAllExpectedAtoms(LinkedList<String> expectedAtomHeaders)86     private LinkedList<String> checkAllExpectedAtoms(LinkedList<String> expectedAtomHeaders)
87             throws Exception {
88         LinkedList<String> notExistingAtoms = new LinkedList<>(expectedAtomHeaders);
89         String log = getDevice().executeShellCommand("cmd stats print-stats");
90         for (String atom : expectedAtomHeaders) {
91             int atomIndex = log.indexOf(atom);
92             if (atomIndex < 0) {
93                 continue;
94             }
95             int numberOfEvents = getIntValue(log, atomIndex + atom.length());
96             if (numberOfEvents <= 0) {
97                 continue;
98             }
99             // valid event happened.
100             notExistingAtoms.remove(atom);
101         }
102         return notExistingAtoms;
103     }
104 
105     // extract the value from the string starting from index till ',''
getIntValue(String str, int index)106     private int getIntValue(String str, int index) throws Exception {
107         int lastIndex = index;
108         for (int i = index; i < str.length(); i++) {
109             if (str.charAt(i) == ',') {
110                 lastIndex = i;
111                 break;
112             }
113         }
114         String valueStr = str.substring(index, lastIndex);
115         int value = Integer.valueOf(valueStr);
116         return value;
117     }
118 
119     /** Need to keep the old version of test for api 27, 28, 29 as new version
120         of tests can be used on devices with old Android versions */
testBootStatsForApiLevel29AndBelow()121     private void testBootStatsForApiLevel29AndBelow() throws Exception {
122         long startTime = System.currentTimeMillis();
123         // Clear buffer to make it easier to find new logs
124         getDevice().executeShellCommand("logcat --buffer=events --clear");
125 
126         // reboot device
127         getDevice().rebootUntilOnline();
128         waitForBootCompleted();
129         int upperBoundSeconds = (int) ((System.currentTimeMillis() - startTime) / 1000);
130 
131         // wait for logs to post
132         Thread.sleep(10000);
133 
134         // find logs and parse them
135         // ex: sysui_multi_action: [757,804,799,ota_boot_complete,801,85,802,1]
136         // ex: 757,804,799,counter_name,801,bucket_value,802,increment_value
137         final String bucketTag = Integer.toString(MetricsEvent.RESERVED_FOR_LOGBUILDER_BUCKET);
138         final String counterNameTag = Integer.toString(MetricsEvent.RESERVED_FOR_LOGBUILDER_NAME);
139         final String counterNamePattern = counterNameTag + ",boot_complete,";
140         final String multiActionPattern = "sysui_multi_action: [";
141 
142         final String log = getDevice().executeShellCommand("logcat --buffer=events -d");
143 
144         int counterNameIndex = log.indexOf(counterNamePattern);
145         Assert.assertTrue("did not find boot logs", counterNameIndex != -1);
146 
147         int multiLogStart = log.lastIndexOf(multiActionPattern, counterNameIndex);
148         multiLogStart += multiActionPattern.length();
149         int multiLogEnd = log.indexOf("]", multiLogStart);
150         String[] multiLogDataStrings = log.substring(multiLogStart, multiLogEnd).split(",");
151 
152         boolean foundBucket = false;
153         int bootTime = 0;
154         for (int i = 0; i < multiLogDataStrings.length; i += 2) {
155             if (bucketTag.equals(multiLogDataStrings[i])) {
156                 foundBucket = true;
157                 Assert.assertTrue("histogram data was truncated",
158                         (i + 1) < multiLogDataStrings.length);
159                 bootTime = Integer.valueOf(multiLogDataStrings[i + 1]);
160             }
161         }
162         Assert.assertTrue("log line did not contain a tag " + bucketTag, foundBucket);
163         Assert.assertTrue("reported boot time must be less than observed boot time",
164                 bootTime < upperBoundSeconds);
165         Assert.assertTrue("reported boot time must be non-zero", bootTime > 0);
166     }
167 
isBootCompleted()168     private boolean isBootCompleted() throws Exception {
169         return "1".equals(getDevice().executeShellCommand("getprop sys.boot_completed").trim());
170     }
171 
waitForBootCompleted()172     private void waitForBootCompleted() throws Exception {
173         for (int i = 0; i < 45; i++) {
174             if (isBootCompleted()) {
175                 return;
176             }
177             Thread.sleep(1000);
178         }
179         throw new AssertionError("System failed to become ready!");
180     }
181 
182     @Override
setDevice(ITestDevice device)183     public void setDevice(ITestDevice device) {
184         mDevice = device;
185     }
186 
187     @Override
getDevice()188     public ITestDevice getDevice() {
189         return mDevice;
190     }
191 }
192