The TastVMTest stage is frequently failing on betty-release (http://cros-goldeneye/chromeos/legoland/builderHistory?buildConfig=betty-release&buildBranch=master). I think that the 10-minute timeout for the stage needs to be increased; tests are slower when they run in VMs and we keep adding more tests.

In http://cros-goldeneye/chromeos/healthmonitoring/buildDetails?buildbucketId=8936955391280436144, the first run at http://pantheon/storage/browser/chromeos-image-archive/betty-release/R70-11012.0.0/tast_vm_test_results_1/tast_vm_canary/ died during power.Reboot. Looking at stdout from the stage, I can see that there was actually a timeout:

...
2018/08/28 09:33:46 Started test power.Reboot
2018/08/28 09:33:46 [09:33:46.905] Rebooting DUT
2018/08/28 09:33:46 [09:33:46.920] Waiting for DUT to become unreachable
2018/08/28 09:33:50 [09:33:50.929] DUT became unreachable (as expected)
2018/08/28 09:33:50 [09:33:50.929] Reconnecting to DUT
cros_sdk: Signaled to shutdown: caught 15 signal.
09:34:18: INFO: Uploading artifacts to Cloud Storage...
09:34:18: INFO: RunCommand: /b/swarming/w/ir/cache/cbuild/repository/.cache/common/gsutil_4.33.tar.gz/gsutil/gsutil -o 'Boto:num_retries=10' -m cp -v -r -e -- /b/swarming/w/ir/cache/cbuild/repository/buildbot_archive/betty-release/R70-11012.0.0/tast_vm_test_results_1 gs://chromeos-image-archive/betty-release/R70-11012.0.0/tast_vm_test_results_1
09:34:20: INFO: RunCommand: /b/swarming/w/ir/cache/cbuild/repository/.cache/common/gsutil_4.33.tar.gz/gsutil/gsutil -o 'Boto:num_retries=10' -m cp -v -- /b/swarming/w/ir/cache/cbuild/repository/buildbot_archive/betty-release/R70-11012.0.0/UPLOADED gs://chromeos-image-archive/betty-release/R70-11012.0.0/UPLOADED
09:34:21: ERROR: Got error while archiving or processing results
Traceback (most recent call last):
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 225, in _ProcessAndArchiveResults
    self._ProcessResultsFile(abs_results_dir, archive_base, suite_names)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 272, in _ProcessResultsFile
    (results_path, str(e)))
TestFailure: ** Failed to read results from /b/swarming/w/ir/cache/cbuild/repository/chroot/tmp/cbuildbot410IjE/tast_vm_canary/results.json: [Errno 2] No such file or directory: u'/b/swarming/w/ir/cache/cbuild/repository/chroot/tmp/cbuildbot410IjE/tast_vm_canary/results.json' **
09:34:21: ERROR: Tast VM tests failed
Traceback (most recent call last):
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 110, in PerformStage
    self._RunAllSuites(self._run.config.tast_vm_tests, chroot_results_dir)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 160, in _RunAllSuites
    suite.suite_name))
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 190, in _RunSuite
    error_code_ok=True, kill_timeout=TastVMTestStage.CLEANUP_TIMEOUT_SEC)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/cros_build_lib.py", line 615, in RunCommand
    (cmd_result.output, cmd_result.error) = proc.communicate(input)
  File "/usr/lib/python2.7/subprocess.py", line 796, in communicate
    self.wait()
  File "/usr/lib/python2.7/subprocess.py", line 1376, in wait
    pid, sts = _eintr_retry_call(os.waitpid, self.pid, 0)
  File "/usr/lib/python2.7/subprocess.py", line 476, in _eintr_retry_call
    return func(*args)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/timeout_util.py", line 88, in kill_us
    raise TimeoutError(error_message % {'time': max_run_time})
TimeoutError: Timeout occurred- waited 600.0 seconds. Reached TastVMTestStage test run timeout.
09:34:21: WARNING: Traceback (most recent call last):
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/generic_stages.py", line 700, in Run
    self.PerformStage()
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 110, in PerformStage
    self._RunAllSuites(self._run.config.tast_vm_tests, chroot_results_dir)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 160, in _RunAllSuites
    suite.suite_name))
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 190, in _RunSuite
    error_code_ok=True, kill_timeout=TastVMTestStage.CLEANUP_TIMEOUT_SEC)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/cros_build_lib.py", line 615, in RunCommand
    (cmd_result.output, cmd_result.error) = proc.communicate(input)
  File "/usr/lib/python2.7/subprocess.py", line 796, in communicate
    self.wait()
  File "/usr/lib/python2.7/subprocess.py", line 1376, in wait
    pid, sts = _eintr_retry_call(os.waitpid, self.pid, 0)
  File "/usr/lib/python2.7/subprocess.py", line 476, in _eintr_retry_call
    return func(*args)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/timeout_util.py", line 88, in kill_us
    raise TimeoutError(error_message % {'time': max_run_time})
TimeoutError: Timeout occurred- waited 600.0 seconds. Reached TastVMTestStage test run timeout.


The second run at http://pantheon/storage/browser/chromeos-image-archive/betty-release/R70-11012.0.0/tast_vm_test_results_2/tast_vm_canary/ looks like it also failed with a TimeoutError:

...
2018/08/28 09:44:28 Results saved to /tmp/cbuildbot0bVPv8/tast_vm_canary
09:44:38: INFO: Uploading artifacts to Cloud Storage...
09:44:38: INFO: RunCommand: /b/swarming/w/ir/cache/cbuild/repository/.cache/common/gsutil_4.33.tar.gz/gsutil/gsutil -o 'Boto:num_retries=10' -m cp -v -r -e -- /b/swarming/w/ir/cache/cbuild/repository/buildbot_archive/betty-release/R70-11012.0.0/tast_vm_test_results_2 gs://chromeos-image-archive/betty-release/R70-11012.0.0/tast_vm_test_results_2
09:44:40: INFO: RunCommand: /b/swarming/w/ir/cache/cbuild/repository/.cache/common/gsutil_4.33.tar.gz/gsutil/gsutil -o 'Boto:num_retries=10' -m cp -v -- /b/swarming/w/ir/cache/cbuild/repository/buildbot_archive/betty-release/R70-11012.0.0/UPLOADED gs://chromeos-image-archive/betty-release/R70-11012.0.0/UPLOADED
09:44:41: ERROR: Tast VM tests failed
Traceback (most recent call last):
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 110, in PerformStage
    self._RunAllSuites(self._run.config.tast_vm_tests, chroot_results_dir)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 160, in _RunAllSuites
    suite.suite_name))
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 190, in _RunSuite
    error_code_ok=True, kill_timeout=TastVMTestStage.CLEANUP_TIMEOUT_SEC)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/cros_build_lib.py", line 615, in RunCommand
    (cmd_result.output, cmd_result.error) = proc.communicate(input)
  File "/usr/lib/python2.7/subprocess.py", line 796, in communicate
    self.wait()
  File "/usr/lib/python2.7/subprocess.py", line 1376, in wait
    pid, sts = _eintr_retry_call(os.waitpid, self.pid, 0)
  File "/usr/lib/python2.7/subprocess.py", line 476, in _eintr_retry_call
    return func(*args)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/timeout_util.py", line 88, in kill_us
    raise TimeoutError(error_message % {'time': max_run_time})
TimeoutError: Timeout occurred- waited 600.0 seconds. Reached TastVMTestStage test run timeout.
09:44:41: ERROR: Traceback (most recent call last):
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/generic_stages.py", line 700, in Run
    self.PerformStage()
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 110, in PerformStage
    self._RunAllSuites(self._run.config.tast_vm_tests, chroot_results_dir)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 160, in _RunAllSuites
    suite.suite_name))
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/cbuildbot/stages/tast_test_stages.py", line 190, in _RunSuite
    error_code_ok=True, kill_timeout=TastVMTestStage.CLEANUP_TIMEOUT_SEC)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/cros_build_lib.py", line 615, in RunCommand
    (cmd_result.output, cmd_result.error) = proc.communicate(input)
  File "/usr/lib/python2.7/subprocess.py", line 796, in communicate
    self.wait()
  File "/usr/lib/python2.7/subprocess.py", line 1376, in wait
    pid, sts = _eintr_retry_call(os.waitpid, self.pid, 0)
  File "/usr/lib/python2.7/subprocess.py", line 476, in _eintr_retry_call
    return func(*args)
  File "/b/swarming/w/ir/cache/cbuild/repository/chromite/lib/timeout_util.py", line 88, in kill_us
    raise TimeoutError(error_message % {'time': max_run_time})
TimeoutError: Timeout occurred- waited 600.0 seconds. Reached TastVMTestStage test run timeout.

09:44:41: INFO: Translating result Timeout occurred- waited 600.0 seconds. Reached TastVMTestStage test run timeout. to fail.