New issue
Advanced search Search tips
Note: Color blocks (like █ or █) mean that a user may not be available. Tooltip shows the reason.

Issue 593110 link

Starred by 2 users
Status: WontFix
Owner:
█ rnep...@chromium.org
Last visit > 30 days ago
Closed: Mar 2016
Cc:
falken@chromium.org
█ zh...@chromium.org
█ nednguyen@chromium.org
█ eakuefner@chromium.org
█ rnep...@chromium.org
jbudorick@chromium.org
█ aiolos@chromium.org
Components:
EstimatedDays: ----
NextAction: ----
OS: Android
Pri: 2
Type: Bug-Regression



Sign in to add a comment

Every test after failed test fails with "Tracing is already started" (due to TracingControllerStoppedError caused by devil error)

Project Member Reported by simonhatch@chromium.org, Mar 8 2016 
https://build.chromium.org/p/chromium.perf/builders/Android%20Nexus6%20Perf%20%281%29/builds/1842


service_worker.service_worker is failing, but then after that every test on the device seems to fail with the same "tracing is already started" message.

Comment 1 by nedngu...@google.com, Mar 8 2016

Owner: falken@chromium.org
Status: Assigned (was: Untriaged)
Falken: the way to prevent this cascading failure is to add tracing_controller.StopTracing() in DidRunPage hook. Or better if you can migrate this to use TimelineBasedMeasurement, which already has a lot of cleanup logic there.

Comment 2 by falken@chromium.org, Mar 9 2016

Components: Blink>ServiceWorker
Status: Started (was: Assigned)

Comment 3 by falken@chromium.org, Mar 9 2016 

I'll just do the easy fix to heal the bot now.
Project Member

Comment 4 by bugdroid1@chromium.org, Mar 9 2016 

The following revision refers to this bug:
  https://chromium.googlesource.com/chromium/src.git/+/a1889274e47117c421011798cb972b9bdaab7aaa

commit a1889274e47117c421011798cb972b9bdaab7aaa
Author: falken <falken@chromium.org>
Date: Wed Mar 09 06:33:05 2016

service_worker.service_worker perf test: call StopTracing() to cleanup

BUG= 593110 
CQ_EXTRA_TRYBOTS=tryserver.chromium.perf:android_s5_perf_cq;tryserver.chromium.perf:winx64_10_perf_cq;tryserver.chromium.perf:mac_retina_perf_cq;tryserver.chromium.perf:linux_perf_cq

Review URL: https://codereview.chromium.org/1779663002

Cr-Commit-Position: refs/heads/master@{#380089}

[modify] https://crrev.com/a1889274e47117c421011798cb972b9bdaab7aaa/tools/perf/benchmarks/service_worker.py

Comment 5 by falken@chromium.org, Mar 10 2016 

Does https://build.chromium.org/p/chromium.perf/builders/Android%20Nexus6%20Perf%20%281%29/builds/1842 which ran after the commit mean the bug is still not fixed?

Comment 6 by simonhatch@chromium.org, Mar 11 2016 

This is still happening.

Comment 7 by nedngu...@google.com, Mar 11 2016 

To #6: can you show the log?

Comment 8 by simonhatch@chromium.org, Mar 11 2016 

From the latest run, you can see device 4 was seemingly ok until it runs service_worker.service_worker, digging into the log output a bit deeper you can see that run 0 fails with a different error (listed below), and then the subsequent runs 1 & 2 fail with the "Tracing is already started" as do all the tests on that device after.



Latest completed run: https://build.chromium.org/p/chromium.perf/builders/Android%20Nexus6%20Perf%20%281%29/builds/1894


Log of service_worker.service_worker: https://uberchromegw.corp.google.com/i/chromium.perf/builders/Android%20Nexus6%20Perf%20%281%29/builds/1894/steps/service_worker.service_worker/logs/stdio




(INFO) 2016-03-11 06:32:33,086 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell '( logcat -d -t 500 );echo %$?'
Traceback (most recent call last):
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/android_platform/development/scripts/stack", line 258, in <module>
    sys.exit(main(sys.argv[1:]))
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/android_platform/development/scripts/stack", line 194, in main
    constants.CheckOutputDirectory()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/android_platform/development/scripts/../../../../build/android/pylib/constants/__init__.py", line 264, in CheckOutputDirectory
    raise Exception('Neither CHROMIUM_OUTPUT_DIR nor CHROMIUM_OUT_DIR '
Exception: Neither CHROMIUM_OUTPUT_DIR nor CHROMIUM_OUT_DIR has been set
Traceback (most recent call last):
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/build/android/tombstones.py", line 273, in <module>
    sys.exit(main())
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/build/android/tombstones.py", line 255, in main
    constants.CheckOutputDirectory()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/build/android/pylib/constants/__init__.py", line 264, in CheckOutputDirectory
    raise Exception('Neither CHROMIUM_OUTPUT_DIR nor CHROMIUM_OUT_DIR '
Exception: Neither CHROMIUM_OUTPUT_DIR nor CHROMIUM_OUT_DIR has been set
(ERROR) 2016-03-11 06:32:33,228 exceptions.__init__:69  Problem when trying to gather standard output: 'NoneType' object has no attribute 'splitlines'
(INFO) 2016-03-11 06:32:33,229 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell '( /system/bin/screencap -p /data/local/tmp/temp_file-35fec663860cd.png );echo %$?'
(INFO) 2016-03-11 06:32:33,237 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-35fec663860cd.png'
(CRITICAL) 2016-03-11 06:32:33,239 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,240 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-1-for-MainThread (attempt 1 of 4)
(CRITICAL) 2016-03-11 06:32:33,240 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,241 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,241 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 1909, in TakeScreenshot
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      check_return=True)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      return impl()
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 828, in RunShellCommand
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      output = handle_large_output(cmd, large_output).splitlines()
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 806, in handle_large_output
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124      return handle_large_command(cmd)
(CRITICAL) 2016-03-11 06:32:33,242 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 788, in handle_large_command
(CRITICAL) 2016-03-11 06:32:33,243 timeout_retry._LogLastException:124      return handle_check_return(cmd)
(CRITICAL) 2016-03-11 06:32:33,243 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 779, in handle_check_return
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      return run(cmd)
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 775, in run
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      return self.adb.Shell(cmd)
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 308, in Shell
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      output = self._RunDeviceAdbCmd(args, timeout, retries, check_error=False)
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 148, in _RunDeviceAdbCmd
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      check_error=check_error)
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      return impl()
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell '( /system/bin/screencap -p /data/local/tmp/temp_file-35fec663860cd.png );echo %$?': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,244 timeout_retry._LogLastException:125  ********************************************************************************
(INFO) 2016-03-11 06:32:33,245 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell '( /system/bin/screencap -p /data/local/tmp/temp_file-85889d68166cf.png );echo %$?'
(CRITICAL) 2016-03-11 06:32:33,248 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,248 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-1-for-delete_temporary_file(ZX1G22KGK7) (attempt 1 of 3)
(CRITICAL) 2016-03-11 06:32:33,248 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell 'rm -f /data/local/tmp/temp_file-35fec663860cd.png': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,249 timeout_retry._LogLastException:125  ********************************************************************************
(INFO) 2016-03-11 06:32:33,250 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-35fec663860cd.png'
(INFO) 2016-03-11 06:32:33,256 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-85889d68166cf.png'
(CRITICAL) 2016-03-11 06:32:33,262 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,262 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-2-for-MainThread (attempt 2 of 4)
(CRITICAL) 2016-03-11 06:32:33,262 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,263 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 1909, in TakeScreenshot
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      check_return=True)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return impl()
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 828, in RunShellCommand
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      output = handle_large_output(cmd, large_output).splitlines()
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 806, in handle_large_output
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return handle_large_command(cmd)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 788, in handle_large_command
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return handle_check_return(cmd)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 779, in handle_check_return
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return run(cmd)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 775, in run
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return self.adb.Shell(cmd)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 308, in Shell
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      output = self._RunDeviceAdbCmd(args, timeout, retries, check_error=False)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 148, in _RunDeviceAdbCmd
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      check_error=check_error)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return impl()
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell '( /system/bin/screencap -p /data/local/tmp/temp_file-85889d68166cf.png );echo %$?': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,264 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,265 timeout_retry._LogLastException:125  ********************************************************************************
(INFO) 2016-03-11 06:32:33,265 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell '( /system/bin/screencap -p /data/local/tmp/temp_file-290965be03a99.png );echo %$?'
(CRITICAL) 2016-03-11 06:32:33,268 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,268 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,268 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-2-for-delete_temporary_file(ZX1G22KGK7) (attempt 2 of 3)
(CRITICAL) 2016-03-11 06:32:33,268 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,268 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell 'rm -f /data/local/tmp/temp_file-35fec663860cd.png': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,269 timeout_retry._LogLastException:125  ********************************************************************************
(INFO) 2016-03-11 06:32:33,270 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-35fec663860cd.png'
(CRITICAL) 2016-03-11 06:32:33,272 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-1-for-delete_temporary_file(ZX1G22KGK7) (attempt 1 of 3)
(CRITICAL) 2016-03-11 06:32:33,272 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell 'rm -f /data/local/tmp/temp_file-85889d68166cf.png': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,273 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,274 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,274 timeout_retry._LogLastException:125  ********************************************************************************
(INFO) 2016-03-11 06:32:33,276 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-85889d68166cf.png'
(INFO) 2016-03-11 06:32:33,279 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-290965be03a99.png'
(CRITICAL) 2016-03-11 06:32:33,282 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,283 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-3-for-MainThread (attempt 3 of 4)
(CRITICAL) 2016-03-11 06:32:33,283 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,283 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 1909, in TakeScreenshot
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      check_return=True)
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
(CRITICAL) 2016-03-11 06:32:33,284 timeout_retry._LogLastException:124      return impl()
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 828, in RunShellCommand
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      output = handle_large_output(cmd, large_output).splitlines()
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 806, in handle_large_output
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return handle_large_command(cmd)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 788, in handle_large_command
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return handle_check_return(cmd)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 779, in handle_check_return
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return run(cmd)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 775, in run
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return self.adb.Shell(cmd)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 308, in Shell
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      output = self._RunDeviceAdbCmd(args, timeout, retries, check_error=False)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 148, in _RunDeviceAdbCmd
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      check_error=check_error)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return impl()
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell '( /system/bin/screencap -p /data/local/tmp/temp_file-290965be03a99.png );echo %$?': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,285 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,286 timeout_retry._LogLastException:125  ********************************************************************************
(INFO) 2016-03-11 06:32:33,286 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell '( /system/bin/screencap -p /data/local/tmp/temp_file-f7b15824f920b.png );echo %$?'
(CRITICAL) 2016-03-11 06:32:33,293 timeout_retry._LogLastException:118  ********************************************************************************
(INFO) 2016-03-11 06:32:33,293 cmd_helper._ValidateAndLogCommand:153  [host]> /b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/bin/deps/linux2/x86_64/bin/adb -s ZX1G22KGK7 shell 'rm -f /data/local/tmp/temp_file-f7b15824f920b.png'
(CRITICAL) 2016-03-11 06:32:33,293 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-1-for-delete_temporary_file(ZX1G22KGK7) (attempt 1 of 3)
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124      thread.ReraiseIfException()
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124      self._ret = self._func(*self._args, **self._kwargs)
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:124      child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124      return f(*args, **kwargs)
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124      args, output, status, device_serial)
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124  AdbCommandFailedError: (device: ZX1G22KGK7) adb shell 'rm -f /data/local/tmp/temp_file-290965be03a99.png': failed with exit status 255 and output:
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124  - error: device 'ZX1G22KGK7' not found
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124  
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:125  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,294 timeout_retry._LogLastException:118  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:120  Exception on thread TimeoutThread-2-for-delete_temporary_file(ZX1G22KGK7) (attempt 2 of 3)
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:121  ********************************************************************************
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124  Traceback (most recent call last):
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124      error_log_func=error_log_func)
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
(CRITICAL) 2016-03-11 06:32:33,295 timeout_retry._LogLastException:124      self._JoinAll(watcher, timeout)
(CRITICAL) 2016-03-11 06:32:33,298 timeout_retry._LogLastException:124    File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
(WARNING) 2016-03-11 06:32:33,299 shared_page_state._TryCaptureScreenShot:157  Exception when trying to capture screenshot: AdbCommandFailedError("(device: ZX1G22KGK7) adb shell '( /system/bin/screencap -p /data/local/tmp/temp_file-f7b15824f920b.png );echo %$?': failed with exit status 255 and output:\n- error: device 'ZX1G22KGK7' not found\n",)
Traceback (most recent call last):
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/story_runner.py", line 84, in _RunStoryAndProcessErrorIfNeeded
    state.RunStory(results)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/page/shared_page_state.py", line 325, in RunStory
    self._current_page, self._current_tab, results)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/tools/perf/benchmarks/service_worker.py", line 113, in ValidateAndMeasurePage
    with runner.CreateInteraction('_DummyInteraction'):
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/page/action_runner.py", line 701, in __enter__
    self.Begin()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/page/action_runner.py", line 718, in Begin
    self._label, self._flags))
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/browser/web_contents.py", line 143, in ExecuteJavaScript
    statement, context_id=None, timeout=timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/browser/web_contents.py", line 176, in ExecuteJavaScriptInContext
    expr, context_id=context_id, timeout=timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 35, in inner
    inspector_backend._ConvertExceptionFromInspectorWebsocket(e)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 32, in inner
    return func(inspector_backend, *args, **kwargs)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py", line 191, in ExecuteJavaScript
    self._runtime.Execute(expr, context_id, timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_runtime.py", line 21, in Execute
    self.Evaluate(expr + '; 0;', context_id, timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_runtime.py", line 45, in Evaluate
    res = self._inspector_websocket.SyncRequest(request, timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_websocket.py", line 110, in SyncRequest
    res = self._Receive(timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_websocket.py", line 149, in _Receive
    data = self._socket.recv()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/third_party/websocket-client/websocket.py", line 596, in recv
    opcode, data = self.recv_data()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/third_party/websocket-client/websocket.py", line 606, in recv_data
    frame = self.recv_frame()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/third_party/websocket-client/websocket.py", line 637, in recv_frame
    self._frame_header = self._recv_strict(2)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/third_party/websocket-client/websocket.py", line 746, in _recv_strict
    bytes = self._recv(shortage)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/third_party/websocket-client/websocket.py", line 739, in _recv
    raise WebSocketConnectionClosedException()
DevtoolsTargetCrashException: Devtools target crashed
********************************************************************************
(/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/backends/chrome_inspector/inspector_backend.py:320 _ConvertExceptionFromInspectorWebsocket) Original exception:

Comment 9 by simonhatch@chromium.org, Mar 11 2016

Labels: OS-Android

Comment 10 by nedngu...@google.com, Mar 11 2016

Cc: rnep...@chromium.org falken@chromium.org
Owner: zh...@chromium.org
+Zhen, Randy:

Since falken has add the call to make sure SoptTracing() is always called even if measurement fail, I suspect that "Tracing is started" error here come from the fact that we failed to clean up the startup tracing file.

+Randy: can you take a look at devil failure?

Comment 11 by zh...@chromium.org, Mar 16 2016

Cc: zh...@chromium.org
Owner: rnep...@chromium.org
I digged more in the log https://uberchromegw.corp.google.com/i/chromium.perf/builders/Android%20Nexus6%20Perf%20%281%29/builds/1894/steps/service_worker.service_worker/logs/stdio

Before "Tracing is already started" error, there was actually TracingControllerStoppedError:


Traceback (most recent call last):
  _RunStoryAndProcessErrorIfNeeded at third_party/catapult/telemetry/telemetry/internal/story_runner.py:110
    test.DidRunPage(state.platform)
  DidRunPage at tools/perf/benchmarks/service_worker.py:100
    platform.tracing_controller.StopTracing()
  StopTracing at third_party/catapult/telemetry/telemetry/core/tracing_controller.py:39
    return self._tracing_controller_backend.StopTracing()
  StopTracing at third_party/catapult/telemetry/telemetry/internal/platform/tracing_controller_backend.py:124
    '\n'.join(raised_exception_messages))
TracingControllerStoppedError: Exceptions raised when trying to stop tracing:
Traceback (most recent call last):
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/platform/tracing_controller_backend.py", line 113, in StopTracing
    agent.StopAgentTracing(builder)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py", line 118, in StopAgentTracing
    self._RemoveTraceConfigFile()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/telemetry/telemetry/internal/platform/tracing_agent/chrome_tracing_agent.py", line 175, in _RemoveTraceConfigFile
    as_root=True)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 57, in timeout_retry_wrapper
    retry_if_func=retry_if_func)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 167, in Run
    error_log_func=error_log_func)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 186, in JoinAll
    self._JoinAll(watcher, timeout)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 158, in _JoinAll
    thread.ReraiseIfException()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/reraiser_thread.py", line 81, in run
    self._ret = self._func(*self._args, **self._kwargs)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/utils/timeout_retry.py", line 160, in <lambda>
    child_thread = reraiser_thread.ReraiserThread(lambda: func(*args, **kwargs),
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
    return f(*args, **kwargs)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 828, in RunShellCommand
    output = handle_large_output(cmd, large_output).splitlines()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 806, in handle_large_output
    return handle_large_command(cmd)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 788, in handle_large_command
    return handle_check_return(cmd)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 779, in handle_check_return
    return run(cmd)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/device_utils.py", line 775, in run
    return self.adb.Shell(cmd)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 308, in Shell
    output = self._RunDeviceAdbCmd(args, timeout, retries, check_error=False)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 148, in _RunDeviceAdbCmd
    check_error=check_error)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 51, in timeout_retry_wrapper
    return impl()
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/decorators.py", line 47, in impl
    return f(*args, **kwargs)
  File "/b/build/slave/Android_Nexus6_Perf__1_/build/src/third_party/catapult/devil/devil/android/sdk/adb_wrapper.py", line 124, in _RunAdbCmd
    args, output, status, device_serial)
AdbCommandFailedError: (device: ZX1G22KGK7) adb shell '( rm -f /data/local/chrome-trace-config.json );echo %$?': failed with exit status 255 and output:
- error: device 'ZX1G22KGK7' not found


So it is actually the device error causing tracing cannot be stopped. So I think the fix for devil should fix the problem.

Assigning to Randy.

Comment 12 by zh...@chromium.org, Mar 16 2016

Summary: Every test after failed test fails with "Tracing is already started" (due to TracingControllerStoppedError caused by devil error) (was: Every test after failed test fails with "Tracing is already started")

Comment 13 by rnep...@chromium.org, Mar 16 2016

Cc: jbudorick@chromium.org
This is not a devil problem. The device is not reachable for some reason, so the commands being issued to it are failing. There is no fix in devil that can make the device become reachable. The failure is one of the tracing agents is not properly cleaning up on this failure condition.

Adding John in case he disagrees with this.

Comment 14 by zh...@chromium.org, Mar 16 2016

Status: WontFix (was: Started)
Given the device was not reachable, I think there is no way for tracing agents to do the cleanup.

It looks like the bots are fine now after the device errors are gone. I will close this issue now. Reopen if you think otherwise.

Comment 15 by rnep...@chromium.org, Mar 16 2016 

It might be a good idea for resilience to do the clean up if the agent sees the error case when starting tracing and does the cleanup and tries again. Its not perfect, but would stop this case from happening again.
►

Sign in to add a comment