2018-11-12 18:28:48,673 - Servod - DEBUG - servo_server.py:813:set - name(image_usbkey_pwr) wr_val(off)
2018-11-12 18:28:48,674 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:48,676 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map onoff
2018-11-12 18:28:48,677 - tca6416 - DEBUG - tca6416.py:99:set -
2018-11-12 18:28:48,678 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:48,679 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:48,679 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2], read_count=1)
2018-11-12 18:28:48,685 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [160])
2018-11-12 18:28:48,687 - I2cReg - DEBUG - i2c_reg.py:108:_write_reg -
2018-11-12 18:28:48,688 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:48,689 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2, 128], read_count=1)
2018-11-12 18:28:48,696 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:48,697 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:48,698 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:48,700 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[6], read_count=1)
2018-11-12 18:28:48,707 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:50,713 - Servod - DEBUG - servo_server.py:813:set - name(image_usbkey_direction) wr_val(dut_sees_usbkey)
2018-11-12 18:28:50,714 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:50,716 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map usbkey
2018-11-12 18:28:50,719 - usbImageManager - DEBUG - hw_driver.py:93:set - logical_value = 1
2018-11-12 18:28:50,721 - Servod - DEBUG - servo_server.py:813:set - name(image_usbkey_pwr) wr_val(off)
2018-11-12 18:28:50,721 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:50,724 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map onoff
2018-11-12 18:28:50,726 - tca6416 - DEBUG - tca6416.py:99:set -
2018-11-12 18:28:50,727 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:50,728 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:50,731 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2], read_count=1)
2018-11-12 18:28:50,739 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [128])
2018-11-12 18:28:50,740 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg - 0x18d1:501a
2018-11-12 18:28:50,741 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:50,745 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[6], read_count=1)
2018-11-12 18:28:50,750 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:52,753 - Servod - DEBUG - servo_server.py:813:set - name(image_usbkey_mux) wr_val(1)
2018-11-12 18:28:52,753 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:52,754 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map usbkey
2018-11-12 18:28:52,755 - tca6416 - DEBUG - tca6416.py:99:set -
2018-11-12 18:28:52,756 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:52,757 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:52,758 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2], read_count=1)
2018-11-12 18:28:52,762 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [128])
2018-11-12 18:28:52,764 - I2cReg - DEBUG - i2c_reg.py:108:_write_reg -
2018-11-12 18:28:52,765 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:52,765 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2, 136], read_count=1)
2018-11-12 18:28:52,772 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:52,773 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:52,774 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:52,776 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[6], read_count=1)
2018-11-12 18:28:52,785 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:54,788 - Servod - DEBUG - servo_server.py:813:set - name(image_usbkey_pwr) wr_val(on)
2018-11-12 18:28:54,790 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:54,791 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map onoff
2018-11-12 18:28:54,793 - tca6416 - DEBUG - tca6416.py:99:set -
2018-11-12 18:28:54,793 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:54,794 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:54,795 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2], read_count=1)
2018-11-12 18:28:54,800 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [136])
2018-11-12 18:28:54,801 - I2cReg - DEBUG - i2c_reg.py:108:_write_reg -
2018-11-12 18:28:54,802 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:54,802 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2, 168], read_count=1)
2018-11-12 18:28:54,808 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:54,811 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:54,814 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:54,815 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[6], read_count=1)
2018-11-12 18:28:54,824 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:54,826 - Servod - DEBUG - servo_server.py:754:get - name(image_usbkey_mux)
2018-11-12 18:28:54,826 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:54,827 - tca6416 - DEBUG - tca6416.py:77:get -
2018-11-12 18:28:54,829 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:54,830 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:54,831 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[0], read_count=1)
2018-11-12 18:28:54,838 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [168])
2018-11-12 18:28:54,839 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map usbkey
2018-11-12 18:28:54,840 - Servod - DEBUG - servo_server.py:766:get - image_usbkey_mux = dut_sees_usbkey
2018-11-12 18:28:56,848 - Servod - DEBUG - servo_server.py:813:set - name(image_usbkey_pwr) wr_val(on)
2018-11-12 18:28:56,849 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:56,851 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map onoff
2018-11-12 18:28:56,852 - tca6416 - DEBUG - tca6416.py:99:set -
2018-11-12 18:28:56,852 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:56,854 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:56,854 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2], read_count=1)
2018-11-12 18:28:56,861 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [168])
2018-11-12 18:28:56,862 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:56,863 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:56,865 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[6], read_count=1)
2018-11-12 18:28:56,872 - Si2c - DEBUG - stm32i2c.py:130:_raw_wr_rd - Si2c.wr_rd result 0x0000, read array('B', [0])
2018-11-12 18:28:56,880 - Servod - DEBUG - servo_server.py:813:set - name(power_state) wr_val(rec)
2018-11-12 18:28:56,881 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
)018-11-12 18:28:56,881 - Servod - DEBUG - servo_server.py:813:set - name(ec_uart_cmd) wr_val(
2018-11-12 18:28:56,883 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:56,885 - uart - DEBUG - hw_driver.py:93:set - logical_value =
2018-11-12 18:28:56,885 - EC3PO Interface - DEBUG - ec3po_interface.py:216:get_command_lock - acquire lock for /dev/pts/18: True
2018-11-12 18:28:56,890 - EC3PO.Console - DEBUG - console.py:904:StartLoop - /dev/pts/17 - Input from interface: , locked:True
2018-11-12 18:28:56,895 - EC3PO.Interpreter - DEBUG - interpreter.py:320:SendCmdToEC - /dev/pts/13 - Removing EC UART from writers.
2018-11-12 18:28:56,900 - EC3PO.Console - DEBUG - console.py:904:StartLoop - /dev/pts/17 - Input from interface: , locked:True
2018-11-12 18:28:56,905 - Suart - DEBUG - stm32uart.py:240:get_pty -
2018-11-12 18:28:56,906 - Suart - DEBUG - stm32uart.py:124:run_tx_thread - tx /dev/pts/13: [Errno 19] No such device (it may have been disconnected)
2018-11-12 18:28:56,907 - Suart - ERROR - stm32uart.py:127:run_tx_thread - USB disconnected 0x18d1:501a, servod failed.
2018-11-12 18:28:56,911 - uart - DEBUG - pty_driver.py:188:_issue_cmd_get_results - Sent cmds:
2018-11-12 18:28:56,912 - EC3PO.Interpreter - DEBUG - interpreter.py:320:SendCmdToEC - /dev/pts/13 - Removing EC UART from writers.
2018-11-12 18:28:56,912 - EC3PO Interface - DEBUG - ec3po_interface.py:221:release_command_lock - release lock for /dev/pts/18: False
2018-11-12 18:28:56,915 - Servod - DEBUG - servo_server.py:813:set - name(warm_reset) wr_val(on)
2018-11-12 18:28:56,915 - Servod - DEBUG - servo_server.py:550:_get_param_drv -
2018-11-12 18:28:56,916 - SystemConfig - DEBUG - system_config.py:358:_lookup - lookup of map onoff_i
2018-11-12 18:28:56,918 - tca6416 - DEBUG - tca6416.py:99:set -
2018-11-12 18:28:56,919 - I2cReg - DEBUG - i2c_reg.py:94:_read_reg -
2018-11-12 18:28:56,921 - I2cReg - DEBUG - i2c_reg.py:166:_wr_rd -
2018-11-12 18:28:56,922 - Si2c - DEBUG - stm32i2c.py:96:_raw_wr_rd - Si2c.wr_rd(port=0, slave_address=0x20, write_list=[2], read_count=1)
2018-11-12 18:28:56,929 - Si2c - ERROR - stm32i2c.py:117:_raw_wr_rd - USB disconnected 0x18d1:501a, servod failed.
Exception in thread Thread-16:
Traceback (most recent call last):
File "/usr/lib/python2.7/threading.py", line 801, in __bootstrap_inner
self.run()
File "/usr/lib/python2.7/threading.py", line 754, in run
self.__target(*self.__args, **self.__kwargs)
File "/root/.local/hdctools/build/servo/stm32uart.py", line 121, in run_tx_thread
self._susb._write_ep.write(r, self._susb.TIMEOUT_MS)
File "/root/.local/hdctools/lib/python2.7/site-packages/usb/core.py", line 287, in write
return self.device.write(self.bEndpointAddress, data, self.interface, timeout)
File "/root/.local/hdctools/lib/python2.7/site-packages/usb/core.py", line 633, in write
self.__get_timeout(timeout)
File "/root/.local/hdctools/lib/python2.7/site-packages/usb/backend/libusb1.py", line 771, in bulk_write
timeout)
File "/root/.local/hdctools/lib/python2.7/site-packages/usb/backend/libusb1.py", line 872, in __write
_check(retval)
File "/root/.local/hdctools/lib/python2.7/site-packages/usb/backend/libusb1.py", line 571, in _check
raise USBError(_str_error[ret], ret, _libusb_errno[ret])
USBError: [Errno 19] No such device (it may have been disconnected)