当客户端重新启动时,usbip 无法正常重新启动(从 docker 容器)

当客户端重新启动时,usbip 无法正常重新启动(从 docker 容器)

简短版本:在 Hyper-V VM 中运行 ubuntu 18.04.02 作为 usbip 客户端,在树莓派上运行 ubuntu 18.04 作为 usb 服务器。 Hyper-V VM 在 Docker 容器中运行 Home Assistant(如 hass.io)。当Hyper-V虚拟机重新启动时,有时,usbip服务无法重新连接到rPi的服务器端,直到rPi的usbip服务重新启动。

看来只有当 Hyper-V VM 从(--privileged)docker 容器内部重新启动时才会发生这种情况;如果从 ubuntu shell 重新启动,则它可以工作。

两个客户端都使用 linux-tools-generic 中的 usbip(不是之前的独立包),并标识为版本 2。我已将两者打包在一个服务中,服务器端作为类型分叉运行,客户端作为一次性运行。在两者的新启动上,它们都工作得很好。

以下是无法连接的客户端 (Hyper-V) 重新启动的日志记录(启用调试)。对长度表示歉意,已经删减了不少,但不确定剩下的内容是相关的。

当一切正常时,这是来自客户端的,您可以看到附加的远程端口:

root@ha:~# usbip port
Imported USB devices
====================
Port 00: <Port in Use> at Full Speed(12Mbps)
       Cygnal Integrated Products, Inc. : unknown product (10c4:8a2a)
       1-1 -> usbip://192.168.132.100:3240/1-1.2
           -> remote bus/dev 001/004

从 Hyper-V(usbip 客户端)端的 docker 重新启动,这是关闭时的日志:

May  2 13:07:04 ha NetworkManager[1181]: <info>  [1556802424.0981] device changed (path: /sys/devices/LNXSYSTM:00/LNXSYBUS:00/ACPI0004:00/VMBUS:00/f8091f75-727b-47ed-85fd-ce642aa4be61/net/eth0, iface: eth0)
May  2 13:07:04 ha ModemManager[964]: <info>  (tty/ttyUSB1): released by modem /sys/devices/platform/vhci_hcd.0/usb1/1-1
May  2 13:07:04 ha ModemManager[964]: <warn>  [plugin manager] task 0,ttyUSB1: error when checking support with plugin 'Iridium': 'Operation was cancelled'
May  2 13:07:04 ha ModemManager[964]: <warn>  [plugin manager] task 0,ttyUSB1: failed: Operation was cancelled
May  2 13:07:04 ha NetworkManager[1181]: <info>  [1556802424.1522] device changed (path: /sys/devices/virtual/net/docker0, iface: docker0)

这是来自服务器(rPi usbip 服务器)端的相同关闭信息;请注意,rPi 并未关闭,这只是对 Hyper-V 关闭的响应(或者更准确地说,我认为这些只是例行公事,似乎对 Hyper-V 关闭没有真正的响应,除非心跳是,但是无论如何,它们确实会定期出现):

May  2 13:06:56 ubuntu kernel: [41155.172199] usbip-host 1-1.2: endpoint 0 is stalled
May  2 13:06:56 ubuntu kernel: [41155.176078] usbip-host 1-1.2: endpoint 0 is stalled
May  2 13:07:03 ubuntu usbipd: usbipd: debug: usbipd.c:573:[do_standalone_mode] heartbeat timeout on ppoll()

重新启动后,Hyper-V 会恢复此状态

May  2 13:11:27 ha kernel: [    2.810394] systemd[1]: Set hostname to <ha>.
May  2 13:11:27 ha kernel: [    2.977418] systemd[1]: /lib/systemd/system/usbip.service:9: Ignoring unknown escape sequences: "/usr/lib/linux-tools/$(uname -r)/usbip detach --port=$(/usr/lib/linux-tools/$(uname -r)/usbip port | grep '<Port in Use>' | sed -E 's/^Port ([0-9][0-9]).*/\1/')"

注意:上面的行来自服务定义的 ExecStop 部分——它如何在服务启动之前在启动时运行不确定,但我认为这没有任何作用。我认为出现这个错误是因为(此时)没有端口可供查找和分离。

May  2 13:11:28 ha sh[1380]: usbip: error: recv op_common
May  2 13:11:28 ha sh[1380]: usbip: error: query
May  2 13:11:28 ha systemd[1]: Starting Docker Application Container Engine...
May  2 13:11:28 ha systemd[1]: usbip.service: Main process exited, code=exited, status=1/FAILURE
May  2 13:11:28 ha systemd[1]: usbip.service: Failed with result 'exit-code'.
May  2 13:11:28 ha systemd[1]: Failed to start usbip client.
May  2 13:11:28 ha systemd[1]: Started Permit User Sessions.

此故障导致服务无法启动,并且也不会手动启动(相同错误见下文)。此时,客户端可以看到远程设备,但无法连接到它,如本手动示例所示:

root@ha:~# usbip list -r zwave
Exportable USB devices
======================
 - zwave
      1-1.2: Cygnal Integrated Products, Inc. : unknown product (10c4:8a2a)
           : /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2
           : (Defined at Interface level) (00/00/00)
           :  0 - Vendor Specific Class / unknown subclass / unknown protocol (ff/00/00)
           :  1 - Vendor Specific Class / unknown subclass / unknown protocol (ff/00/00)

root@ha:~# usbip port
Imported USB devices
====================
root@ha:~# usbip attach -r zwave -b 1-1.2
usbip: error: recv op_common
usbip: error: query

但在服务器 (rPi) 上,当它尝试连接时,对上述命令的响应显示以下内容。请注意,客户端首先执行列表以获取总线 id,然后进行附加,因此您会看到列表的连接,然后是附加失败。

May  2 13:11:28 ubuntu usbipd: usbipd: debug: usbipd.c:568:[do_standalone_mode] read event on fd[0]=4
May  2 13:11:28 ubuntu usbipd: usbipd: info: connection from 192.168.132.254:34686
May  2 13:11:28 ubuntu usbipd: usbipd: info: received request: 0x8005(6)
May  2 13:11:28 ubuntu usbipd: usbipd: info: exportable devices: 1
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:91:[dump_usb_device] path                 = /sys/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.2
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:92:[dump_usb_device] busid                = 1-1.2
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:98:[dump_usb_device] Device(C/SC/P)       = (Defined at Interface level) (00/00/00)
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:100:[dump_usb_device] bcdDevice            = 100
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:105:[dump_usb_device] Vendor/Product       = unknown vendor : unknown product (10c4:8a2a)
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:107:[dump_usb_device] bNumConfigurations   = 1
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:108:[dump_usb_device] bNumInterfaces       = 2
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:111:[dump_usb_device] speed                = Full Speed(12Mbps)
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:113:[dump_usb_device] busnum               = 1
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:114:[dump_usb_device] devnum               = 4
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:84:[dump_usb_interface] Interface(C/SC/P)    = unknown class / unknown subclass / unknown protocol (ff/00/00)
May  2 13:11:28 ubuntu usbipd: libusbip: debug: usbip_common.c:84:[dump_usb_interface] Interface(C/SC/P)    = unknown class / unknown subclass / unknown protocol (ff/00/00)
May  2 13:11:28 ubuntu usbipd: usbipd: info: request 0x8005(6): complete
May  2 13:11:28 ubuntu usbipd: usbipd: debug: usbipd.c:568:[do_standalone_mode] read event on fd[0]=4
May  2 13:11:28 ubuntu usbipd: usbipd: info: connection from 192.168.132.254:34688
May  2 13:11:28 ubuntu usbipd: usbipd: info: received request: 0x8003(6)
May  2 13:11:28 ubuntu usbipd: usbipd: info: found requested device: 1-1.2
May  2 13:11:28 ubuntu usbipd: usbip: debug: usbip_host_common.c:233:[usbip_export_device] device not available: 1-1.2
May  2 13:11:28 ubuntu usbipd: usbip: debug: usbip_host_common.c:239:[usbip_export_device] status SDEV_ST_USED
May  2 13:11:28 ubuntu usbipd: usbipd: debug: usbipd.c:152:[recv_request_import] import request busid 1-1.2: failed
May  2 13:11:28 ubuntu usbipd: usbipd: info: request 0x8003(6): failed

上面的奇怪之处在于,它似乎说该设备在那里,但随后又说不可用,且状态为 SDEV_ST_USED,就好像它正在使用并以某种方式保留一样(好像它没有提前发布?)。

再说一遍,有时(通过推断,但不确定 ubuntu shell 何时重新启动,而不是 docker 导致 ubuntu 重新启动)它可以正常工作。

请注意,rPi 服务会继续运行,因此不会自动重启;连接失败而不是服务失败。首先手动重新启动 rPi 服务器,然后重新启动 HyperV VM 客户端,使其正常工作。我可以在服务定义中自动重新启动客户端,但这没有什么好处,因为它需要重新启动 rPi usbip 服务才能清除问题。

是的,简短的答案是记住始终从 ubuntu 而不是 docker 容器重新启动。

但是……有更强有力的答案吗?是否存在某些配置或设置问题可能会阻止服务器端正确清理?

我想理论上我可以编写客户端重新启动脚本来强制远程重新启动服务器(并等待其准备好),但这似乎非常脆弱。

有什么见解吗?

附言。我应该注意到,相反的情况也是一个问题 - 如果我重新启动 rPi 上的 usbip 服务,客户端(Hyper-V VM)会认为它仍然处于连接状态,但无法工作,并且也需要重新启动。这问题不大,因为 rPi 服务器很少需要重新启动,而我正在 Home Assistant 软件上进行开发,并且它经常重新启动。但根本问题是相似的——重启一端可能会破坏另一端。

相关内容