Chrome Version       : 10009.0.0
FW Version : Google_Coral 9984

What steps will reproduce the problem?
Run FAFT test firmware_UpdateFirmwareDataKeyVersion 

Result: FAILED

Partial logs below. Full logs attached. 

This failure likely started on 9982.0.0. The failure was not seen on 9963.0.0.

This failure is possible caused by https://chromium-review.googlesource.com/#/c/chromiumos/platform/firmware/+/668318/

Firmware version will update to version 2
10/09 23:34:31.262 INFO | test_runner_utils:0199| autoserv| Update firmware with new datakey version.
10/09 23:34:31.263 INFO | test_runner_utils:0199| autoserv| -[FAFT]-[ start stepstate_checker ]----------
10/09 23:34:31.263 INFO | test_runner_utils:0199| autoserv| calling crossystem_checker with args ({'fwid': 'Google_Coral.9984.0.0'},)
10/09 23:34:31.444 INFO | test_runner_utils:0199| autoserv| Expected 'fwid' value 'Google_Coral.9984.0.0' == real value 'Google_Coral.9984.0.0'
10/09 23:34:31.445 INFO | test_runner_utils:0199| autoserv| -[FAFT]-[ end state_checker ]----------------
10/09 23:34:31.446 INFO | test_runner_utils:0199| autoserv| -[FAFT]-[ start stepstate_checker ]----------
10/09 23:34:31.447 INFO | test_runner_utils:0199| autoserv| calling fw_tries_checker with args ('A',)
10/09 23:34:31.503 INFO | test_runner_utils:0199| autoserv| Expected 'mainfw_act' value 'A' == real value 'A'
10/09 23:34:31.503 INFO | test_runner_utils:0199| autoserv| Expected 'fw_try_count' value '0' == real value '0'
10/09 23:34:31.504 INFO | test_runner_utils:0199| autoserv| -[FAFT]-[ end state_checker ]----------------
10/09 23:34:42.436 INFO | test_runner_utils:0199| autoserv| The test failed with the following exception
10/09 23:34:42.437 INFO | test_runner_utils:0199| autoserv| Traceback (most recent call last):
10/09 23:34:42.437 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/client/common_lib/test.py", line 606, in _exec
10/09 23:34:42.437 INFO | test_runner_utils:0199| autoserv| _call_test_function(self.execute, *p_args, **p_dargs)
10/09 23:34:42.438 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/client/common_lib/test.py", line 812, in _call_test_function
10/09 23:34:42.438 INFO | test_runner_utils:0199| autoserv| raise error.UnhandledTestFail(e)
10/09 23:34:42.438 INFO | test_runner_utils:0199| autoserv| UnhandledTestFail: Unhandled Fault: <Fault 1: "<class 'autotest_lib.client.cros.faft.utils.shell_wrapper.ShellError'>:command /bin/sh /var/tmp/faft/autest/chromeos-firmwareupdate-test --mode autoupdate --noupdate_ec --nocheck_rw_compatible failed (code: 1)">
10/09 23:34:42.438 INFO | test_runner_utils:0199| autoserv| Traceback (most recent call last):
10/09 23:34:42.439 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/client/common_lib/test.py", line 806, in _call_test_function
10/09 23:34:42.439 INFO | test_runner_utils:0199| autoserv| return func(*args, **dargs)
10/09 23:34:42.439 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/client/common_lib/test.py", line 470, in execute
10/09 23:34:42.439 INFO | test_runner_utils:0199| autoserv| dargs)
10/09 23:34:42.440 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/client/common_lib/test.py", line 347, in _call_run_once_with_retry
10/09 23:34:42.440 INFO | test_runner_utils:0199| autoserv| postprocess_profiled_run, args, dargs)
10/09 23:34:42.440 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/client/common_lib/test.py", line 380, in _call_run_once
10/09 23:34:42.441 INFO | test_runner_utils:0199| autoserv| self.run_once(*args, **dargs)
10/09 23:34:42.441 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/server/site_tests/firmware_UpdateFirmwareDataKeyVersion/firmware_UpdateFirmwareDataKeyVersion.py", line 94, in run_once
10/09 23:34:42.441 INFO | test_runner_utils:0199| autoserv| self.faft_client.updater.run_autoupdate('test')
10/09 23:34:42.441 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/server/cros/faft/rpc_proxy.py", line 33, in __call__
10/09 23:34:42.442 INFO | test_runner_utils:0199| autoserv| return self.__call_method(self.__name, *args, **dargs)
10/09 23:34:42.442 INFO | test_runner_utils:0199| autoserv| File "/build/coral/usr/local/build/autotest/server/cros/faft/rpc_proxy.py", line 72, in __call_faft_client
10/09 23:34:42.442 INFO | test_runner_utils:0199| autoserv| return getattr(self._faft_client, name)(*args, **dargs)
10/09 23:34:42.443 INFO | test_runner_utils:0199| autoserv| File "/usr/lib64/python2.7/xmlrpclib.py", line 1240, in __call__
10/09 23:34:42.443 INFO | test_runner_utils:0199| autoserv| return self.__send(self.__name, args)
10/09 23:34:42.443 INFO | test_runner_utils:0199| autoserv| File "/usr/lib64/python2.7/xmlrpclib.py", line 1599, in __request
10/09 23:34:42.443 INFO | test_runner_utils:0199| autoserv| verbose=self.__verbose
10/09 23:34:42.444 INFO | test_runner_utils:0199| autoserv| File "/usr/lib64/python2.7/xmlrpclib.py", line 1280, in request
10/09 23:34:42.444 INFO | test_runner_utils:0199| autoserv| return self.single_request(host, handler, request_body, verbose)
10/09 23:34:42.444 INFO | test_runner_utils:0199| autoserv| File "/usr/lib64/python2.7/xmlrpclib.py", line 1313, in single_request
10/09 23:34:42.444 INFO | test_runner_utils:0199| autoserv| return self.parse_response(response)
10/09 23:34:42.445 INFO | test_runner_utils:0199| autoserv| File "/usr/lib64/python2.7/xmlrpclib.py", line 1490, in parse_response
10/09 23:34:42.445 INFO | test_runner_utils:0199| autoserv| return u.close()
10/09 23:34:42.445 INFO | test_runner_utils:0199| autoserv| File "/usr/lib64/python2.7/xmlrpclib.py", line 799, in close
10/09 23:34:42.445 INFO | test_runner_utils:0199| autoserv| raise Fault(**self._stack[0])
10/09 23:34:42.446 INFO | test_runner_utils:0199| autoserv| Fault: <Fault 1: "<class 'autotest_lib.client.cros.faft.utils.shell_wrapper.ShellError'>:command /bin/sh /var/tmp/faft/autest/chromeos-firmwareupdate-test --mode autoupdate --noupdate_ec --nocheck_rw_compatible failed (code: 1)">
10/09 23:34:42.446 INFO | test_runner_utils:0199| autoserv| 
10/09 23:34:51.578 INFO | test_runner_utils:0199| autoserv| FirmwareTest cleaning up (id=b74c8e39-7885-4ac1-a370-bd6f02bac08a)
10/09 23:34:51.665 INFO | test_runner_utils:0199| autoserv| ***
10/09 23:34:51.665 INFO | test_runner_utils:0199| autoserv| *** Please manually restore the original GBB flags to: 0x39 ***
10/09 23:34:51.666 INFO | test_runner_utils:0199| autoserv| ***
10/09 23:34:51.666 INFO | test_runner_utils:0199| autoserv| Starting update-engine...
10/09 23:34:51.832 INFO | test_runner_utils:0199| autoserv| Removing FAFT lockfile...
10/09 23:34:52.045 INFO | test_runner_utils:0199| autoserv| Setting cpu_uart_capture to off
10/09 23:34:52.126 INFO | test_runner_utils:0199| autoserv| Setting ec_uart_capture to off
10/09 23:34:52.227 INFO | test_runner_utils:0199| autoserv| FirmwareTest cleanup done (id=b74c8e39-7885-4ac1-a370-bd6f02bac08a)
10/09 23:34:52.236 INFO | test_runner_utils:0199| autoserv| FAIL	firmware_UpdateFirmwareDataKeyVersion	firmware_UpdateFirmwareDataKeyVersion	timestamp=1507610092	localtime=Oct 09 23:34:52	Unhandled Fault: <Fault 1: "<class 'autotest_lib.client.cros.faft.utils.shell_wrapper.ShellError'>:command /bin/sh /var/tmp/faft/autest/chromeos-firmwareupdate-test --mode autoupdate --noupdate_ec --nocheck_rw_compatible failed (code: 1)">




 

Deleted: single_test_failed_items_full_log.tar.bz2 11.2 MB

single_test_failed_items_full_log.tar.bz2 11.2 MB Download