Recently we have seen the following error occur (autofiled issues linked). I am not sure what if anything we can do about this, but filing this issue for tracking purposes.

At minimum it would be nice to provide more information to the builder when this occurs.



04/19 12:08:54.532 DEBUG|provision_AutoUpda:0091| Start provisioning <remote host: chromeos4-row2-rack3-host12> to tricky-tot-chrome-pfq-informational/R52-8215.0.0-b460
04/19 12:08:54.886 INFO |        dev_server:0921| Staging artifacts on devserver http://100.107.160.7:8082: build=tricky-tot-chrome-pfq-informational/R52-8215.0.0-b460, artifacts=['full_payload', 'stateful', 'autotest_packages'], files=, archive_url=gs://chromeos-image-archive/tricky-tot-chrome-pfq-informational/R52-8215.0.0-b460
04/19 12:09:05.892 WARNI|              test:0606| Autotest caught exception when running test:
Traceback (most recent call last):
  File "/usr/local/autotest/client/common_lib/test.py", line 600, in _exec
    _call_test_function(self.execute, *p_args, **p_dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 804, in _call_test_function
    return func(*args, **dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 461, in execute
    dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 347, in _call_run_once_with_retry
    postprocess_profiled_run, args, dargs)
  File "/usr/local/autotest/client/common_lib/test.py", line 376, in _call_run_once
    self.run_once(*args, **dargs)
  File "/usr/local/autotest/server/site_tests/provision_AutoUpdate/provision_AutoUpdate.py", line 125, in run_once
    raise error.TestFail(str(e))
TestFail: 

503 Service Unavailable

Service Unavailable
The server is temporarily unable to service your
request due to maintenance downtime or capacity
problems. Please try again later.

Apache/2.4.7 (Ubuntu) Server at 100.107.160.7 Port 8082


04/19 12:09:05.895 DEBUG|   logging_manager:0627| Logging subprocess finished
04/19 12:09:05.909 DEBUG|   logging_manager:0627| Logging subprocess finished
04/19 12:09:05.939 DEBUG|          ssh_host:0181| Running (ssh) 'if type "logger" > /dev/null 2>&1; then logger -tag "autotest" "server[stack::runtest|cleanup|uninstall] -> ssh_run(rm -rf /tmp/sysinfo/autoserv-EaRsD5)";fi; rm -rf /tmp/sysinfo/autoserv-EaRsD5'
04/19 12:09:06.150 DEBUG|          ssh_host:0181| Running (ssh) 'if type "logger" > /dev/null 2>&1; then logger -tag "autotest" "server[stack::close|close|close] -> ssh_run(rm -rf \"/tmp/sysinfo/autoserv-EaRsD5\")";fi; rm -rf "/tmp/sysinfo/autoserv-EaRsD5"'
04/19 12:09:06.364 DEBUG|          ssh_host:0181| Running (ssh) 'if type "logger" > /dev/null 2>&1; then logger -tag "autotest" "server[stack::close|close|close] -> ssh_run(rm -rf \"/tmp/autoserv-Ilc5Cc\")";fi; rm -rf "/tmp/autoserv-Ilc5Cc"'
04/19 12:09:06.572 DEBUG|          ssh_host:0181| Running (ssh) 'if type "logger" > /dev/null 2>&1; then logger -tag "autotest" "server[stack::close|close|close] -> ssh_run(rm -rf \"/tmp/autoserv-VV3oAo\")";fi; rm -rf "/tmp/autoserv-VV3oAo"'
04/19 12:09:06.779 DEBUG|      abstract_ssh:0696| Nuking master_ssh_job.
04/19 12:09:07.786 DEBUG|      abstract_ssh:0702| Cleaning master_ssh_tempdir.
04/19 12:09:07.789 INFO |        server_job:0128| 		FAIL	provision_AutoUpdate	provision_AutoUpdate	timestamp=1461092947	localtime=Apr 19 12:09:07	
  
  503 Service Unavailable
  
  Service Unavailable
  The server is temporarily unable to service your
  request due to maintenance downtime or capacity
  problems. Please try again later.
  
  Apache/2.4.7 (Ubuntu) Server at 100.107.160.7 Port 8082
  
  
04/19 12:09:07.790 INFO |        server_job:0128| 	END FAIL	provision_AutoUpdate	provision_AutoUpdate	timestamp=1461092947	localtime=Apr 19 12:09:07	
04/19 12:09:07.791 ERROR|           control:0029| 
Traceback (most recent call last):
  File "/usr/local/autotest/results/hosts/chromeos4-row2-rack3-host12/621501-provision/20161904120815/control.srv", line 27, in provision_machine
    provision.Provision)
  File "/usr/local/autotest/server/cros/provision.py", line 318, in run_special_task_actions
    raise SpecialTaskActionException()
SpecialTaskActionException
04/19 12:09:07.794 INFO |        server_job:0128| END FAIL	----	provision	timestamp=1461092947	localtime=Apr 19 12:09:07	
04/19 12:09:07.795 ERROR|        server_job:0692| Exception escaped control file, job aborting:
Traceback (most recent call last):
  File "/usr/local/autotest/server/server_job.py", line 684, in run
    self._execute_code(server_control_file, namespace)
  File "/usr/local/autotest/server/server_job.py", line 1182, in _execute_code
    execfile(code_file, namespace, namespace)
  File "/usr/local/autotest/results/hosts/chromeos4-row2-rack3-host12/621501-provision/20161904120815/control.srv", line 62, in <module>
    job.parallel_simple(provision_machine, machines)
  File "/usr/local/autotest/server/server_job.py", line 574, in parallel_simple
    return_results=return_results)
  File "/usr/local/autotest/server/subcommand.py", line 93, in parallel_simple
    function(arg)
  File "/usr/local/autotest/results/hosts/chromeos4-row2-rack3-host12/621501-provision/20161904120815/control.srv", line 54, in provision_machine
    raise Exception('')
Exception