1 /* 2 * Copyright (C) 2018 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 package com.android.tradefed.device.cloud; 17 18 import com.android.tradefed.build.IBuildInfo; 19 import com.android.tradefed.command.remote.DeviceDescriptor; 20 import com.android.tradefed.device.TestDeviceOptions; 21 import com.android.tradefed.device.TestDeviceOptions.InstanceType; 22 import com.android.tradefed.device.cloud.AcloudConfigParser.AcloudKeys; 23 import com.android.tradefed.device.cloud.GceAvdInfo.GceStatus; 24 import com.android.tradefed.error.HarnessRuntimeException; 25 import com.android.tradefed.invoker.logger.InvocationMetricLogger; 26 import com.android.tradefed.invoker.logger.InvocationMetricLogger.InvocationMetricKey; 27 import com.android.tradefed.invoker.tracing.CloseableTraceScope; 28 import com.android.tradefed.log.ITestLogger; 29 import com.android.tradefed.log.LogUtil.CLog; 30 import com.android.tradefed.result.ByteArrayInputStreamSource; 31 import com.android.tradefed.result.FileInputStreamSource; 32 import com.android.tradefed.result.InputStreamSource; 33 import com.android.tradefed.result.LogDataType; 34 import com.android.tradefed.result.error.ErrorIdentifier; 35 import com.android.tradefed.result.error.InfraErrorIdentifier; 36 import com.android.tradefed.targetprep.TargetSetupError; 37 import com.android.tradefed.util.CommandResult; 38 import com.android.tradefed.util.CommandStatus; 39 import com.android.tradefed.util.FileUtil; 40 import com.android.tradefed.util.GoogleApiClientUtil; 41 import com.android.tradefed.util.IRunUtil; 42 import com.android.tradefed.util.MultiMap; 43 import com.android.tradefed.util.RunUtil; 44 import com.android.tradefed.util.avd.AcloudUtil; 45 import com.android.tradefed.util.avd.HostOrchestratorUtil; 46 import com.android.tradefed.util.avd.InspectionUtil; 47 import com.android.tradefed.util.avd.LogCollector; 48 import com.android.tradefed.util.avd.OxygenClient; 49 50 import com.google.api.client.googleapis.javanet.GoogleNetHttpTransport; 51 import com.google.api.client.http.HttpRequestInitializer; 52 import com.google.api.client.json.JsonFactory; 53 import com.google.api.client.json.gson.GsonFactory; 54 import com.google.api.services.compute.Compute; 55 import com.google.api.services.compute.Compute.Instances.GetSerialPortOutput; 56 import com.google.api.services.compute.ComputeScopes; 57 import com.google.api.services.compute.model.SerialPortOutput; 58 import com.google.auth.Credentials; 59 import com.google.auth.http.HttpCredentialsAdapter; 60 import com.google.common.annotations.VisibleForTesting; 61 import com.google.common.base.Strings; 62 import com.google.common.collect.Lists; 63 import com.google.common.net.HostAndPort; 64 65 import java.io.File; 66 import java.io.IOException; 67 import java.lang.ProcessBuilder.Redirect; 68 import java.security.GeneralSecurityException; 69 import java.time.Duration; 70 import java.util.ArrayList; 71 import java.util.Arrays; 72 import java.util.List; 73 import java.util.regex.Matcher; 74 import java.util.regex.Pattern; 75 76 /** Helper that manages the GCE calls to start/stop and collect logs from GCE. */ 77 public class GceManager { 78 public static final String GCE_INSTANCE_NAME_KEY = "gce-instance-name"; 79 public static final String GCE_HOSTNAME_KEY = "gce-hostname"; 80 public static final String GCE_INSTANCE_CLEANED_KEY = "gce-instance-clean-called"; 81 public static final String GCE_IP_PRECONFIGURED_KEY = "gce-ip-pre-configured"; 82 83 // Align default value of bugreport timeout with option bugreportz-timeout 84 private static final long BUGREPORT_TIMEOUT = 5 * 60 * 1000L; 85 private static final long REMOTE_FILE_OP_TIMEOUT = 10 * 60 * 1000L; 86 private static final Pattern BUGREPORTZ_RESPONSE_PATTERN = Pattern.compile("(OK:)(.*)"); 87 private static final JsonFactory JSON_FACTORY = GsonFactory.getDefaultInstance(); 88 private static final List<String> SCOPES = Arrays.asList(ComputeScopes.COMPUTE_READONLY); 89 90 // Create list of error codes that warrant a lease retry 91 private static final List<InfraErrorIdentifier> RETRIABLE_LEASE_ERRORS = 92 new ArrayList<>( 93 Arrays.asList( 94 InfraErrorIdentifier.OXYGEN_BAD_GATEWAY_ERROR, 95 InfraErrorIdentifier.OXYGEN_CLIENT_BINARY_ERROR, 96 InfraErrorIdentifier.OXYGEN_SERVER_CONNECTION_FAILURE, 97 InfraErrorIdentifier.OXYGEN_SERVER_LB_CONNECTION_ERROR, 98 InfraErrorIdentifier.OXYGEN_SERVER_SHUTTING_DOWN)); 99 private static final int MAX_LEASE_RETRIES = 3; 100 private DeviceDescriptor mDeviceDescriptor; 101 private TestDeviceOptions mDeviceOptions; 102 private IBuildInfo mBuildInfo; 103 104 private String mGceInstanceName = null; 105 private String mGceHost = null; 106 private GceAvdInfo mGceAvdInfo = null; 107 private HostOrchestratorUtil mHOUtil = null; 108 109 private boolean mSkipSerialLogCollection = false; 110 111 /** 112 * Ctor 113 * 114 * @param deviceDesc The {@link DeviceDescriptor} that will be associated with the GCE device. 115 * @param deviceOptions A {@link TestDeviceOptions} associated with the device. 116 * @param buildInfo A {@link IBuildInfo} describing the gce build to start. 117 */ GceManager( DeviceDescriptor deviceDesc, TestDeviceOptions deviceOptions, IBuildInfo buildInfo)118 public GceManager( 119 DeviceDescriptor deviceDesc, TestDeviceOptions deviceOptions, IBuildInfo buildInfo) { 120 mDeviceDescriptor = deviceDesc; 121 mDeviceOptions = deviceOptions; 122 mBuildInfo = buildInfo; 123 124 if (!deviceOptions.allowGceCmdTimeoutOverride()) { 125 return; 126 } 127 int index = deviceOptions.getGceDriverParams().lastIndexOf("--boot-timeout"); 128 if (index != -1 && deviceOptions.getGceDriverParams().size() > index + 1) { 129 String driverTimeoutStringSec = deviceOptions.getGceDriverParams().get(index + 1); 130 try { 131 // Add some extra time on top of Acloud: acloud boot the device then we expect 132 // the Tradefed online check to take a bit of time, use 3min as a safe overhead 133 long driverTimeoutMs = 134 Long.parseLong(driverTimeoutStringSec) * 1000 + 3 * 60 * 1000; 135 long gceCmdTimeoutMs = deviceOptions.getGceCmdTimeout(); 136 deviceOptions.setGceCmdTimeout(driverTimeoutMs); 137 CLog.i( 138 "Replacing --gce-boot-timeout %s by --boot-timeout %s.", 139 gceCmdTimeoutMs, driverTimeoutMs); 140 } catch (NumberFormatException e) { 141 CLog.e(e); 142 } 143 } 144 } 145 146 /** @deprecated Use other constructors, we keep this temporarily for backward compatibility. */ 147 @Deprecated GceManager( DeviceDescriptor deviceDesc, TestDeviceOptions deviceOptions, IBuildInfo buildInfo, List<IBuildInfo> testResourceBuildInfos)148 public GceManager( 149 DeviceDescriptor deviceDesc, 150 TestDeviceOptions deviceOptions, 151 IBuildInfo buildInfo, 152 List<IBuildInfo> testResourceBuildInfos) { 153 this(deviceDesc, deviceOptions, buildInfo); 154 } 155 156 /** 157 * Ctor, variation that can be used to provide the GCE instance name to use directly. 158 * 159 * @param deviceDesc The {@link DeviceDescriptor} that will be associated with the GCE device. 160 * @param deviceOptions A {@link TestDeviceOptions} associated with the device 161 * @param buildInfo A {@link IBuildInfo} describing the gce build to start. 162 * @param gceInstanceName The instance name to use. 163 * @param gceHost The host name or ip of the instance to use. 164 */ GceManager( DeviceDescriptor deviceDesc, TestDeviceOptions deviceOptions, IBuildInfo buildInfo, String gceInstanceName, String gceHost)165 public GceManager( 166 DeviceDescriptor deviceDesc, 167 TestDeviceOptions deviceOptions, 168 IBuildInfo buildInfo, 169 String gceInstanceName, 170 String gceHost) { 171 this(deviceDesc, deviceOptions, buildInfo); 172 mGceInstanceName = gceInstanceName; 173 mGceHost = gceHost; 174 } 175 startGce()176 public GceAvdInfo startGce() throws TargetSetupError { 177 return startGce(null, null, null, null); 178 } 179 180 /** 181 * Attempt to start a gce instance. 182 * 183 * @param ipDevice the initial IP of the GCE instance to run AVD in, <code>null</code> if not 184 * applicable 185 * @param attributes attributes associated with current invocation, used for passing applicable 186 * information down to the GCE instance to be added as VM metadata 187 * @return a {@link GceAvdInfo} describing the GCE instance. Could be a BOOT_FAIL instance. 188 * @throws TargetSetupError 189 */ startGce(String ipDevice, MultiMap<String, String> attributes)190 public GceAvdInfo startGce(String ipDevice, MultiMap<String, String> attributes) 191 throws TargetSetupError { 192 return startGce(ipDevice, null, null, attributes); 193 } 194 195 /** 196 * Attempt to start a gce instance with either Acloud or Oxygen. 197 * 198 * @param ipDevice the initial IP of the GCE instance to run AVD in, <code>null</code> if not 199 * applicable 200 * @param user the host running user of AVD, <code>null</code> if not applicable 201 * @param offset the device num offset of the AVD in the host, <code>null</code> if not 202 * applicable 203 * @param attributes attributes associated with current invocation, used for passing applicable 204 * information down to the GCE instance to be added as VM metadata 205 * @return a {@link GceAvdInfo} describing the GCE instance. Could be a BOOT_FAIL instance. 206 * @throws TargetSetupError 207 */ startGce( String ipDevice, String user, Integer offset, MultiMap<String, String> attributes)208 public GceAvdInfo startGce( 209 String ipDevice, String user, Integer offset, MultiMap<String, String> attributes) 210 throws TargetSetupError { 211 return startGce(ipDevice, user, offset, attributes, null); 212 } 213 214 /** 215 * Attempt to start a gce instance with either Acloud or Oxygen. 216 * 217 * @param ipDevice the initial IP of the GCE instance to run AVD in, <code>null</code> if not 218 * applicable 219 * @param user the host running user of AVD, <code>null</code> if not applicable 220 * @param offset the device num offset of the AVD in the host, <code>null</code> if not 221 * applicable 222 * @param attributes attributes associated with current invocation, used for passing applicable 223 * information down to the GCE instance to be added as VM metadata 224 * @param logger The {@link ITestLogger} where to log the device launch logs. 225 * @return a {@link GceAvdInfo} describing the GCE instance. Could be a BOOT_FAIL instance. 226 * @throws TargetSetupError 227 */ startGce( String ipDevice, String user, Integer offset, MultiMap<String, String> attributes, ITestLogger logger)228 public GceAvdInfo startGce( 229 String ipDevice, 230 String user, 231 Integer offset, 232 MultiMap<String, String> attributes, 233 ITestLogger logger) 234 throws TargetSetupError { 235 // If ipDevice is specified, skip collecting serial log as the host may not be GCE instance 236 // If Oxygen cuttlefish is used, skip collecting serial log due to lack of access. 237 mSkipSerialLogCollection = 238 (!Strings.isNullOrEmpty(ipDevice) 239 || getTestDeviceOptions().useOxygen() 240 || getTestDeviceOptions().useCvdCF()); 241 if (getTestDeviceOptions().useOxygen() || getTestDeviceOptions().useCvdCF()) { 242 // Validate binary 243 File clientBinary = getTestDeviceOptions().getAvdDriverBinary(); 244 String error = null; 245 if (clientBinary == null) { 246 error = "the Oxygen client binary reference is null"; 247 } else if (!clientBinary.exists()) { 248 error = 249 String.format( 250 "the Oxygen client binary file does not exist at %s", 251 clientBinary.getAbsolutePath()); 252 } else if (!clientBinary.canExecute()) { 253 error = 254 String.format( 255 "the Oxygen client binary file at %s is not executable", 256 clientBinary.getAbsolutePath()); 257 } 258 if (!Strings.isNullOrEmpty(error)) { 259 throw new HarnessRuntimeException( 260 String.format("Error in instantiating OxygenClient class: %s", error), 261 InfraErrorIdentifier.CONFIGURED_ARTIFACT_NOT_FOUND); 262 } 263 // Leasing an oxygenation device will still depend on the existing oxygen client tool 264 // with more parameters passed in. 265 return startGceWithOxygenClient(logger, attributes); 266 } else { 267 return startGceWithAcloud(ipDevice, user, offset, attributes); 268 } 269 } 270 271 /** 272 * @deprecated Remove this after master branch is updated. 273 */ 274 @Deprecated startMultiDevicesGce(List<IBuildInfo> buildInfos)275 public List<GceAvdInfo> startMultiDevicesGce(List<IBuildInfo> buildInfos) 276 throws TargetSetupError { 277 return startMultiDevicesGce(buildInfos, null); 278 } 279 280 /** 281 * Attempt to start multi devices gce instance with Oxygen. 282 * 283 * @param buildInfos {@link List<IBuildInfo>} 284 * @param attributes attributes associated with current invocation 285 * @return a {@link List<GceAvdInfo>} describing the GCE Avd Info. 286 */ startMultiDevicesGce( List<IBuildInfo> buildInfos, MultiMap<String, String> attributes)287 public List<GceAvdInfo> startMultiDevicesGce( 288 List<IBuildInfo> buildInfos, MultiMap<String, String> attributes) 289 throws TargetSetupError { 290 List<GceAvdInfo> gceAvdInfos; 291 long startTime = System.currentTimeMillis(); 292 try (CloseableTraceScope ignore = new CloseableTraceScope("startMultiDevicesGce")) { 293 OxygenClient oxygenClient = 294 OxygenUtil.createOxygenClient(getTestDeviceOptions().getAvdDriverBinary()); 295 List<String> buildTargets = new ArrayList<>(); 296 List<String> buildBranches = new ArrayList<>(); 297 List<String> buildIds = new ArrayList<>(); 298 299 for (IBuildInfo b : buildInfos) { 300 if (b.getBuildAttributes().containsKey("build_target")) { 301 // If BuildInfo contains the attribute for a build target, use that. 302 buildTargets.add(b.getBuildAttributes().get("build_target")); 303 } else { 304 buildTargets.add(b.getBuildFlavor()); 305 } 306 buildBranches.add(b.getBuildBranch()); 307 buildIds.add(b.getBuildId()); 308 } 309 310 CommandResult res = 311 oxygenClient.leaseMultipleDevices( 312 buildTargets, 313 buildBranches, 314 buildIds, 315 OxygenUtil.getTargetRegion(getTestDeviceOptions()), 316 getTestDeviceOptions().getOxygenAccountingUser(), 317 getTestDeviceOptions().getOxygenLeaseLength(), 318 getTestDeviceOptions().getExtraOxygenArgs(), 319 attributes, 320 getTestDeviceOptions().getGceCmdTimeout(), 321 getTestDeviceOptions().useOxygenationDevice()); 322 gceAvdInfos = GceAvdInfo.parseGceInfoFromOxygenClientOutput(res, mDeviceOptions); 323 mGceAvdInfo = gceAvdInfos.get(0); 324 return gceAvdInfos; 325 } finally { 326 InvocationMetricLogger.addInvocationMetrics( 327 InvocationMetricKey.OXYGEN_DEVICE_DIRECT_LEASE_COUNT, 2); 328 InvocationMetricLogger.addInvocationMetrics( 329 InvocationMetricKey.CF_LAUNCH_CVD_TIME, System.currentTimeMillis() - startTime); 330 } 331 } 332 333 /** 334 * Attempt to start a gce instance with Oxygen. 335 * 336 * @param logger The {@link ITestLogger} where to log the device launch logs. 337 * @param attributes attributes associated with current invocation 338 * @return a {@link GceAvdInfo} describing the GCE instance. 339 */ startGceWithOxygenClient( ITestLogger logger, MultiMap<String, String> attributes)340 private GceAvdInfo startGceWithOxygenClient( 341 ITestLogger logger, MultiMap<String, String> attributes) throws TargetSetupError { 342 long startTime = System.currentTimeMillis(); 343 long fetchTime = 0; 344 try { 345 OxygenClient oxygenClient = 346 OxygenUtil.createOxygenClient(getTestDeviceOptions().getAvdDriverBinary()); 347 String buildTarget = 348 mBuildInfo.getBuildAttributes().containsKey("build_target") 349 ? mBuildInfo.getBuildAttributes().get("build_target") 350 : mBuildInfo.getBuildFlavor(); 351 CommandResult res = 352 oxygenClient.leaseDevice( 353 buildTarget, 354 mBuildInfo.getBuildBranch(), 355 mBuildInfo.getBuildId(), 356 OxygenUtil.getTargetRegion(getTestDeviceOptions()), 357 getTestDeviceOptions().getOxygenAccountingUser(), 358 getTestDeviceOptions().getOxygenLeaseLength(), 359 getTestDeviceOptions().getGceDriverParams(), 360 getTestDeviceOptions().getExtraOxygenArgs(), 361 attributes, 362 getTestDeviceOptions().getGceCmdTimeout(), 363 getTestDeviceOptions().useOxygenationDevice()); 364 365 // Retry lease up to 2x if error code is in list of error codes 366 int iteration = 1; 367 while (res.getStatus() != CommandStatus.SUCCESS && iteration < MAX_LEASE_RETRIES) { 368 InfraErrorIdentifier identifier = GceAvdInfo.refineOxygenErrorType(res.getStderr()); 369 if (!RETRIABLE_LEASE_ERRORS.contains(identifier)) { 370 break; 371 } 372 CLog.d("Retrying lease call due to earlier failure of %s", identifier); 373 res = 374 oxygenClient.leaseDevice( 375 buildTarget, 376 mBuildInfo.getBuildBranch(), 377 mBuildInfo.getBuildId(), 378 OxygenUtil.getTargetRegion(getTestDeviceOptions()), 379 getTestDeviceOptions().getOxygenAccountingUser(), 380 getTestDeviceOptions().getOxygenLeaseLength(), 381 getTestDeviceOptions().getGceDriverParams(), 382 getTestDeviceOptions().getExtraOxygenArgs(), 383 attributes, 384 getTestDeviceOptions().getGceCmdTimeout(), 385 getTestDeviceOptions().useOxygenationDevice()); 386 // Update Oxygen lease attempt metrics 387 if (res.getStatus() == CommandStatus.SUCCESS) { 388 InvocationMetricLogger.addInvocationMetrics( 389 InvocationMetricKey.LEASE_RETRY_COUNT_SUCCESS, iteration); 390 } else { 391 InvocationMetricLogger.addInvocationMetrics( 392 InvocationMetricKey.LEASE_RETRY_COUNT_FAILURE, iteration); 393 } 394 iteration++; 395 } 396 mGceAvdInfo = GceAvdInfo.parseGceInfoFromOxygenClientOutput(res, mDeviceOptions).get(0); 397 398 // Lease may time out, skip remaining logic if lease failed. 399 if (mGceAvdInfo.hostAndPort() == null) { 400 CLog.w("Failed to lease a device: %s", mGceAvdInfo); 401 return mGceAvdInfo; 402 } 403 if (getTestDeviceOptions().getExtraOxygenArgs().containsKey("no_wait_for_boot")) { 404 CLog.d( 405 "Device leased without waiting for boot to finish. Poll emulator_stderr.txt" 406 + " for flag `VIRTUAL_DEVICE_BOOT_COMPLETED`"); 407 // When leasing without wait for boot to finish, use the time spent so far as the 408 // best estimate of cf_fetch_artifact_time_ms. 409 fetchTime = System.currentTimeMillis() - startTime; 410 Boolean bootSuccess = false; 411 long timeout = 412 startTime 413 + getTestDeviceOptions().getGceCmdTimeout() 414 - System.currentTimeMillis(); 415 startTime = System.currentTimeMillis(); 416 if (getTestDeviceOptions().useCvdCF()) { 417 mHOUtil = 418 new HostOrchestratorUtil( 419 getTestDeviceOptions().useOxygenationDevice(), 420 getTestDeviceOptions().getExtraOxygenArgs(), 421 mGceAvdInfo.instanceName(), 422 mGceAvdInfo.hostAndPort() != null 423 ? mGceAvdInfo.hostAndPort().getHost() 424 : null, 425 mGceAvdInfo.getOxygenationDeviceId(), 426 OxygenUtil.getTargetRegion(getTestDeviceOptions()), 427 getTestDeviceOptions().getOxygenAccountingUser(), 428 oxygenClient); 429 bootSuccess = mHOUtil.deviceBootCompleted(timeout); 430 } else { 431 final String remoteFile = 432 CommonLogRemoteFileUtil.OXYGEN_EMULATOR_LOG_DIR 433 + "3/emulator_stderr.txt"; 434 // Continuously scan cf boot status and exit immediately when the magic string 435 // VIRTUAL_DEVICE_BOOT_COMPLETED is found 436 String cfBootStatusSshCmd = 437 "tail -F -n +1 " 438 + remoteFile 439 + " | grep -m 1 VIRTUAL_DEVICE_BOOT_COMPLETED"; 440 String[] cfBootStatusSshCommand = cfBootStatusSshCmd.split(" "); 441 442 res = 443 remoteSshCommandExecution( 444 mGceAvdInfo, 445 getTestDeviceOptions(), 446 RunUtil.getDefault(), 447 timeout, 448 cfBootStatusSshCommand); 449 if (CommandStatus.SUCCESS.equals(res.getStatus())) { 450 bootSuccess = true; 451 CLog.d( 452 "Device boot completed after %sms, flag located: %s", 453 System.currentTimeMillis() - startTime, res.getStdout().trim()); 454 } 455 } 456 457 if (!bootSuccess) { 458 if (logger != null) { 459 if (getTestDeviceOptions().useCvdCF()) { 460 CommonLogRemoteFileUtil.pullCommonCvdLogs( 461 mGceAvdInfo, mHOUtil, logger, getTestDeviceOptions()); 462 } else { 463 CommonLogRemoteFileUtil.fetchCommonFiles( 464 logger, mGceAvdInfo, getTestDeviceOptions(), getRunUtil()); 465 } 466 } 467 468 String errorSignatures = 469 InvocationMetricLogger.getInvocationMetrics() 470 .get(InvocationMetricKey.DEVICE_ERROR_SIGNATURES.toString()); 471 ErrorIdentifier errorIdentifier = 472 InspectionUtil.convertErrorSignatureToIdentifier(errorSignatures); 473 if (errorIdentifier == null) { 474 errorIdentifier = InfraErrorIdentifier.OXYGEN_DEVICE_LAUNCHER_TIMEOUT; 475 } 476 mGceAvdInfo.setErrorType(errorIdentifier); 477 mGceAvdInfo.setStatus(GceStatus.BOOT_FAIL); 478 // Align the error message raised when Oxygen lease timed out. 479 mGceAvdInfo.setErrors("Timed out waiting for virtual device to start."); 480 } 481 } 482 InvocationMetricLogger.addInvocationMetrics( 483 InvocationMetricKey.CF_OXYGEN_SESSION_ID, mGceAvdInfo.instanceName()); 484 InvocationMetricLogger.addInvocationMetrics( 485 InvocationMetricKey.CF_OXYGEN_SERVER_URL, mGceAvdInfo.hostAndPort().getHost()); 486 return mGceAvdInfo; 487 } finally { 488 InvocationMetricLogger.addInvocationMetrics( 489 InvocationMetricKey.OXYGEN_DEVICE_DIRECT_LEASE_COUNT, 1); 490 if (mGceAvdInfo != null && GceStatus.SUCCESS.equals(mGceAvdInfo.getStatus())) { 491 InvocationMetricLogger.addInvocationMetrics( 492 InvocationMetricKey.CF_FETCH_ARTIFACT_TIME, fetchTime); 493 InvocationMetricLogger.addInvocationMetrics( 494 InvocationMetricKey.CF_LAUNCH_CVD_TIME, 495 System.currentTimeMillis() - startTime); 496 } 497 } 498 } 499 logAndDeleteFile(File tempFile, String dataName, ITestLogger logger)500 public static void logAndDeleteFile(File tempFile, String dataName, ITestLogger logger) { 501 if (tempFile == null || logger == null) { 502 CLog.i("Skip logging due to either null file or null logger..."); 503 return; 504 } 505 logger.testLog(dataName, LogDataType.CUTTLEFISH_LOG, new FileInputStreamSource(tempFile)); 506 FileUtil.deleteFile(tempFile); 507 } 508 509 /** 510 * Attempt to start a gce instance with Acloud. 511 * 512 * @param ipDevice the initial IP of the GCE instance to run AVD in, <code>null</code> if not 513 * applicable 514 * @param user the host running user of AVD, <code>null</code> if not applicable 515 * @param offset the device num offset of the AVD in the host, <code>null</code> if not 516 * applicable 517 * @param attributes attributes associated with current invocation, used for passing applicable 518 * information down to the GCE instance to be added as VM metadata 519 * @return a {@link GceAvdInfo} describing the GCE instance. Could be a BOOT_FAIL instance. 520 * @throws TargetSetupError 521 */ startGceWithAcloud( String ipDevice, String user, Integer offset, MultiMap<String, String> attributes)522 private GceAvdInfo startGceWithAcloud( 523 String ipDevice, String user, Integer offset, MultiMap<String, String> attributes) 524 throws TargetSetupError { 525 mGceAvdInfo = null; 526 // For debugging purposes bypass. 527 if (mGceHost != null && mGceInstanceName != null) { 528 mGceAvdInfo = 529 new GceAvdInfo( 530 mGceInstanceName, 531 HostAndPort.fromString(mGceHost) 532 .withDefaultPort(mDeviceOptions.getRemoteAdbPort())); 533 mGceAvdInfo.setIpPreconfigured(ipDevice != null); 534 mGceAvdInfo.setDeviceOffset(offset); 535 mGceAvdInfo.setInstanceUser(user); 536 return mGceAvdInfo; 537 } 538 539 mBuildInfo.addBuildAttribute(GCE_IP_PRECONFIGURED_KEY, Boolean.toString(ipDevice != null)); 540 541 // Add extra args. 542 File reportFile = null; 543 try { 544 reportFile = FileUtil.createTempFile("gce_avd_driver", ".json"); 545 // Override the instance name by specified user 546 if (user != null) { 547 getTestDeviceOptions().setInstanceUser(user); 548 } 549 550 List<String> extraArgs = Lists.newArrayList(); 551 552 if (TestDeviceOptions.InstanceType.CHEEPS.equals( 553 getTestDeviceOptions().getInstanceType())) { 554 extraArgs.add("--avd-type"); 555 extraArgs.add("cheeps"); 556 557 if (getTestDeviceOptions().getCrosUser() != null 558 && getTestDeviceOptions().getCrosPassword() != null) { 559 extraArgs.add("--user"); 560 extraArgs.add(getTestDeviceOptions().getCrosUser()); 561 extraArgs.add("--password"); 562 extraArgs.add(getTestDeviceOptions().getCrosPassword()); 563 } 564 } 565 566 String debugOption = null; 567 switch (getTestDeviceOptions().getGceDriverLogLevel()) { 568 case DEBUG: 569 debugOption = "-v"; 570 break; 571 case VERBOSE: 572 debugOption = "-vv"; 573 break; 574 default: 575 break; 576 } 577 if (debugOption != null) { 578 extraArgs.add(debugOption); 579 } 580 581 String buildTarget = mBuildInfo.getBuildFlavor(); 582 if (mBuildInfo.getBuildAttributes().containsKey("build_target")) { 583 // If BuildInfo contains the attribute for a build target, use that. 584 buildTarget = mBuildInfo.getBuildAttributes().get("build_target"); 585 } 586 587 MultiMap<File, String> extraFiles = getTestDeviceOptions().getExtraFiles(); 588 List<String> extraParamsByInstanceType = 589 TestDeviceOptions.getExtraParamsByInstanceType( 590 getTestDeviceOptions().getInstanceType(), 591 getTestDeviceOptions().getBaseImage()); 592 593 String hostUser = user != null ? user : getTestDeviceOptions().getInstanceUser(); 594 if (offset != null) { 595 getTestDeviceOptions().setRemoteAdbPort(6520 + offset); 596 } 597 String serviceAccountKeyPath = null; 598 if (getTestDeviceOptions().getServiceAccountJsonKeyFile() != null) { 599 serviceAccountKeyPath = 600 getTestDeviceOptions().getServiceAccountJsonKeyFile().getAbsolutePath(); 601 } 602 603 // process any info in the invocation context that should be passed onto GCE driver 604 // as meta data to be associated with the VM instance 605 if (attributes != null) { 606 for (String key : getTestDeviceOptions().getInvocationAttributeToMetadata()) { 607 for (String value : attributes.get(key)) { 608 extraArgs.add("--gce-metadata"); 609 extraArgs.add(String.format("%s:%s", key, value)); 610 } 611 } 612 } 613 // Get extra params by instance type 614 extraArgs.addAll(extraParamsByInstanceType); 615 if (getAvdConfigFile() != null) { 616 extraArgs.add("--config_file"); 617 extraArgs.add(getAvdConfigFile().getAbsolutePath()); 618 } 619 620 List<String> gceArgs = 621 AcloudUtil.buildGceCmd( 622 getTestDeviceOptions().getAvdDriverBinary().getAbsolutePath(), 623 TestDeviceOptions.getCreateCommandByInstanceType( 624 getTestDeviceOptions().getInstanceType()), 625 reportFile, 626 buildTarget, 627 mBuildInfo.getBuildBranch(), 628 mBuildInfo.getBuildId(), 629 ipDevice, 630 hostUser, 631 getTestDeviceOptions().getSshPrivateKeyPath().getAbsolutePath(), 632 extraArgs, 633 serviceAccountKeyPath, 634 offset, 635 getTestDeviceOptions().getGceAccount(), 636 getTestDeviceOptions().getGceDriverParams(), 637 getTestDeviceOptions().getGceDriverFileParams(), 638 extraFiles); 639 640 long driverTimeoutMs = getTestDeviceOptions().getGceCmdTimeout(); 641 if (!getTestDeviceOptions().allowGceCmdTimeoutOverride()) { 642 long driverTimeoutSec = 643 Duration.ofMillis(driverTimeoutMs - 3 * 60 * 1000).toSeconds(); 644 // --boot-timeout takes a value in seconds 645 gceArgs.add("--boot-timeout"); 646 gceArgs.add(Long.toString(driverTimeoutSec)); 647 driverTimeoutMs = driverTimeoutSec * 1000; 648 } 649 650 CLog.i("Launching GCE with %s", gceArgs.toString()); 651 CommandResult cmd = 652 getRunUtil() 653 .runTimedCmd( 654 getTestDeviceOptions().getGceCmdTimeout(), 655 gceArgs.toArray(new String[gceArgs.size()])); 656 CLog.i("GCE driver stderr: %s", cmd.getStderr()); 657 String instanceName = extractInstanceName(cmd.getStderr()); 658 if (instanceName != null) { 659 mBuildInfo.addBuildAttribute(GCE_INSTANCE_NAME_KEY, instanceName); 660 } else { 661 CLog.w("Could not extract an instance name for the gce device."); 662 } 663 if (CommandStatus.TIMED_OUT.equals(cmd.getStatus())) { 664 String errors = 665 String.format( 666 "acloud errors: timeout after %dms, acloud did not return", 667 driverTimeoutMs); 668 if (instanceName != null) { 669 // If we managed to parse the instance name, report the boot failure so it 670 // can be shutdown. 671 mGceAvdInfo = 672 new GceAvdInfo(instanceName, null, null, errors, GceStatus.BOOT_FAIL); 673 mGceAvdInfo.setIpPreconfigured(ipDevice != null); 674 mGceAvdInfo.setDeviceOffset(offset); 675 mGceAvdInfo.setInstanceUser(user); 676 return mGceAvdInfo; 677 } 678 throw new TargetSetupError( 679 errors, mDeviceDescriptor, InfraErrorIdentifier.ACLOUD_TIMED_OUT); 680 } else if (!CommandStatus.SUCCESS.equals(cmd.getStatus())) { 681 CLog.w("Error when booting the Gce instance, reading output of gce driver"); 682 mGceAvdInfo = 683 GceAvdInfo.parseGceInfoFromFile( 684 reportFile, mDeviceDescriptor, mDeviceOptions.getRemoteAdbPort()); 685 String errors = ""; 686 if (mGceAvdInfo != null) { 687 // We always return the GceAvdInfo describing the instance when possible 688 // The caller can decide actions to be taken. 689 mGceAvdInfo.setIpPreconfigured(ipDevice != null); 690 mGceAvdInfo.setDeviceOffset(offset); 691 mGceAvdInfo.setInstanceUser(user); 692 return mGceAvdInfo; 693 } else { 694 errors = 695 "Could not get a valid instance name, check the gce driver's output." 696 + "The instance may not have booted up at all."; 697 InfraErrorIdentifier errorId = InfraErrorIdentifier.NO_ACLOUD_REPORT; 698 CLog.e(errors); 699 if (cmd.getStderr() != null 700 && cmd.getStderr().contains("Invalid JWT Signature")) { 701 errorId = InfraErrorIdentifier.ACLOUD_INVALID_SERVICE_ACCOUNT_KEY; 702 } 703 throw new TargetSetupError( 704 String.format( 705 "acloud errors: %s\nGCE driver stderr: %s", 706 errors, cmd.getStderr()), 707 mDeviceDescriptor, 708 errorId); 709 } 710 } 711 mGceAvdInfo = 712 GceAvdInfo.parseGceInfoFromFile( 713 reportFile, mDeviceDescriptor, mDeviceOptions.getRemoteAdbPort()); 714 mGceAvdInfo.setIpPreconfigured(ipDevice != null); 715 mGceAvdInfo.setDeviceOffset(offset); 716 mGceAvdInfo.setInstanceUser(user); 717 return mGceAvdInfo; 718 } catch (IOException e) { 719 throw new TargetSetupError( 720 "failed to create log file", 721 e, 722 mDeviceDescriptor, 723 InfraErrorIdentifier.FAIL_TO_CREATE_FILE); 724 } finally { 725 logCloudDeviceMetadata(); 726 FileUtil.deleteFile(reportFile); 727 } 728 } 729 730 /** 731 * Retrieve the instance name from the gce boot logs. Search for the 'name': 'gce-<name>' 732 * pattern to extract the name of it. We extract from the logs instead of result file because on 733 * gce boot failure, the attempted instance name won't show in json. 734 */ extractInstanceName(String bootupLogs)735 protected String extractInstanceName(String bootupLogs) { 736 if (bootupLogs != null) { 737 final String pattern = "'name': u?'(((gce-)|(ins-))(.*?))'"; 738 Pattern namePattern = Pattern.compile(pattern); 739 Matcher matcher = namePattern.matcher(bootupLogs); 740 if (matcher.find()) { 741 return matcher.group(1); 742 } 743 } 744 return null; 745 } 746 747 /** 748 * Shutdown the Gce instance associated with the {@link #startGce()}. 749 * 750 * @return returns true if gce shutdown was requested as non-blocking. 751 */ shutdownGce()752 public boolean shutdownGce() { 753 if (getTestDeviceOptions().useOxygen() || getTestDeviceOptions().useCvdCF()) { 754 return shutdownGceWithOxygen(); 755 } else { 756 return shutdownGceWithAcloud(); 757 } 758 } 759 760 /** 761 * Shutdown the Oxygen Gce instance. 762 * 763 * @return returns true if gce shutdown was requested as non-blocking. 764 */ shutdownGceWithOxygen()765 private boolean shutdownGceWithOxygen() { 766 try { 767 // If gceAvdInfo is missing info, then it means the device wasn't get leased 768 // successfully. 769 // In such case, there is no need to release the device. 770 if (mGceAvdInfo == null 771 || mGceAvdInfo.instanceName() == null 772 || mGceAvdInfo.hostAndPort() == null 773 || mGceAvdInfo.hostAndPort().getHost() == null) { 774 return true; 775 } 776 OxygenClient oxygenClient = 777 OxygenUtil.createOxygenClient(getTestDeviceOptions().getAvdDriverBinary()); 778 CommandResult res = 779 oxygenClient.release( 780 mGceAvdInfo.instanceName(), 781 mGceAvdInfo.hostAndPort().getHost(), 782 OxygenUtil.getTargetRegion(getTestDeviceOptions()), 783 getTestDeviceOptions().getOxygenAccountingUser(), 784 getTestDeviceOptions().getExtraOxygenArgs(), 785 getTestDeviceOptions().getGceCmdTimeout(), 786 getTestDeviceOptions().useOxygenationDevice()); 787 if (!res.getStatus().equals(CommandStatus.SUCCESS)) { 788 InvocationMetricLogger.addInvocationMetrics( 789 InvocationMetricKey.OXYGEN_DEVICE_RELEASE_FAILURE_COUNT, 1); 790 if (res.getStderr() != null) { 791 String error = "Unknown"; 792 if (res.getStderr().contains("context deadline exceeded")) { 793 error = "SERVER_CALL_TIMEOUT"; 794 } 795 InvocationMetricLogger.addInvocationMetrics( 796 InvocationMetricKey.OXYGEN_DEVICE_RELEASE_FAILURE_MESSAGE, error); 797 } 798 } 799 return res.getStatus().equals(CommandStatus.SUCCESS); 800 } finally { 801 InvocationMetricLogger.addInvocationMetrics( 802 InvocationMetricKey.OXYGEN_DEVICE_DIRECT_RELEASE_COUNT, 1); 803 mGceAvdInfo = null; 804 } 805 } 806 807 /** 808 * Shutdown the Acloud Gce instance. 809 * 810 * @return returns true if gce shutdown was requested as non-blocking. 811 */ shutdownGceWithAcloud()812 private boolean shutdownGceWithAcloud() { 813 if (!getTestDeviceOptions().getAvdDriverBinary().canExecute()) { 814 mGceAvdInfo = null; 815 throw new HarnessRuntimeException( 816 String.format( 817 "GCE launcher %s is invalid", 818 getTestDeviceOptions().getAvdDriverBinary()), 819 InfraErrorIdentifier.CONFIGURED_ARTIFACT_NOT_FOUND); 820 } 821 String instanceName = null; 822 boolean notFromGceAvd = false; 823 if (mGceAvdInfo != null) { 824 instanceName = mGceAvdInfo.instanceName(); 825 } 826 if (instanceName == null) { 827 instanceName = mBuildInfo.getBuildAttributes().get(GCE_INSTANCE_NAME_KEY); 828 notFromGceAvd = true; 829 } 830 if (instanceName == null) { 831 CLog.d("No instance to shutdown."); 832 return false; 833 } 834 // hostname is needed for Oxygen cuttlefish to shutdown. 835 String hostname = null; 836 if (mGceAvdInfo != null && mGceAvdInfo.hostAndPort() != null) { 837 hostname = mGceAvdInfo.hostAndPort().getHost(); 838 } 839 boolean ipPreconfigured = false; 840 if (mGceAvdInfo != null) { 841 ipPreconfigured = mGceAvdInfo.isIpPreconfigured(); 842 } 843 try { 844 boolean res = 845 AcloudShutdown( 846 getTestDeviceOptions(), 847 getRunUtil(), 848 instanceName, 849 hostname, 850 ipPreconfigured); 851 // Be more lenient if instance name was not reported officially and we still attempt 852 // to clean it. 853 if (res || notFromGceAvd) { 854 mBuildInfo.addBuildAttribute(GCE_INSTANCE_CLEANED_KEY, "true"); 855 } 856 if (!res && !notFromGceAvd) { 857 InvocationMetricLogger.addInvocationMetrics( 858 InvocationMetricKey.ACLOUD_DEVICE_RELEASE_FAILURE_COUNT, 1); 859 } 860 return res; 861 } finally { 862 mGceAvdInfo = null; 863 } 864 } 865 buildShutdownCommand( File config, TestDeviceOptions options, String instanceName, String hostname, boolean isIpPreconfigured)866 protected static List<String> buildShutdownCommand( 867 File config, 868 TestDeviceOptions options, 869 String instanceName, 870 String hostname, 871 boolean isIpPreconfigured) { 872 List<String> gceArgs = Lists.newArrayList(options.getAvdDriverBinary().getAbsolutePath()); 873 gceArgs.add("delete"); 874 if (options.getServiceAccountJsonKeyFile() != null) { 875 gceArgs.add("--service-account-json-private-key-path"); 876 gceArgs.add(options.getServiceAccountJsonKeyFile().getAbsolutePath()); 877 } 878 if (isIpPreconfigured) { 879 gceArgs.add("--host"); 880 gceArgs.add(hostname); 881 gceArgs.add("--host-user"); 882 gceArgs.add(options.getInstanceUser()); 883 gceArgs.add("--host-ssh-private-key-path"); 884 gceArgs.add(options.getSshPrivateKeyPath().getAbsolutePath()); 885 } else if (config != null) { 886 gceArgs.add("--config_file"); 887 gceArgs.add(config.getAbsolutePath()); 888 } 889 gceArgs.add("--instance_names"); 890 gceArgs.add(instanceName); 891 return gceArgs; 892 } 893 894 /** 895 * Actual Acloud run to shutdown the virtual device. 896 * 897 * @param options The {@link TestDeviceOptions} for the Acloud options 898 * @param runUtil The {@link IRunUtil} to run Acloud 899 * @param instanceName The instance to shutdown. 900 * @param hostname hostname of the instance, only used for Oxygen cuttlefish. 901 * @param isIpPreconfigured whether the AVD was created on a remote device with preconfigured IP 902 * @return True if successful 903 */ AcloudShutdown( TestDeviceOptions options, IRunUtil runUtil, String instanceName, String hostname, boolean isIpPreconfigured)904 public static boolean AcloudShutdown( 905 TestDeviceOptions options, 906 IRunUtil runUtil, 907 String instanceName, 908 String hostname, 909 boolean isIpPreconfigured) { 910 // Add extra args. 911 File config = null; 912 try { 913 File originalConfig = options.getAvdConfigFile(); 914 if (originalConfig != null) { 915 config = FileUtil.createTempFile(originalConfig.getName(), "config"); 916 // Copy the config in case it comes from a dynamic file. In order to ensure Acloud 917 // has the file until it's done with it. 918 FileUtil.copyFile(originalConfig, config); 919 } 920 List<String> gceArgs = 921 buildShutdownCommand( 922 config, options, instanceName, hostname, isIpPreconfigured); 923 if (gceArgs == null) { 924 CLog.w("Shutdown command as <null>, see earlier logs for reasons."); 925 return false; 926 } 927 CLog.i("Tear down of GCE with %s", gceArgs.toString()); 928 if (options.waitForGceTearDown()) { 929 CommandResult cmd = 930 runUtil.runTimedCmd( 931 options.getGceCmdTimeout(), 932 gceArgs.toArray(new String[gceArgs.size()])); 933 FileUtil.deleteFile(config); 934 CLog.i( 935 "GCE driver teardown output:\nstdout:%s\nstderr:%s", 936 cmd.getStdout(), cmd.getStderr()); 937 if (!CommandStatus.SUCCESS.equals(cmd.getStatus())) { 938 CLog.w( 939 "Failed to tear down GCE %s with the following arg: %s.", 940 instanceName, gceArgs); 941 return false; 942 } 943 } else { 944 // Discard the output so the process is not linked to the parent and doesn't die 945 // if the JVM exit. 946 Process p = runUtil.runCmdInBackground(Redirect.DISCARD, gceArgs); 947 if (config != null) { 948 new AcloudDeleteCleaner(p, config).start(); 949 } 950 } 951 } catch (IOException ioe) { 952 CLog.e("failed to create log file for GCE Teardown"); 953 CLog.e(ioe); 954 FileUtil.deleteFile(config); 955 return false; 956 } 957 return true; 958 } 959 960 /** 961 * Get a bugreportz from the device using ssh to avoid any adb connection potential issue. 962 * 963 * @param gceAvd The {@link GceAvdInfo} that describe the device. 964 * @param options a {@link TestDeviceOptions} describing the device options to be used for the 965 * GCE device. 966 * @param runUtil a {@link IRunUtil} to execute commands. 967 * @return A file pointing to the zip bugreport, or null if an issue occurred. 968 * @throws IOException 969 */ getBugreportzWithSsh( GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil)970 public static File getBugreportzWithSsh( 971 GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil) throws IOException { 972 String output = remoteSshCommandExec(gceAvd, options, runUtil, "bugreportz"); 973 Matcher match = BUGREPORTZ_RESPONSE_PATTERN.matcher(output); 974 if (!match.find()) { 975 CLog.e("Something went wrong during bugreportz collection: '%s'", output); 976 return null; 977 } 978 String remoteFilePath = match.group(2); 979 File localTmpFile = FileUtil.createTempFile("bugreport-ssh", ".zip"); 980 if (!RemoteFileUtil.fetchRemoteFile( 981 gceAvd, options, runUtil, REMOTE_FILE_OP_TIMEOUT, remoteFilePath, localTmpFile)) { 982 FileUtil.deleteFile(localTmpFile); 983 return null; 984 } 985 return localTmpFile; 986 } 987 988 /** 989 * Get a bugreport via ssh for a nested instance. This requires requesting the adb in the nested 990 * virtual instance. 991 * 992 * @param gceAvd The {@link GceAvdInfo} that describe the device. 993 * @param options a {@link TestDeviceOptions} describing the device options to be used for the 994 * GCE device. 995 * @param runUtil a {@link IRunUtil} to execute commands. 996 * @return A file pointing to the zip bugreport, or null if an issue occurred. 997 * @throws IOException 998 */ getNestedDeviceSshBugreportz( GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil)999 public static File getNestedDeviceSshBugreportz( 1000 GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil) throws IOException { 1001 if (gceAvd == null || gceAvd.hostAndPort() == null) { 1002 return null; 1003 } 1004 String adbTool = "./bin/adb"; 1005 String output; 1006 if (options.useOxygen() && !options.useOxygenationDevice()) { 1007 adbTool = "./tools/dynamic_adb_tool"; 1008 // Make sure the Oxygen device is connected. 1009 output = 1010 remoteSshCommandExec( 1011 gceAvd, options, runUtil, adbTool, "connect", "localhost:6520"); 1012 if (output.contains("failed to connect to")) { 1013 CLog.e("Bugreport collection skipped due to device can't be connected: %s", output); 1014 return null; 1015 } 1016 } 1017 1018 // TODO(b/280177749): Remove the special logic after Oxygen side is cleaned up. 1019 if (options.useOxygen() && options.useOxygenationDevice()) { 1020 output = 1021 remoteSshCommandExec( 1022 gceAvd, 1023 options, 1024 runUtil, 1025 adbTool, 1026 "-s", 1027 "localhost:6520", 1028 "wait-for-device", 1029 "shell", 1030 "bugreportz"); 1031 } else { 1032 output = 1033 remoteSshCommandExec( 1034 gceAvd, 1035 options, 1036 runUtil, 1037 adbTool, 1038 "wait-for-device", 1039 "shell", 1040 "bugreportz"); 1041 } 1042 Matcher match = BUGREPORTZ_RESPONSE_PATTERN.matcher(output); 1043 if (!match.find()) { 1044 CLog.e("Something went wrong during bugreportz collection: '%s'", output); 1045 return null; 1046 } 1047 String deviceFilePath = match.group(2); 1048 String pullOutput; 1049 if (options.useOxygen() && options.useOxygenationDevice()) { 1050 pullOutput = 1051 remoteSshCommandExec( 1052 gceAvd, 1053 options, 1054 runUtil, 1055 adbTool, 1056 "-s", 1057 "localhost:6520", 1058 "pull", 1059 deviceFilePath); 1060 } else { 1061 pullOutput = 1062 remoteSshCommandExec(gceAvd, options, runUtil, adbTool, "pull", deviceFilePath); 1063 } 1064 CLog.d(pullOutput); 1065 String remoteFilePath = "./" + new File(deviceFilePath).getName(); 1066 File localTmpFile = FileUtil.createTempFile("bugreport-ssh", ".zip"); 1067 if (!RemoteFileUtil.fetchRemoteFile( 1068 gceAvd, options, runUtil, REMOTE_FILE_OP_TIMEOUT, remoteFilePath, localTmpFile)) { 1069 FileUtil.deleteFile(localTmpFile); 1070 return null; 1071 } 1072 return localTmpFile; 1073 } 1074 1075 /** 1076 * Fetch a remote file from a nested instance and log it. 1077 * 1078 * @param logger The {@link ITestLogger} where to log the file. 1079 * @param gceAvd The {@link GceAvdInfo} that describe the device. 1080 * @param options a {@link TestDeviceOptions} describing the device options to be used for the 1081 * GCE device. 1082 * @param runUtil a {@link IRunUtil} to execute commands. 1083 * @param remoteFilePath The remote path where to find the file. 1084 * @param type the {@link LogDataType} of the logged file. 1085 * @return whether the file is logged successfully. 1086 */ logNestedRemoteFile( ITestLogger logger, GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil, String remoteFilePath, LogDataType type)1087 public static boolean logNestedRemoteFile( 1088 ITestLogger logger, 1089 GceAvdInfo gceAvd, 1090 TestDeviceOptions options, 1091 IRunUtil runUtil, 1092 String remoteFilePath, 1093 LogDataType type) { 1094 return logNestedRemoteFile(logger, gceAvd, options, runUtil, remoteFilePath, type, null); 1095 } 1096 1097 /** 1098 * Fetch a remote file from a nested instance and log it. 1099 * 1100 * @param logger The {@link ITestLogger} where to log the file. 1101 * @param gceAvd The {@link GceAvdInfo} that describe the device. 1102 * @param options a {@link TestDeviceOptions} describing the device options to be used for the 1103 * GCE device. 1104 * @param runUtil a {@link IRunUtil} to execute commands. 1105 * @param remoteFilePath The remote path where to find the file. 1106 * @param type the {@link LogDataType} of the logged file. 1107 * @param baseName The base name to use to log the file. If null the actual file name will be 1108 * used. 1109 * @return whether the file is logged successfully. 1110 */ logNestedRemoteFile( ITestLogger logger, GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil, String remoteFilePath, LogDataType type, String baseName)1111 public static boolean logNestedRemoteFile( 1112 ITestLogger logger, 1113 GceAvdInfo gceAvd, 1114 TestDeviceOptions options, 1115 IRunUtil runUtil, 1116 String remoteFilePath, 1117 LogDataType type, 1118 String baseName) { 1119 File remoteFile; 1120 if (type == LogDataType.DIR) { 1121 remoteFile = 1122 RemoteFileUtil.fetchRemoteDir( 1123 gceAvd, options, runUtil, REMOTE_FILE_OP_TIMEOUT, remoteFilePath); 1124 1125 if (remoteFile != null && remoteFile.listFiles().length == 0) { 1126 // If the retrieved directory is empty, delete it as there is no file to log anyway 1127 FileUtil.recursiveDelete(remoteFile); 1128 return false; 1129 } 1130 // Search log files for known failures for devices hosted by Oxygen and ARM server 1131 if ((options.useOxygen() 1132 || InstanceType.GCE.equals(options.getInstanceType()) 1133 || InstanceType.CUTTLEFISH.equals(options.getInstanceType())) 1134 && remoteFile != null) { 1135 collectErrorSignatures(remoteFile); 1136 } 1137 if (options.useOxygen() && remoteFile != null) { 1138 try (CloseableTraceScope ignore = 1139 new CloseableTraceScope("avd:collectDeviceLaunchMetrics")) { 1140 long[] launchMetrics = LogCollector.collectDeviceLaunchMetrics(remoteFile); 1141 if (launchMetrics[0] > 0) { 1142 InvocationMetricLogger.addInvocationMetrics( 1143 InvocationMetricKey.CF_FETCH_ARTIFACT_TIME, launchMetrics[0]); 1144 InvocationMetricLogger.addInvocationMetrics( 1145 InvocationMetricKey.CF_LAUNCH_CVD_TIME, launchMetrics[1]); 1146 } 1147 } 1148 try (CloseableTraceScope ignore = 1149 new CloseableTraceScope("avd:collectOxygenVersion")) { 1150 String oxygenVersion = LogCollector.collectOxygenVersion(remoteFile); 1151 if (!Strings.isNullOrEmpty(oxygenVersion)) { 1152 InvocationMetricLogger.addInvocationMetrics( 1153 InvocationMetricKey.CF_OXYGEN_VERSION, oxygenVersion); 1154 } 1155 } 1156 } 1157 1158 // Default files under a directory to be CUTTLEFISH_LOG to avoid compression. 1159 type = LogDataType.CUTTLEFISH_LOG; 1160 if (remoteFile != null) { 1161 // If we happened to fetch a directory, log all the subfiles 1162 logDirectory(remoteFile, baseName, logger, type); 1163 return true; 1164 } 1165 } else { 1166 remoteFile = 1167 RemoteFileUtil.fetchRemoteFile( 1168 gceAvd, options, runUtil, REMOTE_FILE_OP_TIMEOUT, remoteFilePath); 1169 if (remoteFile != null) { 1170 if (InstanceType.GCE.equals(options.getInstanceType()) 1171 || InstanceType.CUTTLEFISH.equals(options.getInstanceType())) { 1172 collectErrorSignatures(remoteFile); 1173 } 1174 logFile(remoteFile, baseName, logger, type); 1175 return true; 1176 } 1177 } 1178 return false; 1179 } 1180 collectErrorSignatures(File remoteFile)1181 private static void collectErrorSignatures(File remoteFile) { 1182 try (CloseableTraceScope ignore = new CloseableTraceScope("avd:collectErrorSignature")) { 1183 List<String> signatures = LogCollector.collectErrorSignatures(remoteFile); 1184 if (signatures.size() > 0) { 1185 InvocationMetricLogger.addInvocationMetrics( 1186 InvocationMetricKey.DEVICE_ERROR_SIGNATURES, String.join(",", signatures)); 1187 } 1188 } 1189 } 1190 logDirectory( File remoteDirectory, String baseName, ITestLogger logger, LogDataType type)1191 public static void logDirectory( 1192 File remoteDirectory, String baseName, ITestLogger logger, LogDataType type) { 1193 for (File f : remoteDirectory.listFiles()) { 1194 if (f.isFile()) { 1195 LogDataType typeFromName = OxygenUtil.getDefaultLogType(f.getName()); 1196 if (typeFromName.equals(LogDataType.UNKNOWN)) { 1197 // Use default LogDataType 1198 typeFromName = type; 1199 } 1200 logFile(f, baseName, logger, typeFromName); 1201 } else if (f.isDirectory()) { 1202 logDirectory(f, baseName, logger, type); 1203 } 1204 } 1205 } 1206 logFile( File remoteFile, String baseName, ITestLogger logger, LogDataType type)1207 private static void logFile( 1208 File remoteFile, String baseName, ITestLogger logger, LogDataType type) { 1209 try (InputStreamSource remoteFileStream = new FileInputStreamSource(remoteFile, true)) { 1210 String name = baseName; 1211 if (name == null) { 1212 name = remoteFile.getName(); 1213 } 1214 logger.testLog(name, type, remoteFileStream); 1215 InvocationMetricLogger.addInvocationMetrics( 1216 InvocationMetricKey.CF_LOG_SIZE, remoteFileStream.size()); 1217 } 1218 } 1219 1220 /** 1221 * Execute the remote command via ssh on an instance. 1222 * 1223 * @param gceAvd The {@link GceAvdInfo} that describe the device. 1224 * @param options a {@link TestDeviceOptions} describing the device options to be used for the 1225 * GCE device. 1226 * @param runUtil a {@link IRunUtil} to execute commands. 1227 * @param timeoutMs The timeout in millisecond for the command. 0 means no timeout. 1228 * @param command The remote command to execute. 1229 * @return {@link CommandResult} containing the result of the execution. 1230 */ remoteSshCommandExecution( GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil, long timeoutMs, String... command)1231 public static CommandResult remoteSshCommandExecution( 1232 GceAvdInfo gceAvd, 1233 TestDeviceOptions options, 1234 IRunUtil runUtil, 1235 long timeoutMs, 1236 String... command) { 1237 return RemoteSshUtil.remoteSshCommandExec(gceAvd, options, runUtil, timeoutMs, command); 1238 } 1239 remoteSshCommandExec( GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil, String... command)1240 private static String remoteSshCommandExec( 1241 GceAvdInfo gceAvd, TestDeviceOptions options, IRunUtil runUtil, String... command) { 1242 CommandResult res = 1243 remoteSshCommandExecution(gceAvd, options, runUtil, BUGREPORT_TIMEOUT, command); 1244 // We attempt to get a clean output from our command 1245 String output = res.getStdout().trim(); 1246 if (!CommandStatus.SUCCESS.equals(res.getStatus())) { 1247 CLog.e("issue when attempting to execute '%s':", Arrays.asList(command)); 1248 CLog.e("Stderr: %s", res.getStderr()); 1249 } else if (output.isEmpty()) { 1250 CLog.e("Stdout from '%s' was empty", Arrays.asList(command)); 1251 CLog.e("Stderr: %s", res.getStderr()); 1252 } 1253 return output; 1254 } 1255 1256 /** 1257 * Reads the current content of the Gce Avd instance serial log. 1258 * 1259 * @param infos The {@link GceAvdInfo} describing the instance. 1260 * @param avdConfigFile the avd config file 1261 * @param jsonKeyFile the service account json key file. 1262 * @param runUtil a {@link IRunUtil} to execute commands. 1263 * @return The serial log output or null if something goes wrong. 1264 */ getInstanceSerialLog( GceAvdInfo infos, File avdConfigFile, File jsonKeyFile, IRunUtil runUtil)1265 public static String getInstanceSerialLog( 1266 GceAvdInfo infos, File avdConfigFile, File jsonKeyFile, IRunUtil runUtil) { 1267 AcloudConfigParser config = AcloudConfigParser.parseConfig(avdConfigFile); 1268 if (config == null) { 1269 CLog.e("Failed to parse our acloud config."); 1270 return null; 1271 } 1272 if (infos == null) { 1273 return null; 1274 } 1275 try { 1276 Credentials credential = createCredential(config, jsonKeyFile); 1277 String project = config.getValueForKey(AcloudKeys.PROJECT); 1278 String zone = config.getValueForKey(AcloudKeys.ZONE); 1279 String instanceName = infos.instanceName(); 1280 HttpRequestInitializer requestInitializer = new HttpCredentialsAdapter(credential); 1281 Compute compute = 1282 new Compute.Builder( 1283 GoogleNetHttpTransport.newTrustedTransport(), 1284 JSON_FACTORY, 1285 null) 1286 .setApplicationName(project) 1287 .setHttpRequestInitializer(requestInitializer) 1288 .build(); 1289 GetSerialPortOutput outputPort = 1290 compute.instances().getSerialPortOutput(project, zone, instanceName); 1291 SerialPortOutput output = outputPort.execute(); 1292 return output.getContents(); 1293 } catch (GeneralSecurityException | IOException e) { 1294 CLog.e(e); 1295 return null; 1296 } 1297 } 1298 createCredential(AcloudConfigParser config, File jsonKeyFile)1299 private static Credentials createCredential(AcloudConfigParser config, File jsonKeyFile) 1300 throws GeneralSecurityException, IOException { 1301 if (jsonKeyFile != null) { 1302 return GoogleApiClientUtil.createCredentialFromJsonKeyFile(jsonKeyFile, SCOPES); 1303 } else { 1304 jsonKeyFile = 1305 new File(config.getValueForKey(AcloudKeys.SERVICE_ACCOUNT_JSON_PRIVATE_KEY)); 1306 return GoogleApiClientUtil.createCredentialFromJsonKeyFile(jsonKeyFile, SCOPES); 1307 } 1308 } 1309 cleanUp()1310 public void cleanUp() { 1311 // Clean up logs file if any was created. 1312 } 1313 1314 /** Returns the instance of the {@link IRunUtil}. */ 1315 @VisibleForTesting getRunUtil()1316 IRunUtil getRunUtil() { 1317 return RunUtil.getDefault(); 1318 } 1319 1320 /** Returns the instance of the {@link com.android.tradefed.util.avd.HostOrchestratorUtil}. */ getHostOrchestratorUtil()1321 public HostOrchestratorUtil getHostOrchestratorUtil() { 1322 return mHOUtil; 1323 } 1324 1325 /** 1326 * Log the serial output of a device described by {@link GceAvdInfo}. 1327 * 1328 * @param infos The {@link GceAvdInfo} describing the instance. 1329 * @param logger The {@link ITestLogger} where to log the serial log. 1330 */ logSerialOutput(GceAvdInfo infos, ITestLogger logger)1331 public void logSerialOutput(GceAvdInfo infos, ITestLogger logger) { 1332 if (mSkipSerialLogCollection) { 1333 CLog.d("Serial log collection is skipped"); 1334 return; 1335 } 1336 String output = 1337 GceManager.getInstanceSerialLog( 1338 infos, 1339 getAvdConfigFile(), 1340 getTestDeviceOptions().getServiceAccountJsonKeyFile(), 1341 getRunUtil()); 1342 if (output == null) { 1343 CLog.w("Failed to collect the instance serial logs."); 1344 return; 1345 } 1346 try (ByteArrayInputStreamSource source = 1347 new ByteArrayInputStreamSource(output.getBytes())) { 1348 logger.testLog("gce_full_serial_log", LogDataType.TEXT, source); 1349 } 1350 } 1351 1352 /** Log the information related to the acloud config. */ logCloudDeviceMetadata()1353 private void logCloudDeviceMetadata() { 1354 AcloudConfigParser config = AcloudConfigParser.parseConfig(getAvdConfigFile()); 1355 if (config == null) { 1356 CLog.e("Failed to parse our acloud config."); 1357 return; 1358 } 1359 if (config.getValueForKey(AcloudKeys.STABLE_HOST_IMAGE_NAME) != null) { 1360 InvocationMetricLogger.addInvocationMetrics( 1361 InvocationMetricKey.CLOUD_DEVICE_STABLE_HOST_IMAGE, 1362 config.getValueForKey(AcloudKeys.STABLE_HOST_IMAGE_NAME)); 1363 } 1364 if (config.getValueForKey(AcloudKeys.STABLE_HOST_IMAGE_PROJECT) != null) { 1365 InvocationMetricLogger.addInvocationMetrics( 1366 InvocationMetricKey.CLOUD_DEVICE_STABLE_HOST_IMAGE_PROJECT, 1367 config.getValueForKey(AcloudKeys.STABLE_HOST_IMAGE_PROJECT)); 1368 } 1369 if (config.getValueForKey(AcloudKeys.PROJECT) != null) { 1370 InvocationMetricLogger.addInvocationMetrics( 1371 InvocationMetricKey.CLOUD_DEVICE_PROJECT, 1372 config.getValueForKey(AcloudKeys.PROJECT)); 1373 } 1374 if (config.getValueForKey(AcloudKeys.ZONE) != null) { 1375 InvocationMetricLogger.addInvocationMetrics( 1376 InvocationMetricKey.CLOUD_DEVICE_ZONE, config.getValueForKey(AcloudKeys.ZONE)); 1377 } 1378 if (config.getValueForKey(AcloudKeys.MACHINE_TYPE) != null) { 1379 InvocationMetricLogger.addInvocationMetrics( 1380 InvocationMetricKey.CLOUD_DEVICE_MACHINE_TYPE, 1381 config.getValueForKey(AcloudKeys.MACHINE_TYPE)); 1382 } 1383 } 1384 1385 /** 1386 * Returns the {@link TestDeviceOptions} associated with the device that the gce manager was 1387 * initialized with. 1388 */ getTestDeviceOptions()1389 private TestDeviceOptions getTestDeviceOptions() { 1390 return mDeviceOptions; 1391 } 1392 1393 @VisibleForTesting getAvdConfigFile()1394 File getAvdConfigFile() { 1395 return getTestDeviceOptions().getAvdConfigFile(); 1396 } 1397 1398 /** 1399 * Thread that helps cleaning the copied config when the process is done. This ensures acloud is 1400 * not missing its config until its done. 1401 */ 1402 private static class AcloudDeleteCleaner extends Thread { 1403 private Process mProcess; 1404 private File mConfigFile; 1405 AcloudDeleteCleaner(Process p, File config)1406 public AcloudDeleteCleaner(Process p, File config) { 1407 setDaemon(true); 1408 setName("acloud-delete-cleaner"); 1409 mProcess = p; 1410 mConfigFile = config; 1411 } 1412 1413 @Override run()1414 public void run() { 1415 try { 1416 mProcess.waitFor(); 1417 } catch (InterruptedException e) { 1418 CLog.e(e); 1419 } 1420 FileUtil.deleteFile(mConfigFile); 1421 } 1422 } 1423 } 1424