One thing that might make a difference is that I run NetworkManager and
not netplan on this Jammy laptop.  That seems to be necessary to deal
with the company's VPN.


Looking at the startup sequence,  I wonder if I am failing where virtiosfd is 
spawned.  From what I read, that needs to be run as root.   We see that in 
/var/log/libvirt/qemu/  we get two logs when the guest is attempting to start: 

# ll /var/log/libvirt/qemu/ub*
-rw------- 1 root root   832 Oct  9 11:41 
/var/log/libvirt/qemu/ubuntu22.04-fs0-virtiofsd.log
-rw------- 1 root root 27696 Oct  9 11:41 /var/log/libvirt/qemu/ubuntu22.04.log

No timestamps so I can't tell exactly which is logged first.  That would
be a nice thing to have.


Looking at syslog on the host, I think we get some valid timestamps 
corresponding to those logs:  


Oct  9 11:41:02 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.hostname1' 
unit='dbus-org.freedesktop.hostname1.service' requested by ':1.249' (uid=1000 
pid=11068 comm="/usr/bin/python3 /usr/bin/virt-manager " label="unconfined")
Oct  9 11:41:02 jammy-laptop systemd[1]: Starting Hostname Service...
Oct  9 11:41:02 jammy-laptop dbus-daemon[1605]: [system] Successfully activated 
service 'org.freedesktop.hostname1'
Oct  9 11:41:02 jammy-laptop systemd[1]: Started Hostname Service.
Oct  9 11:41:15 jammy-laptop kernel: [11926.090059] audit: type=1400 
audit(1728499275.656:306): apparmor="STATUS" operation="profile_load" 
profile="unconfined" name="libvirt-7c3e5649-d58e-44e3-9c11-c2ceb3c21185" 
pid=11706 comm="apparmor_parser"
Oct  9 11:41:15 jammy-laptop kernel: [11926.174003] audit: type=1400 
audit(1728499275.740:307): apparmor="STATUS" operation="profile_replace" 
profile="unconfined" name="libvirt-7c3e5649-d58e-44e3-9c11-c2ceb3c21185" 
pid=11709 comm="apparmor_parser"
Oct  9 11:41:15 jammy-laptop kernel: [11926.258421] audit: type=1400 
audit(1728499275.824:308): apparmor="STATUS" operation="profile_replace" 
profile="unconfined" name="libvirt-7c3e5649-d58e-44e3-9c11-c2ceb3c21185" 
pid=11713 comm="apparmor_parser"
Oct  9 11:41:15 jammy-laptop kernel: [11926.348758] audit: type=1400 
audit(1728499275.912:309): apparmor="STATUS" operation="profile_replace" 
profile="unconfined" name="libvirt-7c3e5649-d58e-44e3-9c11-c2ceb3c21185" 
pid=11717 comm="apparmor_parser"
Oct  9 11:41:15 jammy-laptop kernel: [11926.428053] audit: type=1400 
audit(1728499275.992:310): apparmor="STATUS" operation="profile_replace" 
info="same as current profile, skipping" profile="unconfined" 
name="libvirt-7c3e5649-d58e-44e3-9c11-c2ceb3c21185" pid=11721 
comm="apparmor_parser"
Oct  9 11:41:16 jammy-laptop kernel: [11926.508897] audit: type=1400 
audit(1728499276.072:311): apparmor="STATUS" operation="profile_replace" 
info="same as current profile, skipping" profile="unconfined" 
name="libvirt-7c3e5649-d58e-44e3-9c11-c2ceb3c21185" pid=11726 
comm="apparmor_parser"
Oct  9 11:41:16 jammy-laptop kernel: [11926.514785] audit: type=1400 
audit(1728499276.080:312): apparmor="ALLOWED" operation="exec" 
profile="libvirtd" name="/usr/lib/qemu/virtiofsd" pid=11729 comm="rpc-libvirtd" 
requested_mask="x" denied_mask="x" fsuid=0 ouid=0 
target="libvirtd//null-/usr/lib/qemu/virtiofsd"
Oct  9 11:41:16 jammy-laptop kernel: [11926.515211] audit: type=1400 
audit(1728499276.080:313): apparmor="ALLOWED" operation="file_inherit" 
profile="libvirtd//null-/usr/lib/qemu/virtiofsd" name="/dev/null" pid=11729 
comm="virtiofsd" requested_mask="wr" denied_mask="wr" fsuid=0 ouid=0
Oct  9 11:41:16 jammy-laptop kernel: [11926.515224] audit: type=1400 
audit(1728499276.080:314): apparmor="ALLOWED" operation="file_inherit" 
profile="libvirtd//null-/usr/lib/qemu/virtiofsd" 
name="/run/libvirt/qemu/8-ubuntu22.04-fs0-fs.pid" pid=11729 comm="virtiofsd" 
requested_mask="w" denied_mask="w" fsuid=0 ouid=0
Oct  9 11:41:16 jammy-laptop kernel: [11926.515230] audit: type=1400 
audit(1728499276.080:315): apparmor="ALLOWED" operation="file_mmap" 
profile="libvirtd//null-/usr/lib/qemu/virtiofsd" name="/usr/lib/qemu/virtiofsd" 
pid=11729 comm="virtiofsd" requested_mask="r" denied_mask="r" fsuid=0 ouid=0
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0865] 
manager: (vnet10): new Tun device (/org/freedesktop/NetworkManager/Devices/24)
Oct  9 11:41:16 jammy-laptop systemd-udevd[11734]: Using default interface 
naming scheme 'v249'.
Oct  9 11:41:16 jammy-laptop kernel: [11926.518751] virbr0: port 1(vnet10) 
entered blocking state
Oct  9 11:41:16 jammy-laptop kernel: [11926.518753] virbr0: port 1(vnet10) 
entered disabled state
Oct  9 11:41:16 jammy-laptop kernel: [11926.518811] device vnet10 entered 
promiscuous mode
Oct  9 11:41:16 jammy-laptop kernel: [11926.518967] virbr0: port 1(vnet10) 
entered blocking state
Oct  9 11:41:16 jammy-laptop kernel: [11926.518968] virbr0: port 1(vnet10) 
entered listening state
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0936] 
device (vnet10): state change: unmanaged -> unavailable (reason 
'connection-assumed', sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0939] 
device (vnet10): state change: unavailable -> disconnected (reason 
'connection-assumed', sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0944] 
device (vnet10): Activation: starting connection 'vnet10' 
(dafbc54a-c89b-484e-87b9-7eaa9ad69a51)
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0948] 
device (vnet10): state change: disconnected -> prepare (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0950] 
device (vnet10): state change: prepare -> config (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0951] 
device (vnet10): state change: config -> ip-config (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0952] 
device (virbr0): bridge port vnet10 was attached
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0952] 
device (vnet10): Activation: connection 'vnet10' enslaved, continuing activation
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.0953] 
device (vnet10): state change: ip-config -> ip-check (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.nm_dispatcher' 
unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 
pid=1607 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activation via systemd 
failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit 
dbus-org.freedesktop.nm-dispatcher.service not found.
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1041] 
device (vnet10): state change: ip-check -> secondaries (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1042] 
device (vnet10): state change: secondaries -> activated (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1045] 
device (vnet10): Activation: successful, device activated.
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.nm_dispatcher' 
unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 
pid=1607 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activation via systemd 
failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit 
dbus-org.freedesktop.nm-dispatcher.service not found.
Oct  9 11:41:16 jammy-laptop systemd-udevd[11740]: Using default interface 
naming scheme 'v249'.
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1838] 
manager: (vnet11): new Tun device (/org/freedesktop/NetworkManager/Devices/25)
Oct  9 11:41:16 jammy-laptop kernel: [11926.616045] virbr0: port 2(vnet11) 
entered blocking state
Oct  9 11:41:16 jammy-laptop kernel: [11926.616047] virbr0: port 2(vnet11) 
entered disabled state
Oct  9 11:41:16 jammy-laptop kernel: [11926.616104] device vnet11 entered 
promiscuous mode
Oct  9 11:41:16 jammy-laptop kernel: [11926.616191] virbr0: port 2(vnet11) 
entered blocking state
Oct  9 11:41:16 jammy-laptop kernel: [11926.616192] virbr0: port 2(vnet11) 
entered listening state
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1912] 
device (vnet11): state change: unmanaged -> unavailable (reason 
'connection-assumed', sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1915] 
device (vnet11): state change: unavailable -> disconnected (reason 
'connection-assumed', sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1923] 
device (vnet11): Activation: starting connection 'vnet11' 
(42e19fd7-66d4-48d2-b17f-77191b7dfe6d)
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1926] 
device (vnet11): state change: disconnected -> prepare (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1929] 
device (vnet11): state change: prepare -> config (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1931] 
device (vnet11): state change: config -> ip-config (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1932] 
device (virbr0): bridge port vnet11 was attached
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1932] 
device (vnet11): Activation: connection 'vnet11' enslaved, continuing activation
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1935] 
device (vnet11): state change: ip-config -> ip-check (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.nm_dispatcher' 
unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 
pid=1607 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activation via systemd 
failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit 
dbus-org.freedesktop.nm-dispatcher.service not found.
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1995] 
device (vnet11): state change: ip-check -> secondaries (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1996] 
device (vnet11): state change: secondaries -> activated (reason 'none', 
sys-iface-state: 'external')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.1999] 
device (vnet11): Activation: successful, device activated.
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.nm_dispatcher' 
unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 
pid=1607 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activation via systemd 
failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit 
dbus-org.freedesktop.nm-dispatcher.service not found.
Oct  9 11:41:16 jammy-laptop systemd[1]: Started Virtual Machine 
qemu-8-ubuntu22.04.
Oct  9 11:41:16 jammy-laptop kernel: [11926.798640] virbr0: port 2(vnet11) 
entered disabled state
Oct  9 11:41:16 jammy-laptop kernel: [11926.799336] device vnet11 left 
promiscuous mode
Oct  9 11:41:16 jammy-laptop kernel: [11926.799338] virbr0: port 2(vnet11) 
entered disabled state
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.3880] 
device (vnet11): state change: activated -> unmanaged (reason 'unmanaged', 
sys-iface-state: 'removed')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.3883] 
device (vnet11): released from master device virbr0
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.nm_dispatcher' 
unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 
pid=1607 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activation via systemd 
failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit 
dbus-org.freedesktop.nm-dispatcher.service not found.
Oct  9 11:41:16 jammy-laptop kernel: [11926.906203] virbr0: port 1(vnet10) 
entered disabled state
Oct  9 11:41:16 jammy-laptop kernel: [11926.906882] device vnet10 left 
promiscuous mode
Oct  9 11:41:16 jammy-laptop kernel: [11926.906884] virbr0: port 1(vnet10) 
entered disabled state
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.5148] 
device (vnet10): state change: activated -> unmanaged (reason 'unmanaged', 
sys-iface-state: 'removed')
Oct  9 11:41:16 jammy-laptop NetworkManager[1607]: <info>  [1728499276.5150] 
device (vnet10): released from master device virbr0
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activating via 
systemd: service name='org.freedesktop.nm_dispatcher' 
unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.12' (uid=0 
pid=1607 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
Oct  9 11:41:16 jammy-laptop dbus-daemon[1605]: [system] Activation via systemd 
failed for unit 'dbus-org.freedesktop.nm-dispatcher.service': Unit 
dbus-org.freedesktop.nm-dispatcher.service not found.
Oct  9 11:41:16 jammy-laptop libvirtd[1945]: Unable to read from monitor: 
Connection reset by peer
Oct  9 11:41:16 jammy-laptop libvirtd[1945]: internal error: qemu unexpectedly 
closed the monitor: 2024-10-09T18:41:16.337665Z qemu-system-x86_64: -device 
vhost-user-fs-pci,id=fs0,chardev=chr-vu-fs0,tag=dir0,bus=pci.8,addr=0x0: Failed 
to read msg header. Read 0 instead of 12. Original request 
36.#0122024-10-09T18:41:16.337749Z qemu-system-x86_64: -device 
vhost-user-fs-pci,id=fs0,chardev=chr-vu-fs0,tag=dir0,bus=pci.8,addr=0x0: 
vhost_backend_init failed: Protocol error
Oct  9 11:41:16 jammy-laptop systemd[1]: 
machine-qemu\x2d8\x2dubuntu22.04.scope: Deactivated successfully.
Oct  9 11:41:16 jammy-laptop libvirtd[1945]: internal error: process exited 
while connecting to monitor: 2024-10-09T18:41:16.337665Z qemu-system-x86_64: 
-device 
vhost-user-fs-pci,id=fs0,chardev=chr-vu-fs0,tag=dir0,bus=pci.8,addr=0x0: Failed 
to read msg header. Read 0 instead of 12. Original request 
36.#0122024-10-09T18:41:16.337749Z qemu-system-x86_64: -device 
vhost-user-fs-pci,id=fs0,chardev=chr-vu-fs0,tag=dir0,bus=pci.8,addr=0x0: 
vhost_backend_init failed: Protocol error
Oct  9 11:41:32 jammy-laptop systemd[1]: systemd-hostnamed.service: Deactivated 
successfully.


I've seen some people demonstrating the use of virtiofsd run standalone for 
testing.  I'm willing to try that but I am not sure of what parameters to pass 
that would correspond to what I have in the xml that virt-manager created: 

<filesystem type="mount" accessmode="passthrough">
  <driver type="virtiofs"/>
  <source dir="/tmp"/>
  <target dir="hosttmp"/>
  <address type="pci" domain="0x0000" bus="0x08" slot="0x00" function="0x0"/>
</filesystem>

-- 
You received this bug notification because you are a member of Ubuntu
Bugs, which is subscribed to Ubuntu.
https://bugs.launchpad.net/bugs/2083988

Title:
  Cannot use virtiofs on Ubuntu 22.04

To manage notifications about this bug go to:
https://bugs.launchpad.net/ubuntu/+source/qemu/+bug/2083988/+subscriptions


-- 
ubuntu-bugs mailing list
[email protected]
https://lists.ubuntu.com/mailman/listinfo/ubuntu-bugs

Reply via email to