virtiofsd: doesn't garant write access at users allowed by group permission
I'm using Proxmox in an non standard configuration in my little home server with mdadm raid and virtiofsd to pass a directory tree from the host to a guest virtual machine.
The virtiofsd bin included in proxmox is:
# /usr/lib/kvm/virtiofsd -V
using FUSE kernel interface version 7.32
but I also have tested with same results with bins compiled from sources, stable and dev branches:
# /opt/virtiofsd -V
using FUSE kernel interface version 7.27
# /opt/virtiofsd -V
virtiofsd version 5.2.95
Copyright (c) 2003-2021 Fabrice Bellard and the QEMU Project developers
using FUSE kernel interface version 7.33
In Proxmox I start virtiofsd with this configuration:
/usr/lib/kvm/virtiofsd --socket-path=/var/run/virtiofsd-data-VM1.sock -o source=/media/data/vm1/ -o cache=always -o debug
-chardev socket,id=char0,path=/var/run/virtiofsd-data-VM1.sock -device vhost-user-fs-pci,chardev=char0,tag=data -object memory-backend-memfd,id=mem,size=4096M,share=on -numa node,memdev=mem
In my Virtual machine I mount everything with fstab:
data /media/data virtiofs rw 0 2
At the moment my Virtual Machine is a Debian Buster with kernel from Backports:
$ uname -a
Linux debian 5.10.0-0.bpo.5-amd64 #1 SMP Debian 5.10.24-1~bpo10+1 (2021-03-29) x86_64 GNU/Linux
But I also have tested the latest Ubuntu server with same result.
The problem is the following.
The source /media/data/vm1/
passed from the host, in the guest becomes /media/data
and in it there is the following directories tree with the following permissions:
$ ls -la /media/data/
total 16
drwxrwxr-x 4 root root 4096 mag 30 17:15 .
drwxr-xr-x 4 root root 4096 apr 27 17:41 ..
drwxrwx--- 7 root users 4096 mag 30 17:14 Documents
drwxrwxr-x 6 root users 4096 lug 15 2019 www
but if I try to write something in /media/data/Documents with an user that is in the users
group I have a permission denied error:
$ touch /media/data/Documents/test.txt
touch: cannot touch ‘/media/data/Documents/test.txt’: Permission denied
obviously I don't have any problem in writing in ‘/media/data/Documents/’ with sudo and the strange thing is that also if I'm not able to write in the directory with my user, instead I'm able to read its content:
$ ls -la /media/data/Documents/
total 8
drwxrwx--- 7 root users 4096 mag 30 18:26 .
drwxrwxr-x 4 root root 4096 mag 30 17:15 ..
-rw-r--r-- 1 root root 0 mag 30 18:26 test2.txt
-rw-r--r-- 1 root root 0 mag 30 18:26 test3.txt
-rw-r--r-- 1 root root 0 mag 30 18:26 test.txt
When the permission denied error happens, in virtiofsd I have only this log:
[2021-05-31 19:37:09.57+0200] [ID: 00044533] virtio_session_mount: Waiting for vhost-user socket connection...
[2021-05-31 19:37:16.48+0200] [ID: 00044533] virtio_session_mount: Received vhost-user socket connection
[2021-05-31 19:37:16.48+0200] [ID: 00000001] virtio_loop: Entry
[2021-05-31 19:37:16.48+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:17.40+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] fv_queue_set_started: qidx=0 started=1
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.96+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] fv_queue_set_started: qidx=1 started=1
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000004] fv_queue_thread: Start for queue 1 kick_fd 12
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Got VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000003] fv_queue_thread: Start for queue 0 kick_fd 9
[2021-05-31 19:37:33.97+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:37:33.97+0200] [ID: 00000001] virtio_loop: Waiting for VU event
[2021-05-31 19:37:33.97+0200] [ID: 00000003] fv_queue_thread: Waiting for Queue 0 event
[2021-05-31 19:37:33.97+0200] [ID: 00000003] fv_queue_thread: Got queue event on Queue 0
[2021-05-31 19:37:33.97+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:37:33.97+0200] [ID: 00000003] fv_queue_thread: Queue 0 gave evalue: 1 available: in: 0 out: 0
[2021-05-31 19:37:33.97+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 0 out: 0
[2021-05-31 19:37:33.97+0200] [ID: 00000003] fv_queue_thread: Waiting for Queue 0 event
[2021-05-31 19:37:33.97+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:37:34.33+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:37:34.33+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 80 out: 56
[2021-05-31 19:37:34.33+0200] [ID: 00000004] fv_queue_worker: elem 0: with 2 out desc of length 56 bad_in_num=0 bad_out_num=0
[2021-05-31 19:37:34.33+0200] [ID: 00000004] unique: 2, opcode: INIT (26), nodeid: 0, insize: 56, pid: 0
[2021-05-31 19:37:34.33+0200] [ID: 00000004] INIT: 7.32
[2021-05-31 19:37:34.33+0200] [ID: 00000004] flags=0x0bfffffb
[2021-05-31 19:37:34.33+0200] [ID: 00000004] max_readahead=0x00020000
[2021-05-31 19:37:34.33+0200] [ID: 00000004] lo_init: disabling flock locks
[2021-05-31 19:37:34.33+0200] [ID: 00000004] lo_init: disabling posix locks
[2021-05-31 19:37:34.33+0200] [ID: 00000004] lo_init: disabling killpriv_v2
[2021-05-31 19:37:34.33+0200] [ID: 00000004] INIT: 7.33
[2021-05-31 19:37:34.33+0200] [ID: 00000004] flags=0x0044f039
[2021-05-31 19:37:34.33+0200] [ID: 00000004] max_readahead=0x00020000
[2021-05-31 19:37:34.33+0200] [ID: 00000004] max_write=0x00100000
[2021-05-31 19:37:34.33+0200] [ID: 00000004] max_background=0
[2021-05-31 19:37:34.33+0200] [ID: 00000004] congestion_threshold=0
[2021-05-31 19:37:34.33+0200] [ID: 00000004] time_gran=1
[2021-05-31 19:37:34.33+0200] [ID: 00000004] map_alignment=0
[2021-05-31 19:37:34.33+0200] [ID: 00000004] unique: 2, success, outsize: 80
[2021-05-31 19:37:34.33+0200] [ID: 00000004] virtio_send_msg: elem 0: with 2 in desc of length 80
[2021-05-31 19:37:34.33+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 120 out: 56
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_worker: elem 0: with 2 out desc of length 56 bad_in_num=0 bad_out_num=0
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 4, opcode: GETATTR (3), nodeid: 1, insize: 56, pid: 504
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 4, success, outsize: 120
[2021-05-31 19:38:02.59+0200] [ID: 00000004] virtio_send_msg: elem 0: with 2 in desc of length 120
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 45
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_worker: elem 0: with 2 out desc of length 45 bad_in_num=0 bad_out_num=0
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 6, opcode: LOOKUP (1), nodeid: 1, insize: 45, pid: 504
[2021-05-31 19:38:02.59+0200] [ID: 00000004] lo_lookup(parent=1, name=Documents)
[2021-05-31 19:38:02.59+0200] [ID: 00000004] 1/Documents -> 2
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 6, success, outsize: 144
[2021-05-31 19:38:02.59+0200] [ID: 00000004] virtio_send_msg: elem 0: with 2 in desc of length 144
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 144 out: 49
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_worker: elem 0: with 2 out desc of length 49 bad_in_num=0 bad_out_num=0
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 8, opcode: LOOKUP (1), nodeid: 2, insize: 49, pid: 504
[2021-05-31 19:38:02.59+0200] [ID: 00000004] lo_lookup(parent=2, name=test.txt)
[2021-05-31 19:38:02.59+0200] [ID: 00000004] 2/test.txt -> 3
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 8, success, outsize: 144
[2021-05-31 19:38:02.59+0200] [ID: 00000004] virtio_send_msg: elem 0: with 2 in desc of length 144
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 120 out: 56
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_worker: elem 0: with 2 out desc of length 56 bad_in_num=0 bad_out_num=0
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 10, opcode: GETATTR (3), nodeid: 3, insize: 56, pid: 504
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 10, success, outsize: 120
[2021-05-31 19:38:02.59+0200] [ID: 00000004] virtio_send_msg: elem 0: with 2 in desc of length 120
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Got queue event on Queue 1
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Queue 1 gave evalue: 1 available: in: 120 out: 56
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_worker: elem 0: with 2 out desc of length 56 bad_in_num=0 bad_out_num=0
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 12, opcode: GETATTR (3), nodeid: 3, insize: 56, pid: 504
[2021-05-31 19:38:02.59+0200] [ID: 00000004] unique: 12, success, outsize: 120
[2021-05-31 19:38:02.59+0200] [ID: 00000004] virtio_send_msg: elem 0: with 2 in desc of length 120
[2021-05-31 19:38:02.59+0200] [ID: 00000004] fv_queue_thread: Waiting for Queue 1 event
The problem shouldn't be about my permissions, in fact if I copy ‘/media/’ with same permissions (cp -rp) outside the mount point provided by virtiofsd, for example in /tmp/media/data/Documents/, then everything works correctly and I'm able to write and read with the users in the users group.
I also noticed that if I change the ownership of /media/data/Documents from root:users to root:myuser then the user 'myuser' is able to write in that directory.
At the moment to solve this problem I had to change the permission of /media/data/Documents from 770 to 777 but this isn't a great solution. I have also discovered that if I change the permission from 777 to 776 I still have permission denied error If I try to write in the directory.
Is this a known bug or m'I doing some error?