Issue 638610 link

Starred by 2 users

Issue metadata

Status:	Assigned
Owner:	█ shchen@chromium.org Last visit > 30 days ago
Cc:	█ lhui@chromium.org █ venkatar...@chromium.org █ waihong@chromium.org █ kevcheng@chromium.org █ andychanyan@chromium.org █ shchen@chromium.org █ tgillella@chromium.org adurbin@chromium.org
Components:	OS>Firmware
EstimatedDays:	----
NextAction:	----
OS:	----
Pri:	3
Type:	Bug
Hotlist-Google

FAFT need better device reset when running suite

Project Member Reported by dchan@google.com, Aug 17 2016

Issue description

I ran faft:bios on terra and one of the test failed to reset the device and result in the subsequent test to failed due to DUT is down.

Here are all the non-PASS tests for the suite

$ grep '^END' */status.log | grep -v 'END GOOD'
results-13-firmware_EventLog/status.log:END FAIL        firmware_EventLog       firmware_EventLog       timestamp=1471402931    localtime=Aug 16 22:02:11
results-21-firmware_CorruptBothKernelAB.dev/status.log:END FAIL firmware_CorruptBothKernelAB.dev        firmware_CorruptBothKernelAB.dev        timestamp=1471405693    localtime=Aug 16 22:48:13
results-22-firmware_RONormalBoot.dev/status.log:END ERROR       firmware_RONormalBoot.dev       firmware_RONormalBoot.dev       timestamp=1471408735    localtime=Aug 16 23:38:55
results-23-firmware_DevScreenTimeout/status.log:END ERROR       firmware_DevScreenTimeout.dev   firmware_DevScreenTimeout.dev   timestamp=1471410581    localtime=Aug 17 00:09:41
results-24-firmware_LegacyRecovery/status.log:END ERROR firmware_LegacyRecovery.normal  firmware_LegacyRecovery.normal  timestamp=1471412426    localtime=Aug 17 00:40:26
results-25-firmware_UpdateFirmwareDataKeyVersion/status.log:END ERROR   firmware_UpdateFirmwareDataKeyVersion   firmware_UpdateFirmwareDataKeyVersion   timestamp=1471414272    localtime=Aug 17 01:11:12
results-26-firmware_UpdateKernelVersion/status.log:END ERROR    firmware_UpdateKernelVersion.dev        firmware_UpdateKernelVersion.dev        timestamp=1471416116    localtime=Aug 17 01:41:56
results-27-firmware_CorruptBothFwSigAB.dev/status.log:END ERROR firmware_CorruptBothFwSigAB.dev firmware_CorruptBothFwSigAB.dev timestamp=1471417962    localtime=Aug 17 02:12:42
results-28-firmware_CorruptFwBodyB.dev/status.log:END ERROR     firmware_CorruptFwBodyB.dev     firmware_CorruptFwBodyB.dev     timestamp=1471419807    localtime=Aug 17 02:43:27
results-29-firmware_CorruptBothFwBodyAB.dev/status.log:END ERROR        firmware_CorruptBothFwBodyAB.dev        firmware_CorruptBothFwBodyAB.dev        timestamp=1471421653    localtime=Aug 17 03:14:13
results-30-firmware_TPMExtend/status.log:END ERROR      firmware_TPMExtend      firmware_TPMExtend      timestamp=1471423498    localtime=Aug 17 03:44:58
results-31-firmware_RollbackFirmware/status.log:END ERROR       firmware_RollbackFirmware.normal        firmware_RollbackFirmware.normal        timestamp=1471425344    localtime=Aug 17 04:15:44
results-32-firmware_TPMVersionCheck/status.log:END ERROR        firmware_TPMVersionCheck.normal firmware_TPMVersionCheck.normal timestamp=1471427189    localtime=Aug 17 04:46:29
results-33-firmware_TPMVersionCheck.dev/status.log:END ERROR    firmware_TPMVersionCheck.dev    firmware_TPMVersionCheck.dev    timestamp=1471429033    localtime=Aug 17 05:17:13
results-34-firmware_RollbackKernel/status.log:END ERROR firmware_RollbackKernel.normal  firmware_RollbackKernel.normal  timestamp=1471430329    localtime=Aug 17 05:38:49
results-35-firmware_RecoveryButton/status.log:END ERROR firmware_RecoveryButton.normal  firmware_RecoveryButton.normal  timestamp=1471431623    localtime=Aug 17 06:00:23
results-36-firmware_CorruptKernelA.dev/status.log:END ERROR     firmware_CorruptKernelA.dev     firmware_CorruptKernelA.dev     timestamp=1471433468    localtime=Aug 17 06:31:08
results-37-firmware_UpdateKernelSubkeyVersion/status.log:END ERROR      firmware_UpdateKernelSubkeyVersion.dev  firmware_UpdateKernelSubkeyVersion.dev  timestamp=1471435314    localtime=Aug 17 07:01:54
results-38-firmware_SelfSignedBoot/status.log:END ERROR firmware_SelfSignedBoot.dev     firmware_SelfSignedBoot.dev     timestamp=1471436609    localtime=Aug 17 07:23:29
results-39-firmware_CorruptFwSigB/status.log:END ERROR  firmware_CorruptFwSigB.normal   firmware_CorruptFwSigB.normal   timestamp=1471438454    localtime=Aug 17 07:54:14
results-40-firmware_InvalidUSB/status.log:END ERROR     firmware_InvalidUSB.normal      firmware_InvalidUSB.normal      timestamp=1471440330    localtime=Aug 17 08:25:30
results-41-firmware_UpdateKernelDataKeyVersion/status.log:END ERROR     firmware_UpdateKernelDataKeyVersion.dev firmware_UpdateKernelDataKeyVersion.dev timestamp=1471442177    localtime=Aug 17 08:56:17
results-42-firmware_UpdateFirmwareVersion/status.log:END ERROR  firmware_UpdateFirmwareVersion  firmware_UpdateFirmwareVersion  timestamp=1471444024    localtime=Aug 17 09:27:04
results-43-firmware_CorruptBothFwSigAB/status.log:END ERROR     firmware_CorruptBothFwSigAB.normal      firmware_CorruptBothFwSigAB.normal      timestamp=1471445869    localtime=Aug 17 09:57:49
results-45-firmware_CorruptBothFwBodyAB/status.log:END FAIL     firmware_CorruptBothFwBodyAB.normal     firmware_CorruptBothFwBodyAB.normal     timestamp=1471446686    localtime=Aug 17 10:11:26
results-47-firmware_CorruptFwBodyA/status.log:END FAIL  firmware_CorruptFwBodyA.normal  firmware_CorruptFwBodyA.normal  timestamp=1471447227    localtime=Aug 17 10:20:27

The started the test around 6pm last night and came in this morning the DUT was down and the suite was still running. I manually tab the power suite and the test continue to run (and looks like passing)


2 requests here
1- each test should start by trying to reset the machine if needed
2- if the DUT is down, fail quickly.  Based on the output above, each test took 30 minutes to fail


Noted that this test was run with servo v4, but I think the request apply to any servo version.

Comment 1 by dchan@google.com, Aug 17 2016

test suite output
https://storage.googleapis.com/chromiumos-test-logs/bugfiles/crosp/638610/test_that_results_XONXHY.tar.gz

Comment 2 by dchan@google.com, Aug 17 2016

servod error:

2016-08-17 08:15:50,880 - root - INFO - Pressing power button for 0.2000 secs
2016-08-17 08:20:42,389 - Servod - ERROR - Problem initializing usb3_pwr_en -> on :: [Errno 5] Input/output error
2016-08-17 08:20:42,400 - Driver - ERROR - sx1506 REG_DIR should be 0x0, actually is 0xa0!
2016-08-17 08:20:42,416 - Driver - ERROR - sx1506 REG_DIR should be 0x20, actually is 0x20a0!
2016-08-17 08:21:51,876 - Servod - ERROR - Problem initializing uart1_enable -> on :: Timeout waiting for response.
2016-08-17 08:21:54,897 - Servod - ERROR - Problem initializing servo_jtag_trst -> off :: Timeout waiting for response.
2016-08-17 08:21:57,917 - Servod - ERROR - Problem initializing spi1_buf_en -> off :: Timeout waiting for response.
2016-08-17 08:22:00,947 - Servod - ERROR - Problem initializing spi2_buf_en -> off :: Timeout waiting for response.
2016-08-17 08:22:03,967 - Servod - ERROR - Problem initializing uart2_enable -> on :: Timeout waiting for response.
2016-08-17 08:22:06,990 - Servod - ERROR - Problem initializing spi1_vref -> off :: Timeout waiting for response.
2016-08-17 08:22:10,010 - Servod - ERROR - Problem initializing spi2_vref -> off :: Timeout waiting for response.
2016-08-17 08:22:13,031 - Servod - ERROR - Problem initializing servo_jtag_trst_dir -> off :: Timeout waiting for response.
2016-08-17 08:22:16,051 - Servod - ERROR - Problem initializing servo_jtag_tdi_dir -> off :: Timeout waiting for response.
2016-08-17 08:22:19,071 - Servod - ERROR - Problem initializing gpio_expander_reset -> off :: Timeout waiting for response.
2016-08-17 08:22:22,093 - Servod - ERROR - Problem initializing uart3_on_spi1 -> off :: Timeout waiting for response.
2016-08-17 08:22:25,115 - Servod - ERROR - Problem initializing SERVO_JTAG_TMS_DIR -> off :: Timeout waiting for response.
2016-08-17 08:22:28,139 - Servod - ERROR - Problem initializing SERVO_JTAG_TDO_SEL -> off :: Timeout waiting for response.
2016-08-17 08:22:31,165 - Servod - ERROR - Problem initializing SERVO_JTAG_TMS -> off :: Timeout waiting for response.
2016-08-17 08:22:34,186 - Servod - ERROR - Problem initializing UART3_TX_SERVO_JTAG_TCK -> off :: Timeout waiting for response
2016-08-17 08:22:37,207 - Servod - ERROR - Problem initializing UART3_RX_JTAG_BUFFER_TO_SERVO_TDO -> off :: Timeout waiting fo response.
2016-08-17 08:22:40,229 - Servod - ERROR - Problem initializing SERVO_JTAG_TDO_BUFFER_EN -> off :: Timeout waiting for respons.
2016-08-17 08:22:43,253 - Servod - ERROR - Problem initializing SERVO_JTAG_TDI -> off :: Timeout waiting for response.
2016-08-17 08:22:46,274 - Servod - ERROR - Problem initializing SERVO_JTAG_RTCK -> off :: Timeout waiting for response.
2016-08-17 08:22:49,297 - Servod - ERROR - Problem initializing JTAG_BUFOUT_EN_L -> off :: Timeout waiting for response.
2016-08-17 08:22:52,318 - Servod - ERROR - Problem initializing JTAG_BUFIN_EN_L -> off :: Timeout waiting for response.
2016-08-17 08:22:52,325 - Servod - ERROR - Problem initializing fw_wp_en -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,331 - Servod - ERROR - Problem initializing tp1 -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,338 - Servod - ERROR - Problem initializing cold_reset -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,348 - Servod - ERROR - Problem initializing pwr_button -> release :: [Errno 5] Input/output error
2016-08-17 08:22:52,358 - Servod - ERROR - Problem initializing warm_reset -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,363 - Servod - ERROR - Problem initializing rec_mode -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,366 - Servod - ERROR - Problem initializing fw_up -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,368 - Servod - ERROR - Problem initializing lid_open -> yes :: [Errno 5] Input/output error
2016-08-17 08:22:52,373 - Servod - ERROR - Problem initializing pch_disable -> off :: [Errno 5] Input/output error
2016-08-17 08:22:52,376 - Servod - ERROR - Problem initializing tp2 -> off :: [Errno 5] Input/output error
2016-08-17 08:22:55,745 - Servod - ERROR - Problem initializing uart1_enable -> on :: Timeout waiting for response.
2016-08-17 08:22:58,765 - Servod - ERROR - Problem initializing servo_jtag_trst -> off :: Timeout waiting for response.
2016-08-17 08:23:01,787 - Servod - ERROR - Problem initializing spi1_buf_en -> off :: Timeout waiting for response.
2016-08-17 08:23:04,806 - Servod - ERROR - Problem initializing spi2_buf_en -> off :: Timeout waiting for response.
2016-08-17 08:23:07,831 - Servod - ERROR - Problem initializing uart2_enable -> on :: Timeout waiting for response.
2016-08-17 08:23:10,851 - Servod - ERROR - Problem initializing spi1_vref -> off :: Timeout waiting for response.
2016-08-17 08:23:13,872 - Servod - ERROR - Problem initializing spi2_vref -> off :: Timeout waiting for response.
2016-08-17 08:23:16,893 - Servod - ERROR - Problem initializing servo_jtag_trst_dir -> off :: Timeout waiting for response.
2016-08-17 08:23:19,914 - Servod - ERROR - Problem initializing servo_jtag_tdi_dir -> off :: Timeout waiting for response.
2016-08-17 08:23:22,934 - Servod - ERROR - Problem initializing gpio_expander_reset -> off :: Timeout waiting for response.
2016-08-17 08:23:25,954 - Servod - ERROR - Problem initializing uart3_on_spi1 -> off :: Timeout waiting for response.

....
....

Comment 3 by waihong@chromium.org, Aug 17 2016

Probably consider to run the suite using the moblab setup or putting it in a standard lab. The lab infra can handle this kind of failures, like resetting DUT, recovering the firmware, etc.