Bug #1988504 “r8152 driver no longer releases USB NIC for VM pas...” : Bugs : libvirt package : Ubuntu

Revision history for this message

Christian Ehrhardt  (paelzer) wrote on 2022-09-08:

#1

Hi Rolf,
I do not have a USB network card around to try the same over here but I've asked a few friends if they could. While not able to recreate let me ask a few things to get this started ...

1. you mention that "given an IP by the host" which clearly indicates it isn't fully passed through (or failing at doing so and given back). You posted the guest dmesg afaics, it might be useful to look at what the host think is right/wrong while you try to do this.
Could you try to gather `sudo dmesg -w`, `sudo journalctl -f` and `sudo tail -f /var/log/libvirt/qemu/<guestname>.log` from when you try to attach it?

2. How do you issue and configure the attach command?
Do you use virt-manager or an XML + virsh or anything else?
If so how is your guest config as well as the one for the device to pass look like?

Changed in libvirt (Ubuntu):
status:	New → Incomplete

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-09-08:

#2

Download full text (26.5 KiB)

Hi Christian,

here's the requested info. The VM is Ubuntu 22.04 in this case.

> Could you try to gather `sudo dmesg -w`, `sudo journalctl -f` and `sudo tail -f /var/log/libvirt/qemu/<guestname>.log` from when you try to attach it?

I plugged in the USB network card, then attached it to the VM,then plugged in a network cable and removed it again. In this case, the dmesg output of the VM didn't show an error, but the outcome is the same. Other times it often gives the "can't set config #2, error -32" error from above.

On host:
sudo dmesg -w

[ 2828.582191] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2831.585497] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2834.585584] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2837.589359] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2840.589631] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2843.589702] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2843.827413] usb 2-3.4: new SuperSpeed USB device number 6 using xhci_hcd
[ 2843.852217] usb 2-3.4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[ 2843.852226] usb 2-3.4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[ 2843.852229] usb 2-3.4: Product: Thinkpad USB LAN
[ 2843.852231] usb 2-3.4: Manufacturer: Lenovo
[ 2843.852233] usb 2-3.4: SerialNumber: 1C6955000000
[ 2843.939781] usb 2-3.4: reset SuperSpeed USB device number 6 using xhci_hcd
[ 2843.986357] r8152 2-3.4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 2844.016984] r8152 2-3.4:1.0 eth0: v1.12.12
[ 2844.636625] r8152 2-3.4:1.0 enx3c18a01c6955: renamed from eth0
[ 2846.593901] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2849.594001] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2852.640938] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2855.617820] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2858.617880] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2861.029282] audit: type=1400 audit(1662629782.512:114): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-298acbf4-0ef2-45eb-84b9-01754fced637" pid=12934 comm="apparmor_parser"
[ 2861.106273] r8152 2-3.4:1.0 enx3c18a01c6955: Stop submitting intr, status -108
[ 2861.601784] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2861.691979] usb 2-3.4: reset SuperSpeed USB device number 6 using xhci_hcd
[ 2861.750606] r8152 2-3.4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 2861.781394] r8152 2-3.4:1.0 eth0: v1.12.12
[ 2861.826719] r8152 2-3.4:1.0 enx3c18a01c6955: renamed from eth0
[ 2861.843859] usb 2-3.4: usbfs: interface 0 claimed by r8152 while 'qemu-system-x86' sets config #1
[ 2864.621915] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2867.622172] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lock...

Hi Christian,

here's the requested info. The VM is Ubuntu 22.04 in this case.

> Could you try to gather `sudo dmesg -w`, `sudo journalctl -f` and `sudo tail -f /var/log/libvirt/qemu/<guestname>.log` from when you try to attach it?

I plugged in the USB network card, then attached it to the VM,then plugged in a network cable and removed it again. In this case, the dmesg output of the VM didn't show an error, but the outcome is the same. Other times it often gives the "can't set config #2, error -32" error from above.

On host:
sudo dmesg -w

[ 2828.582191] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2831.585497] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2834.585584] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2837.589359] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2840.589631] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2843.589702] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2843.827413] usb 2-3.4: new SuperSpeed USB device number 6 using xhci_hcd
[ 2843.852217] usb 2-3.4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[ 2843.852226] usb 2-3.4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[ 2843.852229] usb 2-3.4: Product: Thinkpad USB LAN
[ 2843.852231] usb 2-3.4: Manufacturer: Lenovo
[ 2843.852233] usb 2-3.4: SerialNumber: 1C6955000000
[ 2843.939781] usb 2-3.4: reset SuperSpeed USB device number 6 using xhci_hcd
[ 2843.986357] r8152 2-3.4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 2844.016984] r8152 2-3.4:1.0 eth0: v1.12.12
[ 2844.636625] r8152 2-3.4:1.0 enx3c18a01c6955: renamed from eth0
[ 2846.593901] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2849.594001] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2852.640938] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2855.617820] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2858.617880] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2861.029282] audit: type=1400 audit(1662629782.512:114): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-298acbf4-0ef2-45eb-84b9-01754fced637" pid=12934 comm="apparmor_parser"
[ 2861.106273] r8152 2-3.4:1.0 enx3c18a01c6955: Stop submitting intr, status -108
[ 2861.601784] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2861.691979] usb 2-3.4: reset SuperSpeed USB device number 6 using xhci_hcd
[ 2861.750606] r8152 2-3.4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 2861.781394] r8152 2-3.4:1.0 eth0: v1.12.12
[ 2861.826719] r8152 2-3.4:1.0 enx3c18a01c6955: renamed from eth0
[ 2861.843859] usb 2-3.4: usbfs: interface 0 claimed by r8152 while 'qemu-system-x86' sets config #1
[ 2864.621915] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2867.622172] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2870.622045] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2873.629192] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2876.626210] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2878.965132] IPv6: ADDRCONF(NETDEV_CHANGE): enx3c18a01c6955: link becomes ready
[ 2878.965598] r8152 2-3.4:1.0 enx3c18a01c6955: carrier on
[ 2879.626125] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2882.625962] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2885.630090] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2888.629865] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2890.429247] Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
[ 2891.630360] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2894.630236] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2895.417700] r8152 2-3.4:1.0 enx3c18a01c6955: carrier off
[ 2897.630247] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2900.630140] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2903.634494] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2906.634384] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2909.634448] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 2912.634459] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7

sudo tail -f /var/log/libvirt/qemu/ubuntu22.log

2022-09-08T09:36:23.331702Z qemu-system-x86_64: libusb_release_interface: -99 [OTHER]
2022-09-08T09:36:23.331773Z qemu-system-x86_64: libusb_release_interface: -99 [OTHER]
2022-09-08T09:36:23.331793Z qemu-system-x86_64: libusb_set_configuration: -6 [BUSY]

sudo journalctl -f

Sep 08 11:35:50 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:35:53 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:35:56 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:35:59 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:02 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:05 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:05 suki kernel: usb 2-3.4: new SuperSpeed USB device number 6 using xhci_hcd
Sep 08 11:36:05 suki kernel: usb 2-3.4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
Sep 08 11:36:05 suki kernel: usb 2-3.4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
Sep 08 11:36:05 suki kernel: usb 2-3.4: Product: Thinkpad USB LAN
Sep 08 11:36:05 suki kernel: usb 2-3.4: Manufacturer: Lenovo
Sep 08 11:36:05 suki kernel: usb 2-3.4: SerialNumber: 1C6955000000
Sep 08 11:36:05 suki kernel: usb 2-3.4: reset SuperSpeed USB device number 6 using xhci_hcd
Sep 08 11:36:05 suki kernel: r8152 2-3.4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 08 11:36:05 suki NetworkManager[1281]: <info>  [1662629765.5066] manager: (eth0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/14)
Sep 08 11:36:05 suki kernel: r8152 2-3.4:1.0 eth0: v1.12.12
Sep 08 11:36:05 suki mtp-probe[12882]: checking bus 2, device 6: "/sys/devices/pci0000:00/0000:00:0d.0/usb2/2-3/2-3.4"
Sep 08 11:36:05 suki mtp-probe[12882]: bus: 2, device: 6 was not an MTP device
Sep 08 11:36:06 suki mtp-probe[12910]: checking bus 2, device 6: "/sys/devices/pci0000:00/0000:00:0d.0/usb2/2-3/2-3.4"
Sep 08 11:36:06 suki mtp-probe[12910]: bus: 2, device: 6 was not an MTP device
Sep 08 11:36:06 suki systemd-udevd[12909]: Using default interface naming scheme 'v249'.
Sep 08 11:36:06 suki kernel: r8152 2-3.4:1.0 enx3c18a01c6955: renamed from eth0
Sep 08 11:36:06 suki NetworkManager[1281]: <info>  [1662629766.1681] device (eth0): interface index 15 renamed iface from 'eth0' to 'enx3c18a01c6955'
Sep 08 11:36:06 suki NetworkManager[1281]: <info>  [1662629766.1735] device (enx3c18a01c6955): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Sep 08 11:36:06 suki systemd-udevd[12880]: Using default interface naming scheme 'v249'.
Sep 08 11:36:06 suki NetworkManager[1281]: <info>  [1662629766.1805] settings: (enx3c18a01c6955): created default wired connection 'Kabelgebundene Verbindung 2'
Sep 08 11:36:08 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:08 suki ModemManager[1513]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:0d.0/usb2/2-3/2-3.4': not supported by any plugin
Sep 08 11:36:11 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:14 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:17 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:20 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:22 suki audit[12934]: AVC apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-298acbf4-0ef2-45eb-84b9-01754fced637" pid=12934 comm="apparmor_parser"
Sep 08 11:36:22 suki kernel: audit: type=1400 audit(1662629782.512:114): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-298acbf4-0ef2-45eb-84b9-01754fced637" pid=12934 comm="apparmor_parser"
Sep 08 11:36:22 suki kernel: r8152 2-3.4:1.0 enx3c18a01c6955: Stop submitting intr, status -108
Sep 08 11:36:22 suki NetworkManager[1281]: <info>  [1662629782.6390] device (enx3c18a01c6955): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Sep 08 11:36:23 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:23 suki kernel: usb 2-3.4: reset SuperSpeed USB device number 6 using xhci_hcd
Sep 08 11:36:23 suki kernel: r8152 2-3.4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 08 11:36:23 suki NetworkManager[1281]: <info>  [1662629783.2711] manager: (eth0): new Ethernet device (/org/freedesktop/NetworkManager/Devices/15)
Sep 08 11:36:23 suki kernel: r8152 2-3.4:1.0 eth0: v1.12.12
Sep 08 11:36:23 suki systemd-udevd[12936]: Using default interface naming scheme 'v249'.
Sep 08 11:36:23 suki kernel: r8152 2-3.4:1.0 enx3c18a01c6955: renamed from eth0
Sep 08 11:36:23 suki kernel: usb 2-3.4: usbfs: interface 0 claimed by r8152 while 'qemu-system-x86' sets config #1
Sep 08 11:36:23 suki NetworkManager[1281]: <info>  [1662629783.3444] device (eth0): interface index 16 renamed iface from 'eth0' to 'enx3c18a01c6955'
Sep 08 11:36:23 suki NetworkManager[1281]: <info>  [1662629783.3561] device (enx3c18a01c6955): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Sep 08 11:36:23 suki systemd-udevd[12937]: Using default interface naming scheme 'v249'.
Sep 08 11:36:23 suki NetworkManager[1281]: <info>  [1662629783.3732] settings: (enx3c18a01c6955): created default wired connection 'Kabelgebundene Verbindung 2'
Sep 08 11:36:25 suki ModemManager[1513]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:0d.0/usb2/2-3/2-3.4': not supported by any plugin
Sep 08 11:36:26 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:29 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:32 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:35 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:38 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4535] device (enx3c18a01c6955): carrier: link connected
Sep 08 11:36:40 suki kernel: IPv6: ADDRCONF(NETDEV_CHANGE): enx3c18a01c6955: link becomes ready
Sep 08 11:36:40 suki kernel: r8152 2-3.4:1.0 enx3c18a01c6955: carrier on
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4561] device (enx3c18a01c6955): state change: unavailable -> disconnected (reason 'carrier-changed', sys-iface-state: 'managed')
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4579] policy: auto-activating connection 'Kabelgebundene Verbindung 2' (a04f36ba-8f04-3915-84bb-c5d6bf69f768)
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4588] device (enx3c18a01c6955): Activation: starting connection 'Kabelgebundene Verbindung 2' (a04f36ba-8f04-3915-84bb-c5d6bf69f768)
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4590] device (enx3c18a01c6955): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4597] device (enx3c18a01c6955): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4604] device (enx3c18a01c6955): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Sep 08 11:36:40 suki NetworkManager[1281]: <info>  [1662629800.4613] dhcp4 (enx3c18a01c6955): activation: beginning transaction (timeout in 45 seconds)
Sep 08 11:36:40 suki avahi-daemon[1277]: Joining mDNS multicast group on interface enx3c18a01c6955.IPv6 with address fe80::6356:ef4f:259c:d480.
Sep 08 11:36:40 suki avahi-daemon[1277]: New relevant interface enx3c18a01c6955.IPv6 for mDNS.
Sep 08 11:36:40 suki avahi-daemon[1277]: Registering new address record for fe80::6356:ef4f:259c:d480 on enx3c18a01c6955.*.
Sep 08 11:36:41 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:41 suki goa-daemon[3534]: secret_password_lookup_sync() returned NULL
Sep 08 11:36:43 suki NetworkManager[1281]: <info>  [1662629803.5344] dhcp4 (enx3c18a01c6955): state changed new lease, address=172.26.180.10
Sep 08 11:36:43 suki avahi-daemon[1277]: Joining mDNS multicast group on interface enx3c18a01c6955.IPv4 with address 172.26.180.10.
Sep 08 11:36:43 suki avahi-daemon[1277]: New relevant interface enx3c18a01c6955.IPv4 for mDNS.
Sep 08 11:36:43 suki avahi-daemon[1277]: Registering new address record for 172.26.180.10 on enx3c18a01c6955.IPv4.
Sep 08 11:36:43 suki dbus-daemon[1280]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=1281 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Sep 08 11:36:43 suki NetworkManager[1281]: <info>  [1662629803.5398] device (enx3c18a01c6955): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Sep 08 11:36:43 suki systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 08 11:36:43 suki dbus-daemon[1280]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 08 11:36:43 suki systemd[1]: Started Network Manager Script Dispatcher Service.
Sep 08 11:36:43 suki NetworkManager[1281]: <info>  [1662629803.5846] device (enx3c18a01c6955): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Sep 08 11:36:43 suki NetworkManager[1281]: <info>  [1662629803.5849] device (enx3c18a01c6955): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Sep 08 11:36:43 suki NetworkManager[1281]: <info>  [1662629803.5876] device (enx3c18a01c6955): Activation: successful, device activated.
Sep 08 11:36:43 suki systemd-resolved[1206]: enx3c18a01c6955: Bus client set default route setting: yes
Sep 08 11:36:43 suki NetworkManager[1281]: <warn>  [1662629803.5917] dns-sd-resolved[2d203986f6885faf]: send-updates SetLinkDomains@10 failed: GDBus.Error:org.freedesktop.resolve1.NoSuchLink: Link 10 not known
Sep 08 11:36:43 suki systemd-resolved[1206]: enx3c18a01c6955: Bus client set DNS server list to: 172.26.180.95
Sep 08 11:36:43 suki systemd-resolved[1206]: Using degraded feature set UDP instead of UDP+EDNS0 for DNS server 172.26.180.95.
Sep 08 11:36:43 suki goa-daemon[3534]: secret_password_lookup_sync() returned NULL
Sep 08 11:36:44 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:44 suki goa-daemon[3534]: secret_password_lookup_sync() returned NULL
Sep 08 11:36:45 suki goa-daemon[3534]: secret_password_lookup_sync() returned NULL
Sep 08 11:36:47 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:50 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:51 suki kernel: Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
Sep 08 11:36:51 suki rtkit-daemon[1941]: Supervising 11 threads of 4 processes of 1 users.
Sep 08 11:36:51 suki rtkit-daemon[1941]: Supervising 11 threads of 4 processes of 1 users.
Sep 08 11:36:53 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:53 suki systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Sep 08 11:36:56 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:36:56 suki kernel: r8152 2-3.4:1.0 enx3c18a01c6955: carrier off
Sep 08 11:36:59 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:37:02 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 11:37:02 suki NetworkManager[1281]: <info>  [1662629822.9036] device (enx3c18a01c6955): state change: activated -> unavailable (reason 'carrier-changed', sys-iface-state: 'managed')
Sep 08 11:37:02 suki NetworkManager[1281]: <info>  [1662629822.9316] dhcp4 (enx3c18a01c6955): canceled DHCP transaction
Sep 08 11:37:02 suki NetworkManager[1281]: <info>  [1662629822.9317] dhcp4 (enx3c18a01c6955): activation: beginning transaction (timeout in 45 seconds)
Sep 08 11:37:02 suki NetworkManager[1281]: <info>  [1662629822.9317] dhcp4 (enx3c18a01c6955): state changed no lease
Sep 08 11:37:02 suki avahi-daemon[1277]: Withdrawing address record for 172.26.180.10 on enx3c18a01c6955.
Sep 08 11:37:02 suki avahi-daemon[1277]: Leaving mDNS multicast group on interface enx3c18a01c6955.IPv4 with address 172.26.180.10.
Sep 08 11:37:02 suki avahi-daemon[1277]: Interface enx3c18a01c6955.IPv4 no longer relevant for mDNS.
Sep 08 11:37:02 suki avahi-daemon[1277]: Withdrawing address record for fe80::6356:ef4f:259c:d480 on enx3c18a01c6955.
Sep 08 11:37:02 suki avahi-daemon[1277]: Leaving mDNS multicast group on interface enx3c18a01c6955.IPv6 with address fe80::6356:ef4f:259c:d480.
Sep 08 11:37:02 suki avahi-daemon[1277]: Interface enx3c18a01c6955.IPv6 no longer relevant for mDNS.
Sep 08 11:37:02 suki systemd-resolved[1206]: enx3c18a01c6955: Bus client set default route setting: no
Sep 08 11:37:02 suki systemd-resolved[1206]: enx3c18a01c6955: Bus client reset DNS server list.
Sep 08 11:37:02 suki NetworkManager[1281]: <warn>  [1662629822.9653] dns-sd-resolved[2d203986f6885faf]: send-updates SetLinkDomains@10 failed: GDBus.Error:org.freedesktop.resolve1.NoSuchLink: Link 10 not known
Sep 08 11:37:02 suki dbus-daemon[1280]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.3' (uid=0 pid=1281 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Sep 08 11:37:03 suki systemd[1]: Starting Network Manager Script Dispatcher Service...
Sep 08 11:37:03 suki dbus-daemon[1280]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Sep 08 11:37:03 suki systemd[1]: Started Network Manager Script Dispatcher Service.

On VM:
sudo dmesg -w
[  999.325410] usb 1-4: USB disconnect, device number 3
[ 1073.696047] usb 1-4: new high-speed USB device number 4 using ehci-pci
[ 1073.854242] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x81 has invalid maxpacket 1024
[ 1073.854252] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x2 has invalid maxpacket 1024
[ 1073.854939] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x81 has invalid maxpacket 1024
[ 1073.854942] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x2 has invalid maxpacket 1024
[ 1073.856711] usb 1-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[ 1073.856717] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[ 1073.856720] usb 1-4: Product: Thinkpad USB LAN
[ 1073.856722] usb 1-4: Manufacturer: Lenovo
[ 1073.856724] usb 1-4: SerialNumber: 1C6955000000
[ 1074.091311] usbcore: registered new interface driver r8152
[ 1074.099216] usbcore: registered new interface driver cdc_ether

> 2. How do you issue and configure the attach command?

I'm attaching the device with virt-manager. The VM configuration looks like this:

<domain type="kvm">
  <name>ubuntu22</name>
  <uuid>298acbf4-0ef2-45eb-84b9-01754fced637</uuid>
  <metadata>
    <libosinfo:libosinfo xmlns:libosinfo="http://libosinfo.org/xmlns/libvirt/domain/1.0">
      <libosinfo:os id="http://ubuntu.com/ubuntu/20.04"/>
    </libosinfo:libosinfo>
  </metadata>
  <memory unit="KiB">8388608</memory>
  <currentMemory unit="KiB">8388608</currentMemory>
  <vcpu placement="static">4</vcpu>
  <os>
    <type arch="x86_64" machine="pc-q35-4.2">hvm</type>
    <boot dev="hd"/>
  </os>
  <features>
    <acpi/>
    <apic/>
    <vmport state="off"/>
  </features>
  <cpu mode="host-model" check="partial"/>
  <clock offset="utc">
    <timer name="rtc" tickpolicy="catchup"/>
    <timer name="pit" tickpolicy="delay"/>
    <timer name="hpet" present="no"/>
  </clock>
  <on_poweroff>destroy</on_poweroff>
  <on_reboot>restart</on_reboot>
  <on_crash>destroy</on_crash>
  <pm>
    <suspend-to-mem enabled="no"/>
    <suspend-to-disk enabled="no"/>
  </pm>
  <devices>
    <emulator>/usr/bin/qemu-system-x86_64</emulator>
    <disk type="file" device="disk">
      <driver name="qemu" type="qcow2"/>
      <source file="/var/lib/libvirt/images/ubuntu20.04.qcow2"/>
      <target dev="vda" bus="virtio"/>
      <address type="pci" domain="0x0000" bus="0x03" slot="0x00" function="0x0"/>
    </disk>
    <disk type="file" device="cdrom">
      <driver name="qemu" type="raw"/>
      <target dev="sda" bus="sata"/>
      <readonly/>
      <address type="drive" controller="0" bus="0" target="0" unit="0"/>
    </disk>
    <controller type="usb" index="0" model="ich9-ehci1">
      <address type="pci" domain="0x0000" bus="0x00" slot="0x1d" function="0x7"/>
    </controller>
    <controller type="usb" index="0" model="ich9-uhci1">
      <master startport="0"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x1d" function="0x0" multifunction="on"/>
    </controller>
    <controller type="usb" index="0" model="ich9-uhci2">
      <master startport="2"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x1d" function="0x1"/>
    </controller>
    <controller type="usb" index="0" model="ich9-uhci3">
      <master startport="4"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x1d" function="0x2"/>
    </controller>
    <controller type="sata" index="0">
      <address type="pci" domain="0x0000" bus="0x00" slot="0x1f" function="0x2"/>
    </controller>
    <controller type="pci" index="0" model="pcie-root"/>
    <controller type="pci" index="1" model="pcie-root-port">
      <model name="pcie-root-port"/>
      <target chassis="1" port="0x10"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x02" function="0x0" multifunction="on"/>
    </controller>
    <controller type="pci" index="2" model="pcie-root-port">
      <model name="pcie-root-port"/>
      <target chassis="2" port="0x11"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x02" function="0x1"/>
    </controller>
    <controller type="pci" index="3" model="pcie-root-port">
      <model name="pcie-root-port"/>
      <target chassis="3" port="0x12"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x02" function="0x2"/>
    </controller>
    <controller type="pci" index="4" model="pcie-root-port">
      <model name="pcie-root-port"/>
      <target chassis="4" port="0x13"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x02" function="0x3"/>
    </controller>
    <controller type="pci" index="5" model="pcie-root-port">
      <model name="pcie-root-port"/>
      <target chassis="5" port="0x14"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x02" function="0x4"/>
    </controller>
    <controller type="pci" index="6" model="pcie-root-port">
      <model name="pcie-root-port"/>
      <target chassis="6" port="0x15"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x02" function="0x5"/>
    </controller>
    <controller type="virtio-serial" index="0">
      <address type="pci" domain="0x0000" bus="0x02" slot="0x00" function="0x0"/>
    </controller>
    <interface type="network">
      <mac address="52:54:00:11:c0:f9"/>
      <source network="default"/>
      <model type="virtio"/>
      <address type="pci" domain="0x0000" bus="0x01" slot="0x00" function="0x0"/>
    </interface>
    <serial type="pty">
      <target type="isa-serial" port="0">
        <model name="isa-serial"/>
      </target>
    </serial>
    <console type="pty">
      <target type="serial" port="0"/>
    </console>
    <channel type="unix">
      <target type="virtio" name="org.qemu.guest_agent.0"/>
      <address type="virtio-serial" controller="0" bus="0" port="1"/>
    </channel>
    <channel type="spicevmc">
      <target type="virtio" name="com.redhat.spice.0"/>
      <address type="virtio-serial" controller="0" bus="0" port="2"/>
    </channel>
    <input type="tablet" bus="usb">
      <address type="usb" bus="0" port="1"/>
    </input>
    <input type="mouse" bus="ps2"/>
    <input type="keyboard" bus="ps2"/>
    <graphics type="spice" autoport="yes">
      <listen type="address"/>
      <image compression="off"/>
    </graphics>
    <sound model="ich9">
      <address type="pci" domain="0x0000" bus="0x00" slot="0x1b" function="0x0"/>
    </sound>
    <audio id="1" type="spice"/>
    <video>
      <model type="qxl" ram="65536" vram="65536" vgamem="16384" heads="1" primary="yes"/>
      <address type="pci" domain="0x0000" bus="0x00" slot="0x01" function="0x0"/>
    </video>
    <hostdev mode="subsystem" type="usb" managed="yes">
      <source>
        <vendor id="0x17ef"/>
        <product id="0x7205"/>
      </source>
      <address type="usb" bus="0" port="4"/>
    </hostdev>
    <redirdev bus="usb" type="spicevmc">
      <address type="usb" bus="0" port="2"/>
    </redirdev>
    <redirdev bus="usb" type="spicevmc">
      <address type="usb" bus="0" port="3"/>
    </redirdev>
    <memballoon model="virtio">
      <address type="pci" domain="0x0000" bus="0x04" slot="0x00" function="0x0"/>
    </memballoon>
    <rng model="virtio">
      <backend model="random">/dev/urandom</backend>
      <address type="pci" domain="0x0000" bus="0x05" slot="0x00" function="0x0"/>
    </rng>
  </devices>
</domain>

The XML of the attached device looks like this:

Revision history for this message

Christian Ehrhardt  (paelzer) wrote on 2022-09-08:

#3

Just to help others reading this "rpc-libvirtd: debugfs access is restricted" is bug 1957924 and a non critical (noise, but not breaking) issue. You can ignore any of these (at least that was the assumption so far.

In dmesg we have no usual suspects (apparmor denials for example:
We only see the device "coming back to the host" without much info about an issue.
Maybe this one:
usb 2-3.4: usbfs: interface 0 claimed by r8152 while 'qemu-system-x86' sets config #1

That is a conflict between the host r8152 driver and qemu.

In the libvirt log we see that libvirt fails because it can not set the config as being busy.
2022-09-08T09:36:23.331793Z qemu-system-x86_64: libusb_set_configuration: -6 [BUSY]

That could match to the above dmesg entry of a fight between host driver and qemu.

I do not know if the host changed behavior in how hard it hold onto this device.
But instead of hot-plugging it back and forth we could try releasing it from the host a bit more before attaching it to the guest.
Then you can try to move it to the guest and see if it works now.
(Of course if you need it in host and guest we will eventually need to sort out how to do this more smoothly).

So I wonder, if yo'd be ok (if you do not need the driver for something else) to try on the host to blacklist that driver.
0. blacklist on the host
$ echo "blacklist r8152" > /etc/modprobe.d/lp-1988504-avoid-hostdrivers.conf
$ echo "blacklist cdc_ether" >> /etc/modprobe.d/lp-1988504-avoid-hostdrivers.conf
# not sure if this is loaded by initramfs (surely not if unplugged) but to be sure
$ sudo update-initramfs -u
1. Unplug your USB network device
2. Reboot
3. Plug in your USB network
4. Check lsmod, it should not more have r8152 or cdc_ether loaded on the host
5. now start your guest
6. set up the log watches again
7. try to attach the USB dev

Let me know if that gets you any further

Revision history for this message

Christian Ehrhardt  (paelzer) wrote on 2022-09-08:

#4

A friend of mine reported that he sees the same behavior.
So whatever it is - it seems to be a general issue for this setup and not so much "your config".

Interested to hear back from your try what happens if the host properly leaves this device alone.

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-09-08:

#5

Download full text (3.9 KiB)

Thanks for the workaround. The VM is getting a an IP now, so the blacklisting works. See the logs below. It does only solve the problem partially for me, since I sometimes use the USB network card on the host, too (and sometimes more than one, mixed between host and VM).

This all used to work with Ubuntu 20.04 host, so it is a bug and regression.

Host:

journalctl -f
Sep 08 15:41:11 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:11 suki kernel: usb 2-1: reset SuperSpeed USB device number 2 using xhci_hcd
Sep 08 15:41:14 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:16 suki firefox.desktop[5274]: Unsupported modifier, resource creation failed.
Sep 08 15:41:16 suki firefox.desktop[5274]: XXX: resource creation failed
Sep 08 15:41:17 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:17 suki firefox.desktop[5274]: Unsupported modifier, resource creation failed.
Sep 08 15:41:17 suki firefox.desktop[5274]: XXX: resource creation failed
Sep 08 15:41:20 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:23 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restr

No log from sudo tail -f /var/log/libvirt/qemu/ubuntu22.log

dmesg -w:
[ 351.694209] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 354.698552] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 357.702326] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 360.702176] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 363.702654] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 366.702513] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 369.702080] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 372.706535] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 375.706651] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 377.947626] audit: type=1400 audit(1662644470.623:105): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-298acbf4-0ef2-45eb-84b9-01754fced637" pid=6651 comm="apparmor_parser"
[ 378.717833] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 378.848430] usb 2-1: reset SuperSpeed USB device number 2 using xhci_hcd
[ 381.718332] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[ 384.718034] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7

On VM:
dmesg -w:
[ 302.038735] usb 1-4: new high-speed USB device number 4 using ehci-pci
[ 302.196684] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x81 has invalid maxpacket 1024
[ 302.196689] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x2 has invalid maxpacket 1024
[ 302.197303] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x81 has invalid ma...

Thanks for the workaround. The VM is getting a an IP now, so the blacklisting works. See the logs below. It does only solve the problem partially for me, since I sometimes use the USB network card on the host, too (and sometimes more than one, mixed between host and VM).

This all used to work with Ubuntu 20.04 host, so it is a bug and regression.

Host:

journalctl -f
Sep 08 15:41:11 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:11 suki kernel: usb 2-1: reset SuperSpeed USB device number 2 using xhci_hcd
Sep 08 15:41:14 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:16 suki firefox.desktop[5274]: Unsupported modifier, resource creation failed.
Sep 08 15:41:16 suki firefox.desktop[5274]: XXX: resource creation failed
Sep 08 15:41:17 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:17 suki firefox.desktop[5274]: Unsupported modifier, resource creation failed.
Sep 08 15:41:17 suki firefox.desktop[5274]: XXX: resource creation failed
Sep 08 15:41:20 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
Sep 08 15:41:23 suki kernel: Lockdown: rpc-libvirtd: debugfs access is restr

No log from sudo tail -f /var/log/libvirt/qemu/ubuntu22.log

dmesg -w:
[  351.694209] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  354.698552] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  357.702326] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  360.702176] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  363.702654] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  366.702513] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  369.702080] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  372.706535] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  375.706651] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  377.947626] audit: type=1400 audit(1662644470.623:105): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-298acbf4-0ef2-45eb-84b9-01754fced637" pid=6651 comm="apparmor_parser"
[  378.717833] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  378.848430] usb 2-1: reset SuperSpeed USB device number 2 using xhci_hcd
[  381.718332] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7
[  384.718034] Lockdown: rpc-libvirtd: debugfs access is restricted; see man kernel_lockdown.7

On VM:
dmesg -w:
[  302.038735] usb 1-4: new high-speed USB device number 4 using ehci-pci
[  302.196684] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x81 has invalid maxpacket 1024
[  302.196689] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x2 has invalid maxpacket 1024
[  302.197303] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x81 has invalid maxpacket 1024
[  302.197306] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x2 has invalid maxpacket 1024
[  302.198819] usb 1-4: New USB device found, idVendor=17ef, idProduct=720c, bcdDevice=30.00
[  302.198824] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[  302.198826] usb 1-4: Product: Lenovo USB-C to LAN
[  302.198829] usb 1-4: Manufacturer: Lenovo
[  302.198831] usb 1-4: SerialNumber: D832B1000000
[  302.486728] usb 1-4: reset high-speed USB device number 4 using ehci-pci
[  302.729356] r8152 1-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[  302.771712] r8152 1-4:1.0 eth0: v1.12.12
[  302.872375] r8152 1-4:1.0 enx606d3cd832b1: renamed from eth0
[  304.552005] IPv6: ADDRCONF(NETDEV_CHANGE): enx606d3cd832b1: link becomes ready
[  304.554790] r8152 1-4:1.0 enx606d3cd832b1: carrier on

Revision history for this message

Christian Ehrhardt  (paelzer) wrote on 2022-09-08:

#6

Thanks for trying, I agree it is a bug/regression - but I'm not yet sure where exactly to point it to. Of the many involved components the two most involved here are libvirt and the kernel.

Would you be able to try this with either:
1. an older libvirt (hard to get onto the new system)
2. a newer libvirt on the old system (if you have a second comparable one you can use https://launchpad.net/~canonical-server/+archive/ubuntu/server-backports)
3. Trying an older kernel matching what 20.04 had - I assume you had the default being 5.4.0-26.30 (you might use https://kernel.ubuntu.com/~kernel-ppa/mainline/ to pick a 5.4 kernel)
4. On said olders system from #2 if you have it try a newer kernel through the HWE stack (https://wiki.ubuntu.com/Kernel/LTSEnablementStack)

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-09-08:

#7

I used linux-oem-5.14 before upgrading. I tried that kernel on 22.04, but it didn't solve the problem. I also tried linux-5.15 default and linux-oem-5.17 kernel. The bug did show with all of those kernel versions, so I guess it is a libvirt problem. I can try again and create some logs if that would help. I don't have a 20.04 system to try, at the moment.

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-09-15:

#8

Download full text (13.0 KiB)

I tested on an Ubuntu 20.04 maschine with a Debian VM. The logs show inserting the USB networking card, delegating, inserting the cable. The VM is getting an IP address after running a dhclient command.

Host:
Ubuntu 20.04.5 LTS
Linux airi 5.15.0-46-generic #49~20.04.1-Ubuntu SMP Thu Aug 4 19:15:44 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
libvirt0:amd64/focal-security 6.0.0-0ubuntu8.16 uptodate

VM:
Debian GNU/Linux 10
Linux management 4.19.0-21-amd64 #1 SMP Debian 4.19.249-2 (2022-06-30) x86_64 GNU/Linux

on Host:
dmesg -w
[ 774.246011] usb 2-4: new SuperSpeed USB device number 4 using xhci_hcd
[ 774.266707] usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[ 774.266726] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[ 774.266732] usb 2-4: Product: Thinkpad USB LAN
[ 774.266738] usb 2-4: Manufacturer: Lenovo
[ 774.266742] usb 2-4: SerialNumber: 1C6955000000
[ 774.294021] usbcore: registered new interface driver r8152
[ 774.301860] usbcore: registered new interface driver cdc_ether
[ 774.422616] usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
[ 774.469822] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 774.504631] r8152 2-4:1.0 eth0: v1.12.12
[ 774.538923] r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
[ 854.297055] audit: type=1400 audit(1663234104.465:129): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=29798 comm="apparmor_parser"
[ 854.977562] usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
[ 855.036675] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 855.070558] r8152 2-4:1.0 eth0: v1.12.12
[ 855.409642] usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd

journalctl -f
ep 15 11:27:01 airi CRON[27337]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:27:01 airi CRON[27338]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:27:01 airi CRON[27339]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:27:01 airi CRON[27340]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:27:01 airi CRON[27338]: pam_unix(cron:session): session closed for user rk
Sep 15 11:27:01 airi CRON[27337]: pam_unix(cron:session): session closed for user rk
Sep 15 11:27:04 airi kernel: usb 2-4: new SuperSpeed USB device number 4 using xhci_hcd
Sep 15 11:27:04 airi kernel: usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
Sep 15 11:27:04 airi kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
Sep 15 11:27:04 airi kernel: usb 2-4: Product: Thinkpad USB LAN
Sep 15 11:27:04 airi kernel: usb 2-4: Manufacturer: Lenovo
Sep 15 11:27:04 airi kernel: usb 2-4: SerialNumber: 1C6955000000
Sep 15 11:27:04 airi kernel: usbcore: registered new interface driver r8152
Sep 15 11:27:04 airi kernel: usbcore: registered new interface driver cdc_ether
Sep 15 11:27:04 airi kernel: usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
Se...

I tested on an Ubuntu 20.04 maschine with a Debian VM. The logs show inserting the USB networking card, delegating, inserting the cable. The VM is getting an IP address after running a dhclient command.

Host:
Ubuntu 20.04.5 LTS
Linux airi 5.15.0-46-generic #49~20.04.1-Ubuntu SMP Thu Aug 4 19:15:44 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux
libvirt0:amd64/focal-security 6.0.0-0ubuntu8.16 uptodate

VM:
Debian GNU/Linux 10
Linux management 4.19.0-21-amd64 #1 SMP Debian 4.19.249-2 (2022-06-30) x86_64 GNU/Linux

on Host:
dmesg -w
[  774.246011] usb 2-4: new SuperSpeed USB device number 4 using xhci_hcd
[  774.266707] usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[  774.266726] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[  774.266732] usb 2-4: Product: Thinkpad USB LAN
[  774.266738] usb 2-4: Manufacturer: Lenovo
[  774.266742] usb 2-4: SerialNumber: 1C6955000000
[  774.294021] usbcore: registered new interface driver r8152
[  774.301860] usbcore: registered new interface driver cdc_ether
[  774.422616] usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
[  774.469822] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[  774.504631] r8152 2-4:1.0 eth0: v1.12.12
[  774.538923] r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
[  854.297055] audit: type=1400 audit(1663234104.465:129): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=29798 comm="apparmor_parser"
[  854.977562] usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
[  855.036675] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[  855.070558] r8152 2-4:1.0 eth0: v1.12.12
[  855.409642] usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd

journalctl -f 
ep 15 11:27:01 airi CRON[27337]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:27:01 airi CRON[27338]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:27:01 airi CRON[27339]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:27:01 airi CRON[27340]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:27:01 airi CRON[27338]: pam_unix(cron:session): session closed for user rk
Sep 15 11:27:01 airi CRON[27337]: pam_unix(cron:session): session closed for user rk
Sep 15 11:27:04 airi kernel: usb 2-4: new SuperSpeed USB device number 4 using xhci_hcd
Sep 15 11:27:04 airi kernel: usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
Sep 15 11:27:04 airi kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
Sep 15 11:27:04 airi kernel: usb 2-4: Product: Thinkpad USB LAN
Sep 15 11:27:04 airi kernel: usb 2-4: Manufacturer: Lenovo
Sep 15 11:27:04 airi kernel: usb 2-4: SerialNumber: 1C6955000000
Sep 15 11:27:04 airi kernel: usbcore: registered new interface driver r8152
Sep 15 11:27:04 airi kernel: usbcore: registered new interface driver cdc_ether
Sep 15 11:27:04 airi kernel: usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
Sep 15 11:27:04 airi kernel: r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 15 11:27:04 airi networkd-dispatcher[912]: WARNING:Unknown index 21 seen, reloading interface list
Sep 15 11:27:04 airi kernel: r8152 2-4:1.0 eth0: v1.12.12
Sep 15 11:27:04 airi systemd-udevd[27428]: Using default interface naming scheme 'v245'.
Sep 15 11:27:04 airi systemd-udevd[27428]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Sep 15 11:27:04 airi kernel: r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
Sep 15 11:27:04 airi systemd-networkd[499]: eth0: Interface name change detected, eth0 has been renamed to enx3c18a01c6955.
Sep 15 11:27:04 airi networkd-dispatcher[912]: WARNING:Unknown index 21 seen, reloading interface list
Sep 15 11:27:04 airi systemd-udevd[27426]: Using default interface naming scheme 'v245'.
Sep 15 11:27:04 airi systemd-udevd[27426]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Sep 15 11:27:07 airi ModemManager[945]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:15.0/usb2/2-4': not supported by any plugin
Sep 15 11:27:18 airi systemd[1]: Starting Checkmk agent (10.91.0.249:60926)...
Sep 15 11:27:21 airi systemd[1]: check-mk-agent@12-10.91.0.203:6556-10.91.0.249:60926.service: Succeeded.
Sep 15 11:27:21 airi systemd[1]: Finished Checkmk agent (10.91.0.249:60926).
Sep 15 11:28:01 airi CRON[29132]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:28:01 airi CRON[29133]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:28:01 airi CRON[29134]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:28:01 airi CRON[29135]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:28:01 airi CRON[29133]: pam_unix(cron:session): session closed for user rk
Sep 15 11:28:01 airi CRON[29132]: pam_unix(cron:session): session closed for user rk
Sep 15 11:28:21 airi systemd[1]: Starting Checkmk agent (10.91.0.249:60928)...
Sep 15 11:28:24 airi audit[29798]: AVC apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=29798 comm="apparmor_parser"
Sep 15 11:28:24 airi kernel: audit: type=1400 audit(1663234104.465:129): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=29798 comm="apparmor_parser"
Sep 15 11:28:25 airi kernel: usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
Sep 15 11:28:25 airi systemd[1]: check-mk-agent@13-10.91.0.203:6556-10.91.0.249:60928.service: Succeeded.
Sep 15 11:28:25 airi systemd[1]: Finished Checkmk agent (10.91.0.249:60928).
Sep 15 11:28:25 airi kernel: r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 15 11:28:25 airi kernel: r8152 2-4:1.0 eth0: v1.12.12
Sep 15 11:28:25 airi networkd-dispatcher[912]: WARNING:Unknown index 22 seen, reloading interface list
Sep 15 11:28:25 airi networkd-dispatcher[912]: ERROR:Unknown interface index 22 seen even after reload
Sep 15 11:28:25 airi networkd-dispatcher[912]: WARNING:Unknown index 22 seen, reloading interface list
Sep 15 11:28:25 airi networkd-dispatcher[912]: ERROR:Unknown interface index 22 seen even after reload
Sep 15 11:28:25 airi systemd-udevd[29859]: eth0: Failed to get link config: No such device
Sep 15 11:28:25 airi libvirtd[1160]: Failed to open file '/sys/class/net/eth0/operstate': No such file or directory
Sep 15 11:28:25 airi libvirtd[1160]: unable to read: /sys/class/net/eth0/operstate: No such file or directory
Sep 15 11:28:25 airi ModemManager[945]: <info>  [base-manager] port eth0 released by device '/sys/devices/pci0000:00/0000:00:15.0/usb2/2-4'
Sep 15 11:28:25 airi ModemManager[945]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:15.0/usb2/2-4': Operation was cancelled
Sep 15 11:28:25 airi kernel: usb 2-4: reset SuperSpeed USB device number 4 using xhci_hcd
Sep 15 11:29:01 airi CRON[31052]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:29:01 airi CRON[31053]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:29:01 airi CRON[31055]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:29:01 airi CRON[31054]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:29:01 airi CRON[31053]: pam_unix(cron:session): session closed for user rk
Sep 15 11:29:01 airi CRON[31052]: pam_unix(cron:session): session closed for user rk
Sep 15 11:29:25 airi systemd[1]: Starting Checkmk agent (10.91.0.249:60930)...
Sep 15 11:29:25 airi systemd[1]: Starting Cleanup of Temporary Directories...
Sep 15 11:29:25 airi systemd[1]: systemd-tmpfiles-clean.service: Succeeded.
Sep 15 11:29:25 airi systemd[1]: Finished Cleanup of Temporary Directories.
Sep 15 11:29:28 airi systemd[1]: check-mk-agent@14-10.91.0.203:6556-10.91.0.249:60930.service: Succeeded.
Sep 15 11:29:28 airi systemd[1]: Finished Checkmk agent (10.91.0.249:60930).
Sep 15 11:30:01 airi CRON[32860]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:30:01 airi CRON[32859]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:30:01 airi CRON[32862]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:30:01 airi CRON[32861]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:30:01 airi CRON[32860]: pam_unix(cron:session): session closed for user rk
Sep 15 11:30:01 airi CRON[32859]: pam_unix(cron:session): session closed for user rk
Sep 15 11:30:28 airi systemd[1]: Starting Checkmk agent (10.91.0.249:60932)...
Sep 15 11:30:32 airi systemd[1]: check-mk-agent@15-10.91.0.203:6556-10.91.0.249:60932.service: Succeeded.
Sep 15 11:30:32 airi systemd[1]: Finished Checkmk agent (10.91.0.249:60932).
Sep 15 11:31:01 airi CRON[34763]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:31:01 airi CRON[34764]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:31:01 airi CRON[34768]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:31:01 airi CRON[34769]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:31:01 airi CRON[34764]: pam_unix(cron:session): session closed for user rk
Sep 15 11:31:02 airi CRON[34763]: pam_unix(cron:session): session closed for user rk
Sep 15 11:31:32 airi systemd[1]: Starting Checkmk agent (10.91.0.249:60934)...
Sep 15 11:31:35 airi systemd[1]: check-mk-agent@16-10.91.0.203:6556-10.91.0.249:60934.service: Succeeded.
Sep 15 11:31:35 airi systemd[1]: Finished Checkmk agent (10.91.0.249:60934).
Sep 15 11:32:01 airi CRON[36510]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:32:01 airi CRON[36509]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 11:32:01 airi CRON[36511]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:32:01 airi CRON[36512]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 11:32:01 airi CRON[36510]: pam_unix(cron:session): session closed for user rk
Sep 15 11:32:01 airi CRON[36509]: pam_unix(cron:session): session closed for user rk

tail -f /var/log/libvirt/qemu/management.log: 
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change
libusb: error [udev_hotplug_event] ignoring udev action change

on VM:

dmesg -w
[  521.259874] usb 1-4: new high-speed USB device number 3 using ehci-pci
[  521.426989] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x81 has invalid maxpacket 1024                                                  
[  521.431288] usb 1-4: config 1 interface 0 altsetting 0 bulk endpoint 0x2 has invalid maxpacket 1024                                                   
[  521.439304] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x81 has invalid maxpacket 1024                                                  
[  521.442762] usb 1-4: config 2 interface 1 altsetting 1 bulk endpoint 0x2 has invalid maxpacket 1024                                                   
[  521.450293] usb 1-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00                                                             
[  521.453350] usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6                                                                         
[  521.456176] usb 1-4: Product: Thinkpad USB LAN
[  521.457827] usb 1-4: Manufacturer: Lenovo
[  521.459298] usb 1-4: SerialNumber: 1C6955000000
[  521.816199] usbcore: registered new interface driver r8152
[  521.841568] usbcore: registered new interface driver cdc_ether
[  522.104041] usb 1-4: reset high-speed USB device number 3 using ehci-pci
[  522.567164] r8152 1-4:1.0 eth0: v1.09.9
[  522.586018] r8152 1-4:1.0 enx3c18a01c6955: renamed from eth0
[  584.144692] IPv6: ADDRCONF(NETDEV_UP): enx3c18a01c6955: link is not ready
[  584.193573] IPv6: ADDRCONF(NETDEV_CHANGE): enx3c18a01c6955: link becomes ready                                                                        
[  584.203952] r8152 1-4:1.0 enx3c18a01c6955: carrier on

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-09-15:

#9

Download full text (8.8 KiB)

I updated the hosts libvirt to the version of the backport ppa you mentioned, inserted, delegated the USB-NIC and inserted the cable. It shows the same error as Ubuntu 22.04 before. This strongly suggests, that it is indeed a libvirt bug.

Host:
libvirt0:amd64/focal 8.0.0-1ubuntu7.1~backport20.04.202205310636~ubuntu20.04.1 uptodate

On Host:
dmesg:
[ 446.125558] usb 2-4: new SuperSpeed USB device number 3 using xhci_hcd
[ 446.145912] usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[ 446.145924] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[ 446.145927] usb 2-4: Product: Thinkpad USB LAN
[ 446.145929] usb 2-4: Manufacturer: Lenovo
[ 446.145931] usb 2-4: SerialNumber: 1C6955000000
[ 446.173154] usbcore: registered new interface driver r8152
[ 446.183791] usbcore: registered new interface driver cdc_ether
[ 446.302087] usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
[ 446.349809] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 446.383514] r8152 2-4:1.0 eth0: v1.12.12
[ 446.424504] r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
[ 470.390919] audit: type=1400 audit(1663236916.760:125): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=18610 comm="apparmor_parser"
[ 471.097459] usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
[ 471.151505] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[ 471.179161] r8152 2-4:1.0 eth0: v1.12.12

journalctl:
Sep 15 12:14:52 airi kernel: usb 2-4: new SuperSpeed USB device number 3 using xhci_hcd
Sep 15 12:14:52 airi kernel: usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
Sep 15 12:14:52 airi kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
Sep 15 12:14:52 airi kernel: usb 2-4: Product: Thinkpad USB LAN
Sep 15 12:14:52 airi kernel: usb 2-4: Manufacturer: Lenovo
Sep 15 12:14:52 airi kernel: usb 2-4: SerialNumber: 1C6955000000
Sep 15 12:14:52 airi kernel: usbcore: registered new interface driver r8152
Sep 15 12:14:52 airi kernel: usbcore: registered new interface driver cdc_ether
Sep 15 12:14:52 airi kernel: usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
Sep 15 12:14:52 airi kernel: r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 15 12:14:52 airi kernel: r8152 2-4:1.0 eth0: v1.12.12
Sep 15 12:14:52 airi networkd-dispatcher[867]: WARNING:Unknown index 20 seen, reloading interface list
Sep 15 12:14:52 airi systemd-udevd[18057]: Using default interface naming scheme 'v245'.
Sep 15 12:14:52 airi systemd-udevd[18057]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Sep 15 12:14:52 airi kernel: r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
Sep 15 12:14:52 airi systemd-networkd[513]: eth0: Interface name change detected, eth0 has been renamed to enx3c18a01c6955.
Sep 15 12:14:52 airi networkd-dispatcher[867]: WARNING:Unknown index 20 seen, reloading interface list
Sep 15 12:14:52 airi systemd-udevd[18059]: Using default interface naming scheme 'v245'.
Sep 15 12:14:52 airi systemd-udevd[18059]: ethtool: autonegotiation is unse...

I updated the hosts libvirt to the version of the backport ppa you mentioned, inserted, delegated the USB-NIC and inserted the cable. It shows the same error as Ubuntu 22.04 before. This strongly suggests, that it is indeed a libvirt bug.

Host:
libvirt0:amd64/focal 8.0.0-1ubuntu7.1~backport20.04.202205310636~ubuntu20.04.1 uptodate

On Host:
dmesg:
[  446.125558] usb 2-4: new SuperSpeed USB device number 3 using xhci_hcd
[  446.145912] usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
[  446.145924] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
[  446.145927] usb 2-4: Product: Thinkpad USB LAN
[  446.145929] usb 2-4: Manufacturer: Lenovo
[  446.145931] usb 2-4: SerialNumber: 1C6955000000
[  446.173154] usbcore: registered new interface driver r8152
[  446.183791] usbcore: registered new interface driver cdc_ether
[  446.302087] usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
[  446.349809] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[  446.383514] r8152 2-4:1.0 eth0: v1.12.12
[  446.424504] r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
[  470.390919] audit: type=1400 audit(1663236916.760:125): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=18610 comm="apparmor_parser"
[  471.097459] usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
[  471.151505] r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
[  471.179161] r8152 2-4:1.0 eth0: v1.12.12

journalctl:
Sep 15 12:14:52 airi kernel: usb 2-4: new SuperSpeed USB device number 3 using xhci_hcd
Sep 15 12:14:52 airi kernel: usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00
Sep 15 12:14:52 airi kernel: usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6
Sep 15 12:14:52 airi kernel: usb 2-4: Product: Thinkpad USB LAN
Sep 15 12:14:52 airi kernel: usb 2-4: Manufacturer: Lenovo
Sep 15 12:14:52 airi kernel: usb 2-4: SerialNumber: 1C6955000000
Sep 15 12:14:52 airi kernel: usbcore: registered new interface driver r8152
Sep 15 12:14:52 airi kernel: usbcore: registered new interface driver cdc_ether
Sep 15 12:14:52 airi kernel: usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
Sep 15 12:14:52 airi kernel: r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 15 12:14:52 airi kernel: r8152 2-4:1.0 eth0: v1.12.12
Sep 15 12:14:52 airi networkd-dispatcher[867]: WARNING:Unknown index 20 seen, reloading interface list
Sep 15 12:14:52 airi systemd-udevd[18057]: Using default interface naming scheme 'v245'.
Sep 15 12:14:52 airi systemd-udevd[18057]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Sep 15 12:14:52 airi kernel: r8152 2-4:1.0 enx3c18a01c6955: renamed from eth0
Sep 15 12:14:52 airi systemd-networkd[513]: eth0: Interface name change detected, eth0 has been renamed to enx3c18a01c6955.
Sep 15 12:14:52 airi networkd-dispatcher[867]: WARNING:Unknown index 20 seen, reloading interface list
Sep 15 12:14:52 airi systemd-udevd[18059]: Using default interface naming scheme 'v245'.
Sep 15 12:14:52 airi systemd-udevd[18059]: ethtool: autonegotiation is unset or enabled, the speed and duplex are not writable.
Sep 15 12:14:55 airi ModemManager[887]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:15.0/usb2/2-4': not supported by any plugin
Sep 15 12:15:01 airi CRON[18230]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 12:15:01 airi CRON[18231]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 12:15:01 airi CRON[18232]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 12:15:01 airi CRON[18233]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 12:15:01 airi CRON[18231]: pam_unix(cron:session): session closed for user rk
Sep 15 12:15:01 airi CRON[18230]: pam_unix(cron:session): session closed for user rk
Sep 15 12:15:14 airi systemd[1]: Starting Checkmk agent (10.91.0.249:38112)...
Sep 15 12:15:16 airi audit[18610]: AVC apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=18610 comm="apparmor_parser"
Sep 15 12:15:16 airi kernel: audit: type=1400 audit(1663236916.760:125): apparmor="STATUS" operation="profile_replace" profile="unconfined" name="libvirt-21d2ab6e-d039-4e13-8956-4249b580d756" pid=18610 comm="apparmor_parser"
Sep 15 12:15:17 airi systemd[1]: check-mk-agent@6-10.91.0.203:6556-10.91.0.249:38112.service: Succeeded.
Sep 15 12:15:17 airi systemd[1]: Finished Checkmk agent (10.91.0.249:38112).
Sep 15 12:15:17 airi kernel: usb 2-4: reset SuperSpeed USB device number 3 using xhci_hcd
Sep 15 12:15:17 airi kernel: r8152 2-4:1.0: load rtl8153a-3 v2 02/07/20 successfully
Sep 15 12:15:17 airi kernel: r8152 2-4:1.0 eth0: v1.12.12
Sep 15 12:15:17 airi networkd-dispatcher[867]: WARNING:Unknown index 21 seen, reloading interface list
Sep 15 12:15:17 airi networkd-dispatcher[867]: ERROR:Unknown interface index 21 seen even after reload
Sep 15 12:15:17 airi networkd-dispatcher[867]: WARNING:Unknown index 21 seen, reloading interface list
Sep 15 12:15:17 airi networkd-dispatcher[867]: ERROR:Unknown interface index 21 seen even after reload
Sep 15 12:15:17 airi systemd-udevd[18653]: eth0: Failed to get link config: No such device
Sep 15 12:15:17 airi ModemManager[887]: <info>  [base-manager] port eth0 released by device '/sys/devices/pci0000:00/0000:00:15.0/usb2/2-4'
Sep 15 12:15:17 airi ModemManager[887]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:15.0/usb2/2-4': Operation was cancelled
Sep 15 12:16:01 airi CRON[20061]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 12:16:01 airi CRON[20062]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 12:16:01 airi CRON[20063]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 12:16:01 airi CRON[20064]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 12:16:01 airi CRON[20062]: pam_unix(cron:session): session closed for user rk
Sep 15 12:16:01 airi CRON[20061]: pam_unix(cron:session): session closed for user rk
Sep 15 12:16:17 airi systemd[1]: Starting Checkmk agent (10.91.0.249:38114)...
Sep 15 12:16:20 airi systemd[1]: check-mk-agent@7-10.91.0.203:6556-10.91.0.249:38114.service: Succeeded.
Sep 15 12:16:20 airi systemd[1]: Finished Checkmk agent (10.91.0.249:38114).
Sep 15 12:17:01 airi CRON[21946]: pam_unix(cron:session): session opened for user root by (uid=0)
Sep 15 12:17:01 airi CRON[21948]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 12:17:01 airi CRON[21949]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Sep 15 12:17:01 airi CRON[21947]: pam_unix(cron:session): session opened for user rk by (uid=0)
Sep 15 12:17:01 airi CRON[21950]: (rk) CMD (/usr/bin/wget -6 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 12:17:01 airi CRON[21951]: (rk) CMD (/usr/bin/wget -4 --no-check-certificate --output-document=/dev/null --timeout=600 -q "https://naoko.zsze.de")
Sep 15 12:17:01 airi CRON[21946]: pam_unix(cron:session): session closed for user root
Sep 15 12:17:02 airi CRON[21948]: pam_unix(cron:session): session closed for user rk
Sep 15 12:17:02 airi CRON[21947]: pam_unix(cron:session): session closed for user rk

Nothing happend in /var/log/libvirt/qemu/management.log

On VM:
dmesg:
[  284.845919] usb 2-4: new high-speed USB device number 3 using ehci-pci
[  285.004095] usb 2-4: config 1 interface 0 altsetting 0 bulk endpoint 0x81 has invalid maxpacket 1024                                                  
[  285.007834] usb 2-4: config 1 interface 0 altsetting 0 bulk endpoint 0x2 has invalid maxpacket 1024                                                   
[  285.020715] usb 2-4: config 2 interface 1 altsetting 1 bulk endpoint 0x81 has invalid maxpacket 1024                                                  
[  285.024468] usb 2-4: config 2 interface 1 altsetting 1 bulk endpoint 0x2 has invalid maxpacket 1024                                                   
[  285.036259] usb 2-4: New USB device found, idVendor=17ef, idProduct=7205, bcdDevice=30.00                                                             
[  285.039715] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=6                                                                         
[  285.042661] usb 2-4: Product: Thinkpad USB LAN
[  285.044804] usb 2-4: Manufacturer: Lenovo
[  285.048580] usb 2-4: SerialNumber: 1C6955000000
[  285.316969] usb 2-4: can't set config #2, error -32

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-10-04:

#10

Is there anything missing or anything I can do to help fix this bug?

Revision history for this message

Rolf Kutz (vzsze) wrote on 2022-10-28:

#11

Interestingly usb-passthrough does work with an ax88179 NIC. But that might be, because of initialization errors on the Host or because of diffent kind of initialization. Despite the errors it does work on the host.

Host (Ubuntu 22.04, Kernel Linux 5.15.0-52-generic)
[45964.858866] ax88179_178a 3-8:2.1 eth1: Failed to read reg index 0x000e: -32
[message repeated multiple times]
[45964.901841] ax88179_178a 3-8:2.1 eth1: Failed to write reg index 0x000e: -32
[45964.912302] ax88179_178a 3-8:2.1 eth1: Failed to read reg index 0x0000: -32
[45965.988669] ax88179_178a 3-8:2.0 eth0: unregister 'ax88179_178a' usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet
[45965.988726] ax88179_178a 3-8:2.0 eth0: Failed to read reg index 0x0002: -19
[45965.988732] ax88179_178a 3-8:2.0 eth0: Failed to write reg index 0x0002: -19
[45966.031579] ax88179_178a 3-8:2.0 eth0 (unregistered): Failed to write reg index 0x0002: -19
[45966.031591] ax88179_178a 3-8:2.0 eth0 (unregistered): Failed to write reg index 0x0001: -19
[45966.031596] ax88179_178a 3-8:2.0 eth0 (unregistered): Failed to write reg index 0x0002: -19
[45966.031820] ax88179_178a 3-8:2.1 eth1: unregister 'ax88179_178a' usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet
[45966.031937] ax88179_178a 3-8:2.1 eth1: Failed to read reg index 0x0002: -19
[45966.031944] ax88179_178a 3-8:2.1 eth1: Failed to write reg index 0x0002: -19
[45966.075553] ax88179_178a 3-8:2.1 eth1 (unregistered): Failed to write reg index 0x0002: -19
[45966.075567] ax88179_178a 3-8:2.1 eth1 (unregistered): Failed to write reg index 0x0001: -19
[45966.075572] ax88179_178a 3-8:2.1 eth1 (unregistered): Failed to write reg index 0x0002: -19
[45967.862773] ax88179_178a 3-8:1.0 (unnamed net_device) (uninitialized): Failed to read reg index 0x0040: -32
[45968.172405] ax88179_178a 3-8:1.0 eth0: register 'ax88179_178a' at usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet, f8:e4:3b:90:97:0f
[45968.714083] ax88179_178a 3-8:1.0 enxf8e43b90970f: renamed from eth0
[45969.304396] ax88179_178a 3-8:1.0 enxf8e43b90970f: Failed to read reg index 0x0040: -32
[45971.298515] ax88179_178a 3-8:1.0 enxf8e43b90970f: ax88179 - Link status is: 1
[46073.074394] ax88179_178a 3-8:1.0 enxf8e43b90970f: unregister 'ax88179_178a' usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet

VM (Ubuntu 20.04 Kernel Linux 5.15.0-52-generic):
rkutz@linux02:~$ dmesg |grep ax88
[ 49.404245] ax88179_178a 1-4:1.0 (unnamed net_device) (uninitialized): Failed to read reg index 0x0040: -32
[ 49.727024] ax88179_178a 1-4:1.0 eth0: register 'ax88179_178a' at usb-0000:00:1d.7-4, ASIX AX88179 USB 3.0 Gigabit Ethernet, f8:e4:3b:90:97:0f
[ 49.727049] usbcore: registered new interface driver ax88179_178a
[ 49.728594] ax88179_178a 1-4:1.0 enxf8e43b90970f: renamed from eth0
[ 50.319450] ax88179_178a 1-4:1.0 enxf8e43b90970f: Failed to read reg index 0x0040: -32
[ 2124.862130] ax88179_178a 1-4:1.0 enxf8e43b90970f: ax88179 - Link status is: 1

Interestingly usb-passthrough does work with an ax88179 NIC. But that might be, because of initialization errors on the Host or because of diffent kind of initialization. Despite the errors it does work on the host.

Host (Ubuntu 22.04, Kernel Linux 5.15.0-52-generic)
[45964.858866] ax88179_178a 3-8:2.1 eth1: Failed to read reg index 0x000e: -32
[message repeated multiple times]
[45964.901841] ax88179_178a 3-8:2.1 eth1: Failed to write reg index 0x000e: -32
[45964.912302] ax88179_178a 3-8:2.1 eth1: Failed to read reg index 0x0000: -32
[45965.988669] ax88179_178a 3-8:2.0 eth0: unregister 'ax88179_178a' usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet
[45965.988726] ax88179_178a 3-8:2.0 eth0: Failed to read reg index 0x0002: -19
[45965.988732] ax88179_178a 3-8:2.0 eth0: Failed to write reg index 0x0002: -19
[45966.031579] ax88179_178a 3-8:2.0 eth0 (unregistered): Failed to write reg index 0x0002: -19
[45966.031591] ax88179_178a 3-8:2.0 eth0 (unregistered): Failed to write reg index 0x0001: -19
[45966.031596] ax88179_178a 3-8:2.0 eth0 (unregistered): Failed to write reg index 0x0002: -19
[45966.031820] ax88179_178a 3-8:2.1 eth1: unregister 'ax88179_178a' usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet
[45966.031937] ax88179_178a 3-8:2.1 eth1: Failed to read reg index 0x0002: -19
[45966.031944] ax88179_178a 3-8:2.1 eth1: Failed to write reg index 0x0002: -19
[45966.075553] ax88179_178a 3-8:2.1 eth1 (unregistered): Failed to write reg index 0x0002: -19
[45966.075567] ax88179_178a 3-8:2.1 eth1 (unregistered): Failed to write reg index 0x0001: -19
[45966.075572] ax88179_178a 3-8:2.1 eth1 (unregistered): Failed to write reg index 0x0002: -19
[45967.862773] ax88179_178a 3-8:1.0 (unnamed net_device) (uninitialized): Failed to read reg index 0x0040: -32
[45968.172405] ax88179_178a 3-8:1.0 eth0: register 'ax88179_178a' at usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet, f8:e4:3b:90:97:0f
[45968.714083] ax88179_178a 3-8:1.0 enxf8e43b90970f: renamed from eth0
[45969.304396] ax88179_178a 3-8:1.0 enxf8e43b90970f: Failed to read reg index 0x0040: -32
[45971.298515] ax88179_178a 3-8:1.0 enxf8e43b90970f: ax88179 - Link status is: 1
[46073.074394] ax88179_178a 3-8:1.0 enxf8e43b90970f: unregister 'ax88179_178a' usb-0000:00:14.0-8, ASIX AX88179 USB 3.0 Gigabit Ethernet

VM (Ubuntu 20.04 Kernel Linux 5.15.0-52-generic):
rkutz@linux02:~$ dmesg |grep ax88
[   49.404245] ax88179_178a 1-4:1.0 (unnamed net_device) (uninitialized): Failed to read reg index 0x0040: -32
[   49.727024] ax88179_178a 1-4:1.0 eth0: register 'ax88179_178a' at usb-0000:00:1d.7-4, ASIX AX88179 USB 3.0 Gigabit Ethernet, f8:e4:3b:90:97:0f
[   49.727049] usbcore: registered new interface driver ax88179_178a
[   49.728594] ax88179_178a 1-4:1.0 enxf8e43b90970f: renamed from eth0
[   50.319450] ax88179_178a 1-4:1.0 enxf8e43b90970f: Failed to read reg index 0x0040: -32
[ 2124.862130] ax88179_178a 1-4:1.0 enxf8e43b90970f: ax88179 - Link status is: 1

Revision history for this message

Robie Basak (racb) wrote on 2022-11-01:

#12

Since Christian agreed this is a valid bug I'm adding this to our backlog and tagging it regression-release to represent that it's a regression compared to 20.04.

I'm sorry I don't know how to progress it though, and unless Christian thinks otherwise then unfortunately I don't expect it to make any progress soon. Volunteers welcome.

summary:	- usb-passthrough of network card not working any more on 22.04 + r8152 driver no longer releases USB NIC for VM passthrough
Changed in libvirt (Ubuntu):
status:	Incomplete → Triaged
importance:	Undecided → Medium
tags:	added: regression-release

Revision history for this message

Wayne Manion (treowayne) wrote on 2023-06-09:

#13

I have also experienced this problem. It took a pretty long time to figure out why my USB Ethernet adapter worked just fine on the Ubuntu host but would never work correctly on the Ubuntu or Home Assistant OS guests.

For whatever its worth, I experienced this problem on several different Realtek 8152 (10/100) and 8153 (Gigabit) USB ethernet adapters from multiple manufacturers. My ASIX Ethernet adapters (88179 and 88772) pass through to guests just fine. I have multiple guest VMs and I wanted to be able to provide a gigabit NIC for each without having to deal with USB paths.

I had to blacklist the r8152, r8153_ecm, and cdc_ether modules on the host to get the passthrough to work correctly. I would like to confirm that the '$ sudo update-initramfs -u' step IS necessary to get this to work.

Thanks Christian Ehrhardt.

Revision history for this message

Rolf Kutz (vzsze) wrote on 2023-08-07:

#14

The problem is still present with kernel 6.2.0-26-generic.

Ubuntu
libvirt package

r8152 driver no longer releases USB NIC for VM passthrough

Bug Description

Other bug subscribers

Related questions

Remote bug watches

Ubuntulibvirt package

r8152 driver no longer releases USB NIC for VM passthrough

Bug Description

Other bug subscribers

Related questions

Remote bug watches

Ubuntu
libvirt package