1 /* 2 * Copyright (C) 2023 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.boottime; 18 19 import com.android.ddmlib.testrunner.IRemoteAndroidTestRunner; 20 import com.android.ddmlib.testrunner.RemoteAndroidTestRunner; 21 import com.android.tradefed.config.Option; 22 import com.android.tradefed.config.OptionClass; 23 import com.android.tradefed.device.DeviceNotAvailableException; 24 import com.android.tradefed.device.ITestDevice; 25 import com.android.tradefed.device.LogcatReceiver; 26 import com.android.tradefed.invoker.TestInformation; 27 import com.android.tradefed.log.LogUtil.CLog; 28 import com.android.tradefed.result.CollectingTestListener; 29 import com.android.tradefed.result.FileInputStreamSource; 30 import com.android.tradefed.result.InputStreamSource; 31 import com.android.tradefed.result.LogDataType; 32 import com.android.tradefed.testtype.DeviceJUnit4ClassRunner; 33 import com.android.tradefed.testtype.DeviceJUnit4ClassRunner.TestLogData; 34 import com.android.tradefed.testtype.DeviceJUnit4ClassRunner.TestMetrics; 35 import com.android.tradefed.testtype.junit4.BaseHostJUnit4Test; 36 import com.android.tradefed.testtype.junit4.BeforeClassWithInfo; 37 import com.android.tradefed.util.CommandResult; 38 import com.android.tradefed.util.CommandStatus; 39 import com.android.tradefed.util.RunUtil; 40 41 import org.junit.Before; 42 import org.junit.Rule; 43 import org.junit.Test; 44 import org.junit.runner.RunWith; 45 46 import java.io.File; 47 import java.util.ArrayList; 48 import java.util.List; 49 50 /** Performs successive reboots */ 51 @RunWith(DeviceJUnit4ClassRunner.class) 52 @OptionClass(alias = "boot-time-test") 53 public class BootTimeTest extends BaseHostJUnit4Test { 54 private static final String LOGCAT_CMD_ALL = "logcat -b all *:V"; 55 private static final String LOGCAT_CMD_CLEAR = "logcat -c"; 56 private static final long LOGCAT_SIZE = 80 * 1024 * 1024; 57 private static final String DMESG_FILE = "/data/local/tmp/dmesglogs.txt"; 58 private static final String DUMP_DMESG = String.format("dmesg > %s", DMESG_FILE); 59 private static final String LOGCAT_FILENAME = "Successive_reboots_logcat"; 60 private static final String DMESG_FILENAME = "Successive_reboots_dmesg"; 61 private static final String IMMEDIATE_DMESG_FILENAME = "Successive_reboots_immediate_dmesg"; 62 private static final String F2FS_SHUTDOWN_COMMAND = "f2fs_io shutdown 4 /data"; 63 private static final String F2FS_SHUTDOWN_SUCCESS_OUTPUT = "Shutdown /data with level=4"; 64 private static final String BOOT_TIME_PROP = "ro.boot.boottime"; 65 private static final String BOOT_TIME_PROP_KEY = "boot_time_prop"; 66 private static final String METRIC_KEY_SEPARATOR = "_"; 67 private static final String PERFETTO_TRACE_FILE_CHECK_CMD = "ls -l /data/misc/perfetto-traces"; 68 private static final String PERFETTO_TRACE_MV_CMD = 69 "mv /data/misc/perfetto-traces/boottrace.perfetto-trace %s"; 70 private static final String PERFETTO_FILE_PATH = "perfetto_file_path"; 71 private static final int BOOT_COMPLETE_POLL_INTERVAL = 1000; 72 private static final int BOOT_COMPLETE_POLL_RETRY_COUNT = 45; 73 private static final String PACKAGE_NAME = "com.android.boothelper"; 74 private static final String CLASS_NAME = "com.android.boothelper.BootHelperTest"; 75 private static final String RUNNER = "androidx.test.runner.AndroidJUnitRunner"; 76 private static final String UNLOCK_PIN_TEST = "unlockScreenWithPin"; 77 private static final String SETUP_PIN_TEST = "setupLockScreenPin"; 78 getBootTimePropKey()79 public static String getBootTimePropKey() { 80 return BOOT_TIME_PROP_KEY; 81 } 82 83 @Option( 84 name = "boot-count", 85 description = 86 "Number of times to boot the devices to calculate the successive boot delay." 87 + " Second boot after the first boot will be skipped for correctness.") 88 private int mBootCount = 5; 89 90 @Option( 91 name = "boot-delay", 92 isTimeVal = true, 93 description = "Time to wait between the successive boots.") 94 private long mBootDelayTime = 2000; 95 96 @Option( 97 name = "after-boot-delay", 98 isTimeVal = true, 99 description = "Time to wait immediately after the successive boots.") 100 private long mAfterBootDelayTime = 0; 101 102 @Option(name = "device-boot-time", description = "Max time in ms to wait for device to boot.") 103 protected long mDeviceBootTime = 5 * 60 * 1000; 104 105 @Option( 106 name = "successive-boot-prepare-cmd", 107 description = 108 "A list of adb commands to run after first boot to prepare for successive" 109 + " boot tests") 110 private List<String> mDeviceSetupCommands = new ArrayList<>(); 111 112 /** 113 * Use this flag not to dump the dmesg logs immediately after the device is online. Use it only 114 * if some of the boot dmesg logs are cleared when waiting until boot completed. By default this 115 * is set to true which might result in duplicate logging. 116 */ 117 @Option( 118 name = "dump-dmesg-immediate", 119 description = 120 "Whether to dump the dmesg logs" + "immediately after the device is online") 121 private boolean mDumpDmesgImmediate = true; 122 123 @Option( 124 name = "force-f2fs-shutdown", 125 description = "Force f2fs shutdown to trigger fsck check during the reboot.") 126 private boolean mForceF2FsShutdown = false; 127 128 @Option( 129 name = "skip-pin-setup", 130 description = 131 "Skip the pin setup if already set once" 132 + "and not needed for the second run especially in local testing.") 133 private boolean mSkipPinSetup = false; 134 135 @Option( 136 name = "enable-perfetto-trace", 137 description = "Enable perfetto trace collection during the reboot. True by default.") 138 private boolean mEnablePerfettoTrace = true; 139 140 private LogcatReceiver mRebootLogcatReceiver = null; 141 private IRemoteAndroidTestRunner mPostBootTestRunner = null; 142 143 @Rule public TestLogData testLog = new TestLogData(); 144 @Rule public TestMetrics testMetrics = new TestMetrics(); 145 146 /** 147 * Prepares the device for successive boots 148 * 149 * @param testInfo Test Information 150 * @throws DeviceNotAvailableException if connection with device is lost and cannot be 151 * recovered. 152 */ 153 @BeforeClassWithInfo beforeClassWithDevice(TestInformation testInfo)154 public static void beforeClassWithDevice(TestInformation testInfo) 155 throws DeviceNotAvailableException { 156 ITestDevice testDevice = testInfo.getDevice(); 157 158 testDevice.enableAdbRoot(); 159 testDevice.setDate(null); 160 testDevice.nonBlockingReboot(); 161 testDevice.waitForDeviceOnline(); 162 testDevice.waitForDeviceAvailable(0); 163 } 164 165 @Before setUp()166 public void setUp() throws Exception { 167 mPostBootTestRunner = null; 168 setUpDeviceForSuccessiveBoots(); 169 CLog.v("Waiting for %d msecs before successive boots.", mBootDelayTime); 170 sleep(mBootDelayTime); 171 mRebootLogcatReceiver = new LogcatReceiver(getDevice(), LOGCAT_CMD_ALL, LOGCAT_SIZE, 0); 172 mRebootLogcatReceiver.start(); 173 } 174 175 @Test testSuccessiveBoots()176 public void testSuccessiveBoots() throws Exception { 177 for (int count = 0; count < mBootCount; count++) { 178 testSuccessiveBoot(count); 179 } 180 } 181 182 @Test testSuccessiveBootsDismissPin()183 public void testSuccessiveBootsDismissPin() throws Exception { 184 // If pin is already set skip the setup method otherwise setup the pin. 185 if (!mSkipPinSetup) { 186 getDevice() 187 .runInstrumentationTests( 188 createRemoteAndroidTestRunner(SETUP_PIN_TEST), 189 new CollectingTestListener()); 190 } 191 mPostBootTestRunner = createRemoteAndroidTestRunner(UNLOCK_PIN_TEST); 192 for (int count = 0; count < mBootCount; count++) { 193 testSuccessiveBoot(count); 194 } 195 } 196 testSuccessiveBoot(int iteration)197 public void testSuccessiveBoot(int iteration) throws Exception { 198 CLog.v("Successive boot iteration %d", iteration); 199 getDevice().enableAdbRoot(); 200 // Property used for collecting the perfetto trace file on boot. 201 String setPerfettoPropValue = mEnablePerfettoTrace ? "1" : "\"\""; 202 String perfettoPropCmd = String.format("setprop persist.debug.perfetto.boottrace %s", setPerfettoPropValue); 203 getDevice().executeShellCommand(perfettoPropCmd); 204 if (mForceF2FsShutdown) { 205 forseF2FsShutdown(); 206 } 207 clearLogcat(); 208 sleep(5000); 209 getDevice().nonBlockingReboot(); 210 getDevice().waitForDeviceOnline(mDeviceBootTime); 211 getDevice().enableAdbRoot(); 212 if (mDumpDmesgImmediate) { 213 saveDmesgInfo( 214 String.format( 215 "%s%s%d", IMMEDIATE_DMESG_FILENAME, METRIC_KEY_SEPARATOR, iteration)); 216 } 217 waitForBootComplete(); 218 CLog.v("Waiting for %d msecs immediately after successive boot.", mAfterBootDelayTime); 219 sleep(mAfterBootDelayTime); 220 if (mPostBootTestRunner != null) { 221 sleep(2000); 222 getDevice().runInstrumentationTests(mPostBootTestRunner, new CollectingTestListener()); 223 } 224 saveDmesgInfo(String.format("%s%s%d", DMESG_FILENAME, METRIC_KEY_SEPARATOR, iteration)); 225 saveLogcatInfo(iteration); 226 // TODO(b/288323866): figure out why is the prop value null 227 String bootLoaderVal = getDevice().getProperty(BOOT_TIME_PROP); 228 // Sample Output : 1BLL:89,1BLE:590,2BLL:0,2BLE:1344,SW:6734,KL:1193 229 CLog.d("%s value is %s", BOOT_TIME_PROP, bootLoaderVal); 230 testMetrics.addTestMetric( 231 String.format("%s%s%d", BOOT_TIME_PROP_KEY, METRIC_KEY_SEPARATOR, iteration), 232 bootLoaderVal == null ? "" : bootLoaderVal); 233 String perfettoTraceFilePath = 234 processPerfettoFile( 235 String.format( 236 "%s%s%d", 237 BootTimeTest.class.getSimpleName(), 238 METRIC_KEY_SEPARATOR, 239 iteration)); 240 if (perfettoTraceFilePath != null) { 241 testMetrics.addTestMetric( 242 String.format("%s%s%d", PERFETTO_FILE_PATH, METRIC_KEY_SEPARATOR, iteration), 243 perfettoTraceFilePath); 244 } 245 } 246 setUpDeviceForSuccessiveBoots()247 private void setUpDeviceForSuccessiveBoots() throws DeviceNotAvailableException { 248 for (String cmd : mDeviceSetupCommands) { 249 CommandResult result; 250 result = getDevice().executeShellV2Command(cmd); 251 if (!CommandStatus.SUCCESS.equals(result.getStatus())) { 252 CLog.w( 253 "Post boot setup cmd: '%s' failed, returned:\nstdout:%s\nstderr:%s", 254 cmd, result.getStdout(), result.getStderr()); 255 } 256 } 257 } 258 forseF2FsShutdown()259 private void forseF2FsShutdown() throws DeviceNotAvailableException { 260 String output = getDevice().executeShellCommand(F2FS_SHUTDOWN_COMMAND).trim(); 261 if (!F2FS_SHUTDOWN_SUCCESS_OUTPUT.equalsIgnoreCase(output)) { 262 CLog.e("Unable to shutdown the F2FS."); 263 } else { 264 CLog.i("F2FS shutdown successful."); 265 } 266 } 267 saveLogcatInfo(int iteration)268 private void saveLogcatInfo(int iteration) { 269 try (InputStreamSource logcat = mRebootLogcatReceiver.getLogcatData()) { 270 String testLogKey = 271 String.format("%s%s%d", LOGCAT_FILENAME, METRIC_KEY_SEPARATOR, iteration); 272 testLog.addTestLog(testLogKey, LogDataType.LOGCAT, logcat); 273 } 274 } 275 saveDmesgInfo(String filename)276 private void saveDmesgInfo(String filename) throws DeviceNotAvailableException { 277 getDevice().executeShellCommand(DUMP_DMESG); 278 File dmesgFile = getDevice().pullFile(DMESG_FILE); 279 testLog.addTestLog( 280 filename, LogDataType.HOST_LOG, new FileInputStreamSource(dmesgFile, false)); 281 } 282 clearLogcat()283 private void clearLogcat() throws DeviceNotAvailableException { 284 getDevice().executeShellCommand(LOGCAT_CMD_CLEAR); 285 mRebootLogcatReceiver.clear(); 286 } 287 sleep(long duration)288 private void sleep(long duration) { 289 RunUtil.getDefault().sleep(duration); 290 } 291 292 /** 293 * Look for the perfetto trace file collected during reboot under /data/misc/perfetto-traces and 294 * copy the file under /data/local/tmp using the test iteration name and return the path to the 295 * newly copied trace file. 296 */ processPerfettoFile(String testId)297 private String processPerfettoFile(String testId) throws DeviceNotAvailableException { 298 CommandResult result = getDevice().executeShellV2Command(PERFETTO_TRACE_FILE_CHECK_CMD); 299 if (result != null) { 300 CLog.i( 301 "Command Output: Cmd - %s, Output - %s, Error - %s, Status - %s", 302 PERFETTO_TRACE_FILE_CHECK_CMD, 303 result.getStdout(), 304 result.getStderr(), 305 result.getStatus()); 306 if (CommandStatus.SUCCESS.equals(result.getStatus()) 307 && result.getStdout().contains("boottrace.perfetto-trace")) { 308 // Move the perfetto trace file to the new location and rename it using the test 309 // name. 310 String finalTraceFileLocation = 311 String.format("/data/local/tmp/%s.perfetto-trace", testId); 312 CommandResult moveResult = 313 getDevice() 314 .executeShellV2Command( 315 String.format( 316 PERFETTO_TRACE_MV_CMD, finalTraceFileLocation)); 317 if (moveResult != null) { 318 CLog.i( 319 "Command Output: Cmd - %s, Output - %s, Error - %s, Status - %s", 320 PERFETTO_TRACE_MV_CMD, 321 moveResult.getStdout(), 322 moveResult.getStderr(), 323 moveResult.getStatus()); 324 if (CommandStatus.SUCCESS.equals(result.getStatus())) { 325 return finalTraceFileLocation; 326 } 327 } 328 } 329 } 330 return null; 331 } 332 waitForBootComplete()333 private void waitForBootComplete() throws DeviceNotAvailableException { 334 for (int i = 0; i < BOOT_COMPLETE_POLL_RETRY_COUNT; i++) { 335 if (isBootCompleted()) { 336 return; 337 } 338 CLog.v(String.format("waitForBootComplete %d", i)); 339 sleep(BOOT_COMPLETE_POLL_INTERVAL); 340 } 341 throw new DeviceNotAvailableException( 342 "Can't confirm boot complete. Exhausted retries. sys.boot_completed property does" 343 + " not equal 1.", 344 getDevice().getSerialNumber()); 345 } 346 isBootCompleted()347 private boolean isBootCompleted() throws DeviceNotAvailableException { 348 return "1".equals(getDevice().getProperty("sys.boot_completed")); 349 } 350 351 /** 352 * Method to create the runner with given testName 353 * 354 * @return the {@link IRemoteAndroidTestRunner} to use. 355 */ createRemoteAndroidTestRunner(String testName)356 IRemoteAndroidTestRunner createRemoteAndroidTestRunner(String testName) 357 throws DeviceNotAvailableException { 358 RemoteAndroidTestRunner runner = 359 new RemoteAndroidTestRunner(PACKAGE_NAME, RUNNER, getDevice().getIDevice()); 360 runner.setMethodName(CLASS_NAME, testName); 361 return runner; 362 } 363 } 364