Re: USB-hotplugging fails with "failed to load cgroup BPF prog: Operation not permitted" on cgroups v2
On Mon, Jan 20, 2020 at 09:00:15PM +0100, Pol Van Aubel wrote:
Hi,
Quoting Pavel Hrdina (2020-01-20 14:29:36)
On Sat, Jan 18, 2020 at 11:17:11PM +0100, Pol Van Aubel wrote:
Hi all,
I've disabled cgroups v1 on my system with the kernel boot option "systemd.unified_cgroup_hierarchy=1". Since doing so, USB hotplugging fails to work, seemingly due to a permissions problem with BPF. Please note that the technique I'm going to describe worked just fine for hotplugging USB devices to running domains until this change. Attaching / detaching USB devices when the domain is down still works as expected.
I get the same error when attaching a device in virt-manager, as I do when running the following command:
sudo virsh attach-device wenger /dev/stdin --persistent <<END <hostdev mode='subsystem' type='usb' managed='yes'> <source startupPolicy='optional'> <vendor id='0x046d' /> <product id='0xc215' /> </source> </hostdev> END
This returns error: Failed to attach device from /dev/stdin error: failed to load cgroup BPF prog: Operation not permitted
virt-manager returns basically the same error, but for completeness' sake, here it is:
failed to load cgroup BPF prog: Operation not permitted
Traceback (most recent call last): File "/usr/share/virt-manager/virtManager/addhardware.py", line 1327, in _add_device self.vm.attach_device(dev) File "/usr/share/virt-manager/virtManager/object/domain.py", line 920, in attach_device self._backend.attachDevice(devxml) File "/usr/lib/python3.8/site-packages/libvirt.py", line 590, in attachDevice if ret == -1: raise libvirtError ('virDomainAttachDevice() failed', dom=self) libvirt.libvirtError: failed to load cgroup BPF prog: Operation not permitted
Now, libvirtd is running as root, so I don't understand why any operation on BPF programs is not permitted. I've dug into libvirt's code a bit to see what is throwing this error and it boils down to <https://github.com/libvirt/libvirt/blob/7d608469621a3fda72dff2a89308e68cc9fb4c9a/src/util/vircgroupv2devices.c#L292-L296> and <https://github.com/libvirt/libvirt/blob/02bf7cc68bfc76242f02d23e73cad36618f3f790/src/util/virbpf.c#L54> but I have no clue what that syscall is doing, so that's where my debugging capability basically ends.
Maybe this is something as simple as setting the right ACL somewhere. I haven't touched /etc/libvirt/qemu.conf except for setting nvram. There *is* something about cgroup_device_acl there but afaict that's for cgroups v1, when there was still a device cgroup controller. Any help would be greatly appreciated.
Domain log files: Upon execution of the above commands, nothing gets added to the domain log in /var/log/qemu/wenger.log, so I've decided they're likely irrelevant to the issue. Please ask for any additional info required.
System information: Arch Linux, (normal) kernel 5.4.11 libvirt 5.10.0 qemu 4.2.0, using KVM. Host system is x86_64 on an intel 5820k. Guest system is probably irrelevant, but is Windows 10 on the same.
Possibly relevant kernel build options: $ zgrep BPF /proc/config.gz [22:55:52]: zgrep BPF /proc/config.gz
CONFIG_CGROUP_BPF=y CONFIG_BPF=y CONFIG_BPF_SYSCALL=y CONFIG_BPF_JIT_ALWAYS_ON=y CONFIG_IPV6_SEG6_BPF=y CONFIG_NETFILTER_XT_MATCH_BPF=m # CONFIG_BPFILTER is not set CONFIG_NET_CLS_BPF=m CONFIG_NET_ACT_BPF=m CONFIG_BPF_JIT=y CONFIG_BPF_STREAM_PARSER=y CONFIG_LWTUNNEL_BPF=y CONFIG_HAVE_EBPF_JIT=y CONFIG_BPF_EVENTS=y # CONFIG_BPF_KPROBE_OVERRIDE is not set # CONFIG_TEST_BPF is not set
Hi
I've installed clean archlinux to try this out and it works as expected, I'm able to attach USB device into a VM.
My system env is mostly the same as yours except for kernel version:
kernel 5.4.13 libvirt 5.10.0 qemu 4.2.0, using KVM.
Please enable libvirt debug logs [1] and share the output with us.
I've updated to 5.4.13 and created a barebones VM without storage to reproduce the behaviour. libvirtd debug logs are attached. There appear to be two BPF failures of the same BPF program (?). The first is on line 23209, which appears to be part of machine startup, and which I don't actually notice. The second one is where I manually add the USB device, on line 30599.
Thanks,
Thanks for the logs, but it did not help to figure out where the issue is. I was hoping to see some error output from the syscall but the line that should contain it is empty: 2020-01-20 19:47:15.589+0000: 8579: debug : virBPFLoadProg:78 : Can you please check system logs and output of dmesg? I've managed to run into this article [1] that explains that even if you have all permissions and no SELinux you can still be blocked by something called kernel_lockdown and it should appear in dmesg. Pavel [1] <https://gehrcke.de/2019/09/running-an-ebpf-program-may-require-lifting-the-kernel-lockdown/>
Hi, Quoting Pavel Hrdina (2020-01-21 12:53:49)
On Mon, Jan 20, 2020 at 09:00:15PM +0100, Pol Van Aubel wrote:
Hi,
Quoting Pavel Hrdina (2020-01-20 14:29:36)
On Sat, Jan 18, 2020 at 11:17:11PM +0100, Pol Van Aubel wrote:
Hi all,
I've disabled cgroups v1 on my system with the kernel boot option "systemd.unified_cgroup_hierarchy=1". Since doing so, USB hotplugging fails to work, seemingly due to a permissions problem with BPF. Please note that the technique I'm going to describe worked just fine for hotplugging USB devices to running domains until this change. Attaching / detaching USB devices when the domain is down still works as expected.
I get the same error when attaching a device in virt-manager, as I do when running the following command:
sudo virsh attach-device wenger /dev/stdin --persistent <<END <hostdev mode='subsystem' type='usb' managed='yes'> <source startupPolicy='optional'> <vendor id='0x046d' /> <product id='0xc215' /> </source> </hostdev> END
This returns error: Failed to attach device from /dev/stdin error: failed to load cgroup BPF prog: Operation not permitted
virt-manager returns basically the same error, but for completeness' sake, here it is:
failed to load cgroup BPF prog: Operation not permitted
Traceback (most recent call last): File "/usr/share/virt-manager/virtManager/addhardware.py", line 1327, in _add_device self.vm.attach_device(dev) File "/usr/share/virt-manager/virtManager/object/domain.py", line 920, in attach_device self._backend.attachDevice(devxml) File "/usr/lib/python3.8/site-packages/libvirt.py", line 590, in attachDevice if ret == -1: raise libvirtError ('virDomainAttachDevice() failed', dom=self) libvirt.libvirtError: failed to load cgroup BPF prog: Operation not permitted
Now, libvirtd is running as root, so I don't understand why any operation on BPF programs is not permitted. I've dug into libvirt's code a bit to see what is throwing this error and it boils down to <https://github.com/libvirt/libvirt/blob/7d608469621a3fda72dff2a89308e68cc9fb4c9a/src/util/vircgroupv2devices.c#L292-L296> and <https://github.com/libvirt/libvirt/blob/02bf7cc68bfc76242f02d23e73cad36618f3f790/src/util/virbpf.c#L54> but I have no clue what that syscall is doing, so that's where my debugging capability basically ends.
Maybe this is something as simple as setting the right ACL somewhere. I haven't touched /etc/libvirt/qemu.conf except for setting nvram. There *is* something about cgroup_device_acl there but afaict that's for cgroups v1, when there was still a device cgroup controller. Any help would be greatly appreciated.
Domain log files: Upon execution of the above commands, nothing gets added to the domain log in /var/log/qemu/wenger.log, so I've decided they're likely irrelevant to the issue. Please ask for any additional info required.
System information: Arch Linux, (normal) kernel 5.4.11 libvirt 5.10.0 qemu 4.2.0, using KVM. Host system is x86_64 on an intel 5820k. Guest system is probably irrelevant, but is Windows 10 on the same.
Possibly relevant kernel build options: $ zgrep BPF /proc/config.gz [22:55:52]: zgrep BPF /proc/config.gz
CONFIG_CGROUP_BPF=y CONFIG_BPF=y CONFIG_BPF_SYSCALL=y CONFIG_BPF_JIT_ALWAYS_ON=y CONFIG_IPV6_SEG6_BPF=y CONFIG_NETFILTER_XT_MATCH_BPF=m # CONFIG_BPFILTER is not set CONFIG_NET_CLS_BPF=m CONFIG_NET_ACT_BPF=m CONFIG_BPF_JIT=y CONFIG_BPF_STREAM_PARSER=y CONFIG_LWTUNNEL_BPF=y CONFIG_HAVE_EBPF_JIT=y CONFIG_BPF_EVENTS=y # CONFIG_BPF_KPROBE_OVERRIDE is not set # CONFIG_TEST_BPF is not set
Hi
I've installed clean archlinux to try this out and it works as expected, I'm able to attach USB device into a VM.
My system env is mostly the same as yours except for kernel version:
kernel 5.4.13 libvirt 5.10.0 qemu 4.2.0, using KVM.
Please enable libvirt debug logs [1] and share the output with us.
I've updated to 5.4.13 and created a barebones VM without storage to reproduce the behaviour. libvirtd debug logs are attached. There appear to be two BPF failures of the same BPF program (?). The first is on line 23209, which appears to be part of machine startup, and which I don't actually notice. The second one is where I manually add the USB device, on line 30599.
Thanks,
Thanks for the logs, but it did not help to figure out where the issue is. I was hoping to see some error output from the syscall but the line that should contain it is empty:
2020-01-20 19:47:15.589+0000: 8579: debug : virBPFLoadProg:78 :
Can you please check system logs and output of dmesg?
I've managed to run into this article [1] that explains that even if you have all permissions and no SELinux you can still be blocked by something called kernel_lockdown and it should appear in dmesg.
Pavel
[1] <https://gehrcke.de/2019/09/running-an-ebpf-program-may-require-lifting-the-kernel-lockdown/>
Unfortunately, nothing related to kernel lockdowns. My kernel sysrq also doesn't seem to recognize x, and neither dmesg nor system journal indicate the system is even booted with lockdowns. I don't run Secure Boot, so that makes sense. I do get an audit message but that doesn't really enlighten me any further; there's only 4 messages in the journal related to this action. Newlines added for clarity with line wrap. Jan 21 23:29:33 victorinox libvirtd[790]: failed to load cgroup BPF prog: Operation not permitted Jan 21 23:29:33 victorinox audit[790]: VIRT_RESOURCE pid=790 uid=0 auid=4294967295 ses=4294967295 msg='virt=kvm resrc=cgroup reason=allow vm="testvm" uuid=4da0d457-2e1f-4c53-87fc-530858e5e4cb cgroup="/sys/fs/cgroup/machine.slice/machine-qemu\x2d1\x2dtestvm.scope/" class=path path="/dev/bus/usb/002/011" rdev=BD:8A acl=rw exe="/usr/bin/libvirtd" hostname=? addr=? terminal=? res=failed' Jan 21 23:29:33 victorinox libvirtd[790]: Tried to close invalid fd 29 Jan 21 23:29:33 victorinox kernel: audit: type=2501 audit(1579645773.264:202): pid=790 uid=0 auid=4294967295 ses=4294967295 msg='virt=kvm resrc=cgroup reason=allow vm="testvm" uuid=4da0d457-2e1f-4c53-87fc-530858e5e4cb cgroup="/sys/fs/cgroup/machine.slice/machine-qemu\x2d1\x2dtestvm.scope/" class=path path="/dev/bus/usb/002/011" rdev=BD:8A acl=rw exe="/usr/bin/libvirtd" hostname=? addr=? terminal=? res=failed' I honestly don't know how to even begin debugging what's happening, what the reason for the rejection is. -- Pol P.S. My previous message got rejected from the list because I wasn't thinking and attached 3MiB of debug logs. Since Pavel hasn't found what he was looking for in them I figure it makes little sense to upload and link them, the rest of the message is included inline.
Hi, Quoting Pol Van Aubel (2020-01-21 23:41:48)
Hi,
Quoting Pavel Hrdina (2020-01-21 12:53:49)
Thanks for the logs, but it did not help to figure out where the issue is. I was hoping to see some error output from the syscall but the line that should contain it is empty:
2020-01-20 19:47:15.589+0000: 8579: debug : virBPFLoadProg:78 :
Can you please check system logs and output of dmesg?
I've managed to run into this article [1] that explains that even if you have all permissions and no SELinux you can still be blocked by something called kernel_lockdown and it should appear in dmesg.
Pavel
[1] <https://gehrcke.de/2019/09/running-an-ebpf-program-may-require-lifting-the-kernel-lockdown/>
Unfortunately, nothing related to kernel lockdowns. My kernel sysrq also doesn't seem to recognize x, and neither dmesg nor system journal indicate the system is even booted with lockdowns. I don't run Secure Boot, so that makes sense. I do get an audit message but that doesn't really enlighten me any further; there's only 4 messages in the journal related to this action.
<snip>
I honestly don't know how to even begin debugging what's happening, what the reason for the rejection is.
I've spent a long afternoon reading into BPF, checking that I'm really running this as root, with CAP_SYS_ADMIN, etc, and am drawing a blank. Everything I'm looking at is telling me this *should* work, but it doesn't. Does anyone have a suggestion of how to either efficiently debug this issue (I'm not too familiar with tracing, but figuring out where the rejection actually happens might help?), or where to put the question instead? -- Pol
Hi, Top-posting a quick update to this: it has magically started working with linux 5.6.10. Didn't on 5.5.13 nor 5.4.35-lts. So the problem has been solved, even though I never got to trace it to its source. -- Pol Quoting Pol Van Aubel (2020-02-15 17:16:14)
Hi,
Quoting Pol Van Aubel (2020-01-21 23:41:48)
Hi,
Quoting Pavel Hrdina (2020-01-21 12:53:49)
Thanks for the logs, but it did not help to figure out where the issue is. I was hoping to see some error output from the syscall but the line that should contain it is empty:
2020-01-20 19:47:15.589+0000: 8579: debug : virBPFLoadProg:78 :
Can you please check system logs and output of dmesg?
I've managed to run into this article [1] that explains that even if you have all permissions and no SELinux you can still be blocked by something called kernel_lockdown and it should appear in dmesg.
Pavel
[1] <https://gehrcke.de/2019/09/running-an-ebpf-program-may-require-lifting-the-kernel-lockdown/>
Unfortunately, nothing related to kernel lockdowns. My kernel sysrq also doesn't seem to recognize x, and neither dmesg nor system journal indicate the system is even booted with lockdowns. I don't run Secure Boot, so that makes sense. I do get an audit message but that doesn't really enlighten me any further; there's only 4 messages in the journal related to this action.
<snip>
I honestly don't know how to even begin debugging what's happening, what the reason for the rejection is.
I've spent a long afternoon reading into BPF, checking that I'm really running this as root, with CAP_SYS_ADMIN, etc, and am drawing a blank. Everything I'm looking at is telling me this *should* work, but it doesn't.
Does anyone have a suggestion of how to either efficiently debug this issue (I'm not too familiar with tracing, but figuring out where the rejection actually happens might help?), or where to put the question instead?
-- Pol
participants (2)
-
Pavel Hrdina -
Pol Van Aubel