Failed to execute faft bios, board tense to stuck and after reset board and test pass when rerun.

/tmp/test_that_results_vyCKNR/results-44-firmware_LegacyRecovery/firmware_LegacyRecovery.normal                             [  PASSED  ]
/tmp/test_that_results_vyCKNR/results-45-firmware_TryFwB.dev                                                                [  FAILED  ]
/tmp/test_that_results_vyCKNR/results-45-firmware_TryFwB.dev                                                                  FAIL: Setting 'power_state' to 'on' :: [Errno 11] Resou
rce temporarily unavailable
/tmp/test_that_results_vyCKNR/results-45-firmware_TryFwB.dev/firmware_TryFwB.dev                                            [  FAILED  ]
/tmp/test_that_results_vyCKNR/results-45-firmware_TryFwB.dev/firmware_TryFwB.dev                                              FAIL: Setting 'power_state' to 'on' :: [Errno 11] Resou
rce temporarily unavailable
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion                                                       [  FAILED  ]
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion                                                         ERROR: Unhandled AutoservInstallError: Unable to find a
 place to install Autotest; tried /usr/local/autotest, /usr/local/autodir
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                      [  FAILED  ]
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        ERROR: Unhandled AutoservInstallError: Unable to find a
 place to install Autotest; tried /usr/local/autotest, /usr/local/autodir
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.862 ERROR|              test:0613| Ignor
ing exception during cleanup() phase:
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.863 ERROR|         traceback:0013| Trace
back (most recent call last):
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.864 ERROR|         traceback:0013|   Fil
e "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 611, in _exec
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.864 ERROR|         traceback:0013|     _
cherry_pick_call(self.cleanup, *args, **dargs)
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.864 ERROR|         traceback:0013|   Fil
e "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 719, in _cherry_pick_call
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.864 ERROR|         traceback:0013|     r
eturn func(*p_args, **p_dargs)
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.865 ERROR|         traceback:0013|   Fil
e "/mnt/host/source/src/third_party/autotest/files/server/site_tests/firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.py", line 57, in cleanup
/tmp/test_that_results_vyCKNR/results-46-firmware_UpdateKernelVersion/firmware_UpdateKernelVersion.dev                        08/27 00:19:28.865 ERROR|         traceback:0013|     s


#1 dchan@google.com
full log uploaded https://storage.googleapis.com/chromiumos-test-logs/bugfiles/crosp/56733/test_that_results_vyCKNR.tar.gz

servod debug log https://storage.googleapis.com/chromiumos-test-logs/bugfiles/crosp/56733/servod.txt


#2 dchan@google.com
(No comment was entered for this change.)
Cc: nsanders@chromium.org kevcheng@google.com 


#3 dchan@google.com
Noted that the test was executed on my desktop, there are no recovery done between test, once the test failed to power on the dut firmware_TryFwB.dev, the remaining test will failed.

There are not much detail on why the test failed to invoke power_state:on

08/26 23:28:37.425 INFO |             servo:0506| Setting power_state to off
08/26 23:28:48.957 INFO |             servo:0506| Setting power_state to on
08/26 23:28:49.022 DEBUG|   logging_manager:0627| Logging subprocess finished
08/26 23:28:49.025 DEBUG|   logging_manager:0627| Logging subprocess finished
08/26 23:28:49.027 INFO |        server_job:0129|       FAIL    firmware_TryFwB.dev     firmware_TryFwB.dev     timestamp=1472272129    localtime=Aug 26 23:28:49       Setting 'power_state' to 'on' :: [Errno 11] Resource temporarily unavailable
08/26 23:28:49.028 INFO |        server_job:0129| END FAIL      firmware_TryFwB.dev     firmware_TryFwB.dev     timestamp=1472272129    localtime=Aug 26 23:28:49


#4 nsanders@google.com
(No comment was entered for this change.)
Owner: nsanders@google.com 


#5 dchan@google.com
I reran the bios suite and both time the failure was due to something like this

09/06 19:10:11.691 INFO |     mode_switcher:0238| -[ModeSwitcher]-[ start reboot_to_mode('dev', None, True) ]-
09/06 19:10:11.898 INFO |     mode_switcher:0458| Enabling keyboard controlled developer mode
09/06 19:10:11.899 INFO |             servo:0506| Setting power_state to off
09/06 19:10:22.930 INFO |             servo:0506| Setting prtctl4_pwren to off
09/06 19:10:24.944 INFO |             servo:0506| Setting usb_mux_sel1 to servo_sees_usbkey
09/06 19:10:26.959 INFO |             servo:0506| Setting prtctl4_pwren to on
09/06 19:10:36.978 INFO |             servo:0506| Setting power_state to rec
09/06 19:10:37.176 WARNI|              test:0606| Autotest caught exception when running test:
Traceback (most recent call last):
  File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 567, in _exec
    _cherry_pick_call(self.initialize, *args, **dargs)
  File "/mnt/host/source/src/third_party/autotest/files/client/common_lib/test.py", line 719, in _cherry_pick_call
    return func(*p_args, **p_dargs)
  File "/mnt/host/source/src/third_party/autotest/files/server/site_tests/firmware_RollbackKernel/firmware_RollbackKernel.py", line 41, in initialize
    self.switcher.setup_mode('dev' if dev_mode else 'normal')
  File "/mnt/host/source/src/third_party/autotest/files/server/cros/faft/utils/mode_switcher.py", line 215, in setup_mode
    self.reboot_to_mode(mode)
  File "/mnt/host/source/src/third_party/autotest/files/server/cros/faft/utils/mode_switcher.py", line 248, in reboot_to_mode
    self._enable_dev_mode_and_reboot()
  File "/mnt/host/source/src/third_party/autotest/files/server/cros/faft/utils/mode_switcher.py", line 461, in _enable_dev_mode_and_reboot
    self._enable_rec_mode_and_reboot(usb_state='host')
  File "/mnt/host/source/src/third_party/autotest/files/server/cros/faft/utils/mode_switcher.py", line 332, in _enable_rec_mode_and_reboot
    psc.power_on(psc.REC_ON)
  File "/mnt/host/source/src/third_party/autotest/files/server/cros/servo/servo.py", line 104, in power_on
    self._servo.set_nocheck('power_state', rec_mode)
  File "/mnt/host/source/src/third_party/autotest/files/server/cros/servo/servo.py", line 512, in set_nocheck
    raise error.TestFail(err_msg)
TestFail: Setting 'power_state' to 'rec' :: [Errno 11] Resource temporarily unavailable


#6 kevcheng@google.com
I have a script that just repeatedly powers on the device in rec mode every 20 seconds, it's been going strong since yesterday afternoon (so almost 24 hours).  I think there might be some contention between the ec uart during testing since there is ec uart capture going on at the same time this power cycling happens.
Sep 9, 2016 #7 dchan@google.com
while running faft_ec I see occasional servod error 
 2016-09-09 12:28:26,808 - Servod - ERROR - Problem initializing usb3_pwr_en -> on :: [Errno 5] Input/output error
2016-09-09 13:44:10,492 - Servod - ERROR - Problem initializing sbu_uart_sel -> ccd :: [Errno 110] Operation timed out

Summary: servov4: failed to complete faft suite (was: servov4: failed to complete faft bios suite) 
Sep 9, 2016 #8 dchan@google.com
while running faft_ec I see occasional servod error 
 2016-09-09 12:28:26,808 - Servod - ERROR - Problem initializing usb3_pwr_en -> on :: [Errno 5] Input/output error
2016-09-09 13:44:10,492 - Servod - ERROR - Problem initializing sbu_uart_sel -> ccd :: [Errno 110] Operation timed out


original bug from parter https://code.google.com/p/chrome-os-partner/issues/detail?id=56733