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