Writes to virtiofs (linux host w/ virtiofsd) filesystem fail even when using --mount-writable

[rjsmith1999]

Description

Host OS is ubuntu 2022.2, using latest virtiofsd from gitlab.

Could this be a virtiofsd issue, if so, how can I test?
 
Example:

jackson@SOME_HOST:~$ limactl start --name test --mount-type virtiofs --mount-writable
? Creating an instance "test" Proceed with the current configuration
WARN[0007] `mountType: virtiofs` on Linux is experimental 
INFO[0007] Starting the instance "test" with VM driver "qemu" 
INFO[0007] Attempting to download the image              arch=x86_64 digest="sha256:f6529be56da3429a56e4f5ef202bf4958201bc63f8541e478caa6e8eb712e635" location="https://cloud-images.ubuntu.com/releases/23.10/release-20231011/ubuntu-23.10-server-cloudimg-amd64.img"
INFO[0008] Using cache "/home/jackson/.cache/lima/download/by-url-sha256/c80fd2f7776369eb3c6fe0ce62d1a608491698e05554a6d04c4730f135078d87/data" 
INFO[0008] Attempting to download the nerdctl archive    arch=x86_64 digest="sha256:7c174a9ccc4dffdef08fe43eeb99e62ed00d7a4fd0b3a2fe60b3bfdd044c9135" location="https://github.com/containerd/nerdctl/releases/download/v1.7.1/nerdctl-full-1.7.1-linux-amd64.tar.gz"
INFO[0008] Using cache "/home/jackson/.cache/lima/download/by-url-sha256/c8ac6e3fed99e2f731ad6ab86ea00680d3e895ffad08832b2e7dbc3e0a80a00f/data" 
INFO[0009] [hostagent] hostagent socket created at /home/jackson/.lima/test/ha.sock 
INFO[0010] [hostagent] Starting QEMU (hint: to watch the boot progress, see "/home/jackson/.lima/test/serial*.log") 
INFO[0010] SSH Local Port: 36927                        
INFO[0010] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
INFO[0020] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
INFO[0036] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
INFO[0046] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
INFO[0056] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
INFO[0058] [hostagent] The essential requirement 1 of 2 is satisfied 
INFO[0058] [hostagent] Waiting for the essential requirement 2 of 2: "user session is ready for ssh" 
INFO[0058] [hostagent] The essential requirement 2 of 2 is satisfied 
INFO[0058] [hostagent] Waiting for the optional requirement 1 of 2: "systemd must be available" 
INFO[0058] [hostagent] Guest agent is running           
INFO[0058] [hostagent] Not forwarding TCP 127.0.0.54:53 
INFO[0058] [hostagent] Not forwarding TCP 127.0.0.53:53 
INFO[0058] [hostagent] Not forwarding TCP [::]:22       
INFO[0058] [hostagent] The optional requirement 1 of 2 is satisfied 
INFO[0058] [hostagent] Waiting for the optional requirement 2 of 2: "containerd binaries to be installed" 
INFO[0098] [hostagent] Waiting for the optional requirement 2 of 2: "containerd binaries to be installed" 
INFO[0098] [hostagent] The optional requirement 2 of 2 is satisfied 
INFO[0098] [hostagent] Waiting for the guest agent to be running 
INFO[0098] [hostagent] Waiting for the final requirement 1 of 1: "boot scripts must have finished" 
INFO[0113] [hostagent] The final requirement 1 of 1 is satisfied 
INFO[0113] READY. Run `limactl shell test` to open the shell. 
jackson@SOME_HOST:~$ limactl shell test
jackson@lima-test:/home/jackson$ touch test.txt
touch: cannot touch 'test.txt': Invalid argument

[rjsmith1999]

Here is the output of limactl start --debug

jackson@SOME_HOST:~$ limactl start test --debug
DEBU[0000] interpreting argument "test" as an instance name 
INFO[0000] Using the existing instance "test"           
DEBU[0000] Make sure "user-v2" network is stopped       
DEBU[0000] Make sure usernet network is stopped         
DEBU[0000] Make sure "shared" network is stopped        
DEBU[0000] Make sure "bridged" network is stopped       
DEBU[0000] Make sure "host" network is stopped          
INFO[0000] Starting the instance "test" with VM driver "qemu" 
DEBU[0000] [hostagent] Creating iso file /home/jackson/.lima/test/cidata.iso 
DEBU[0000] [hostagent] Using /tmp/diskfs_iso371276119 as workspace 
DEBU[0000] [hostagent] OpenSSH version 8.2.1 detected   
DEBU[0000] [hostagent] AES accelerator seems available, prioritizing aes128-gcm@openssh.com and aes256-gcm@openssh.com 
INFO[0000] [hostagent] hostagent socket created at /home/jackson/.lima/test/ha.sock 
DEBU[0000] [hostagent] Start udp DNS listening on: 127.0.0.1:47162 
DEBU[0000] [hostagent] Start tcp DNS listening on: 127.0.0.1:41393 
DEBU[0001] [hostagent] QEMU version 8.1.3 detected      
DEBU[0001] [hostagent] firmware candidates = [/home/jackson/.local/share/qemu/edk2-x86_64-code.fd /home/linuxbrew/.linuxbrew/share/qemu/edk2-x86_64-code.fd /usr/share/OVMF/OVMF_CODE.fd /usr/share/qemu/ovmf-x86_64-code.bin /usr/share/edk2-ovmf/x64/OVMF_CODE.fd] 
DEBU[0001] [hostagent] Checking vhost directory /home/jackson/.local/share/qemu/vhost-user 
DEBU[0001] [hostagent] Checking vhost config 50-virtiofsd.json 
DEBU[0001] [hostagent] {fs /home/jackson/.cargo/bin/virtiofsd} 
DEBU[0001] [hostagent] vhostCmd[0].Args: [/home/jackson/.cargo/bin/virtiofsd --socket-path /home/jackson/.lima/test/virtiofsd-0.sock --shared-dir /home/jackson] 
DEBU[0001] [hostagent] Try waiting for /home/jackson/.lima/test/virtiofsd-0.sock to appear (attempt 0) 
DEBU[0001] [hostagent] virtiofsd-0[stderr]: [2024-01-18T16:17:15Z WARN  virtiofsd::sandbox] Couldn't set the process uid as root: -1 
DEBU[0001] [hostagent] virtiofsd-0[stderr]: [2024-01-18T16:17:15Z WARN  virtiofsd::sandbox] Couldn't set the process gid as root: -1 
DEBU[0001] [hostagent] virtiofsd-0[stderr]: [2024-01-18T16:17:15Z INFO  virtiofsd] Waiting for vhost-user socket connection... 
DEBU[0001] [hostagent] Try waiting for /home/jackson/.lima/test/virtiofsd-0.sock to appear (attempt 1) 
DEBU[0001] [hostagent] vhostCmd[1].Args: [/home/jackson/.cargo/bin/virtiofsd --socket-path /home/jackson/.lima/test/virtiofsd-1.sock --shared-dir /tmp/lima] 
DEBU[0001] [hostagent] Try waiting for /home/jackson/.lima/test/virtiofsd-1.sock to appear (attempt 0) 
DEBU[0001] [hostagent] virtiofsd-1[stderr]: [2024-01-18T16:17:15Z WARN  virtiofsd::sandbox] Couldn't set the process uid as root: -1 
DEBU[0001] [hostagent] virtiofsd-1[stderr]: [2024-01-18T16:17:15Z WARN  virtiofsd::sandbox] Couldn't set the process gid as root: -1 
DEBU[0001] [hostagent] virtiofsd-1[stderr]: [2024-01-18T16:17:15Z INFO  virtiofsd] Waiting for vhost-user socket connection... 
DEBU[0001] [hostagent] Try waiting for /home/jackson/.lima/test/virtiofsd-1.sock to appear (attempt 1) 
INFO[0001] [hostagent] Starting QEMU (hint: to watch the boot progress, see "/home/jackson/.lima/test/serial*.log") 
DEBU[0001] [hostagent] qCmd.Args: [/home/linuxbrew/.linuxbrew/bin/qemu-system-x86_64 -m 4096 -object memory-backend-file,id=virtiofs-shm,size=4294967296,mem-path=/dev/shm,share=on -numa node,memdev=virtiofs-shm -cpu host -machine q35,accel=kvm -smp 4,sockets=1,cores=4,threads=1 -drive if=pflash,format=raw,readonly=on,file=/home/linuxbrew/.linuxbrew/share/qemu/edk2-x86_64-code.fd -boot order=c,splash-time=0,menu=on -drive file=/home/jackson/.lima/test/diffdisk,if=virtio,discard=on -drive id=cdrom0,if=none,format=raw,readonly=on,file=/home/jackson/.lima/test/cidata.iso -device virtio-scsi-pci,id=scsi0 -device scsi-cd,bus=scsi0.0,drive=cdrom0 -netdev user,id=net0,net=192.168.5.0/24,dhcpstart=192.168.5.15,hostfwd=tcp:127.0.0.1:41929-:22 -device virtio-net-pci,netdev=net0,mac=52:55:55:90:5f:fb -device virtio-rng-pci -display none -device virtio-vga -device virtio-keyboard-pci -device virtio-mouse-pci -device qemu-xhci,id=usb-bus -parallel none -chardev socket,id=char-serial,path=/home/jackson/.lima/test/serial.sock,server=on,wait=off,logfile=/home/jackson/.lima/test/serial.log -serial chardev:char-serial -chardev socket,id=char-serial-virtio,path=/home/jackson/.lima/test/serialv.sock,server=on,wait=off,logfile=/home/jackson/.lima/test/serialv.log -device virtio-serial-pci,id=virtio-serial0,max_ports=1 -device virtconsole,chardev=char-serial-virtio,id=console0 -chardev socket,id=char-virtiofs-0,path=/home/jackson/.lima/test/virtiofsd-0.sock -device vhost-user-fs-pci,queue-size=1024,chardev=char-virtiofs-0,tag=mount0 -chardev socket,id=char-virtiofs-1,path=/home/jackson/.lima/test/virtiofsd-1.sock -device vhost-user-fs-pci,queue-size=1024,chardev=char-virtiofs-1,tag=mount1 -chardev socket,id=char-qmp,path=/home/jackson/.lima/test/qmp.sock,server=on,wait=off -qmp chardev:char-qmp -chardev socket,path=/home/jackson/.lima/test/ga.sock,server=on,wait=off,id=qga0 -device virtio-serial -device virtserialport,chardev=qga0,name=io.lima-vm.guest_agent.0 -name lima-test -pidfile /home/jackson/.lima/test/qemu.pid] 
DEBU[0001] received an event                             event="{2024-01-18 11:17:16.116424632 -0500 EST {false false false [] 41929}}"
INFO[0001] SSH Local Port: 41929                        
INFO[0001] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
DEBU[0001] [hostagent] executing script "ssh"           
DEBU[0001] [hostagent] executing ssh for script "ssh": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0001] [hostagent] stdout="", stderr="ssh: connect to host 127.0.0.1 port 41929: Connection refused\r\n", err=failed to execute script "ssh": stdout="", stderr="ssh: connect to host 127.0.0.1 port 41929: Connection refused\r\n": exit status 255 
DEBU[0001] [hostagent] virtiofsd-1[stderr]: [2024-01-18T16:17:16Z INFO  virtiofsd] Client connected, servicing requests 
DEBU[0001] [hostagent] virtiofsd-0[stderr]: [2024-01-18T16:17:16Z INFO  virtiofsd] Client connected, servicing requests 
DEBU[0003] [hostagent] virtiofsd-0[stderr]: Warning: Cannot announce submounts, client does not support it 
DEBU[0003] [hostagent] virtiofsd-1[stderr]: Warning: Cannot announce submounts, client does not support it 
INFO[0011] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
DEBU[0011] [hostagent] executing script "ssh"           
DEBU[0011] [hostagent] executing ssh for script "ssh": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0017] [hostagent] stdout="", stderr="kex_exchange_identification: read: Connection reset by peer\r\n", err=failed to execute script "ssh": stdout="", stderr="kex_exchange_identification: read: Connection reset by peer\r\n": exit status 255 
INFO[0027] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
DEBU[0027] [hostagent] executing script "ssh"           
DEBU[0027] [hostagent] executing ssh for script "ssh": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0028] [hostagent] stdout="", stderr="mux_client_request_session: read from master failed: Broken pipe\r\nFailed to connect to new control master\r\n", err=failed to execute script "ssh": stdout="", stderr="mux_client_request_session: read from master failed: Broken pipe\r\nFailed to connect to new control master\r\n": exit status 255 
INFO[0038] [hostagent] Waiting for the essential requirement 1 of 2: "ssh" 
DEBU[0038] [hostagent] executing script "ssh"           
DEBU[0038] [hostagent] executing ssh for script "ssh": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0039] [hostagent] stdout="", stderr="", err=<nil>  
INFO[0039] [hostagent] The essential requirement 1 of 2 is satisfied 
INFO[0039] [hostagent] Waiting for the essential requirement 2 of 2: "user session is ready for ssh" 
DEBU[0039] [hostagent] executing script "user session is ready for ssh" 
DEBU[0039] [hostagent] executing ssh for script "user session is ready for ssh": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0039] [hostagent] stdout="", stderr="+ timeout 30s bash -c 'until sudo diff -q /run/lima-ssh-ready /mnt/lima-cidata/meta-data 2>/dev/null; do sleep 3; done'\n", err=<nil> 
INFO[0039] [hostagent] The essential requirement 2 of 2 is satisfied 
INFO[0039] [hostagent] Waiting for the optional requirement 1 of 2: "systemd must be available" 
DEBU[0039] [hostagent] executing script "systemd must be available" 
DEBU[0039] [hostagent] Forwarding unix sockets          
DEBU[0039] [hostagent] executing ssh for script "systemd must be available": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
INFO[0039] [hostagent] Guest agent is running           
DEBU[0039] [hostagent] guest agent info: &{LocalPorts:[{IP:127.0.0.54 Port:53} {IP:127.0.0.53 Port:53} {IP::: Port:22}]} 
DEBU[0039] [hostagent] guest agent event: {Time:2024-01-18 16:17:54.153174836 +0000 UTC LocalPortsAdded:[{IP:127.0.0.54 Port:53} {IP:127.0.0.53 Port:53} {IP::: Port:22}] LocalPortsRemoved:[] Errors:[]} 
INFO[0039] [hostagent] Not forwarding TCP 127.0.0.54:53 
INFO[0039] [hostagent] Not forwarding TCP 127.0.0.53:53 
INFO[0039] [hostagent] Not forwarding TCP [::]:22       
DEBU[0039] [hostagent] stdout="", stderr="+ command -v systemctl\n", err=<nil> 
INFO[0039] [hostagent] The optional requirement 1 of 2 is satisfied 
INFO[0039] [hostagent] Waiting for the optional requirement 2 of 2: "containerd binaries to be installed" 
DEBU[0039] [hostagent] executing script "containerd binaries to be installed" 
DEBU[0039] [hostagent] executing ssh for script "containerd binaries to be installed": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0039] [hostagent] stdout="/usr/local/bin/nerdctl\n", stderr="+ timeout 30s bash -c 'until command -v nerdctl || test -x /usr/local/bin/nerdctl; do sleep 3; done'\n", err=<nil> 
INFO[0039] [hostagent] The optional requirement 2 of 2 is satisfied 
INFO[0039] [hostagent] Waiting for the guest agent to be running 
INFO[0039] [hostagent] Waiting for the final requirement 1 of 1: "boot scripts must have finished" 
DEBU[0039] [hostagent] executing script "boot scripts must have finished" 
DEBU[0039] [hostagent] executing ssh for script "boot scripts must have finished": /usr/bin/ssh [ssh -F /dev/null -o IdentityFile="/home/jackson/.lima/_config/user" -o IdentityFile="/home/jackson/.ssh/id_ed25519" -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o NoHostAuthenticationForLocalhost=yes -o GSSAPIAuthentication=no -o PreferredAuthentications=publickey -o Compression=no -o BatchMode=yes -o IdentitiesOnly=yes -o Ciphers="^aes128-gcm@openssh.com,aes256-gcm@openssh.com" -o User=jackson -o ControlMaster=auto -o ControlPath="/home/jackson/.lima/test/ssh.sock" -o ControlPersist=yes -p 41929 127.0.0.1 -- /bin/bash] 
DEBU[0039] [hostagent] stdout="", stderr="+ timeout 30s bash -c 'until sudo diff -q /run/lima-boot-done /mnt/lima-cidata/meta-data 2>/dev/null; do sleep 3; done'\n", err=<nil> 
INFO[0039] [hostagent] The final requirement 1 of 1 is satisfied 
DEBU[0039] received an event                             event="{2024-01-18 11:17:54.508367788 -0500 EST {true false false [] 41929}}"
INFO[0039] READY. Run `limactl shell test` to open the shell.