* qemu-system-aarch64: Failed to retrieve host CPU features
@ 2022-08-12 2:14 Vitaly Chikunov
2022-08-12 8:45 ` Vitaly Chikunov
0 siblings, 1 reply; 14+ messages in thread
From: Vitaly Chikunov @ 2022-08-12 2:14 UTC (permalink / raw)
To: qemu-arm, Peter Maydell; +Cc: Dmitry V. Levin
Hi,
I noticed that we starting to get many errors like this:
qemu-system-aarch64: Failed to retrieve host CPU features
Where many is 1-2% per run, depends on host, host is Kunpeng-920, and
Linux kernel is v5.15.59, but it started to appear months before that.
strace shows in erroneous case:
1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call)
And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu:
vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size);
if (vmfd < 0) {
goto err;
}
Maybe it should restart ioctl on EINTR?
I don't see EINTR documented in ioctl(2) nor in Linux'
Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it
says "an unmasked signal is pending".
Thanks,
^ permalink raw reply [flat|nested] 14+ messages in thread* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-12 2:14 qemu-system-aarch64: Failed to retrieve host CPU features Vitaly Chikunov @ 2022-08-12 8:45 ` Vitaly Chikunov 2022-08-12 9:25 ` Peter Maydell 0 siblings, 1 reply; 14+ messages in thread From: Vitaly Chikunov @ 2022-08-12 8:45 UTC (permalink / raw) To: qemu-arm, Peter Maydell; +Cc: Dmitry V. Levin On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > Hi, > > I noticed that we starting to get many errors like this: > > qemu-system-aarch64: Failed to retrieve host CPU features > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > Linux kernel is v5.15.59, but it started to appear months before that. > > strace shows in erroneous case: > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > if (vmfd < 0) { > goto err; > } > > Maybe it should restart ioctl on EINTR? > > I don't see EINTR documented in ioctl(2) nor in Linux' > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > says "an unmasked signal is pending". I am suggested that almost any blocking syscall could return EINTR, so I checked the strace log and it does not show evidence of arriving a signal, the log ends like this: 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) 1152244 close(9) = 0 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 1152244 exit_group(1) = ? 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? 1152245 +++ exited with 1 +++ 1152244 +++ exited with 1 +++ Thanks, > > Thanks, > ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-12 8:45 ` Vitaly Chikunov @ 2022-08-12 9:25 ` Peter Maydell 0 siblings, 0 replies; 14+ messages in thread From: Peter Maydell @ 2022-08-12 9:25 UTC (permalink / raw) To: Vitaly Chikunov; +Cc: qemu-arm, kvmarm, QEMU Developers, Dmitry V. Levin I've added some more relevant mailing lists to the cc. On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > I noticed that we starting to get many errors like this: > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > strace shows in erroneous case: > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > if (vmfd < 0) { > > goto err; > > } > > > > Maybe it should restart ioctl on EINTR? > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > says "an unmasked signal is pending". > > I am suggested that almost any blocking syscall could return EINTR, so I > checked the strace log and it does not show evidence of arriving a signal, > the log ends like this: > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > 1152244 close(9) = 0 > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > 1152244 exit_group(1) = ? > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > 1152245 +++ exited with 1 +++ > 1152244 +++ exited with 1 +++ KVM folks: should we expect that KVM_CREATE_VM might fail EINTR and need retrying? (I suspect the answer is "yes", given we do this in the generic code in kvm-all.c.) thanks -- PMM _______________________________________________ kvmarm mailing list kvmarm@lists.cs.columbia.edu https://lists.cs.columbia.edu/mailman/listinfo/kvmarm ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features @ 2022-08-12 9:25 ` Peter Maydell 0 siblings, 0 replies; 14+ messages in thread From: Peter Maydell @ 2022-08-12 9:25 UTC (permalink / raw) To: Vitaly Chikunov; +Cc: qemu-arm, Dmitry V. Levin, QEMU Developers, kvmarm I've added some more relevant mailing lists to the cc. On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > I noticed that we starting to get many errors like this: > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > strace shows in erroneous case: > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > if (vmfd < 0) { > > goto err; > > } > > > > Maybe it should restart ioctl on EINTR? > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > says "an unmasked signal is pending". > > I am suggested that almost any blocking syscall could return EINTR, so I > checked the strace log and it does not show evidence of arriving a signal, > the log ends like this: > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > 1152244 close(9) = 0 > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > 1152244 exit_group(1) = ? > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > 1152245 +++ exited with 1 +++ > 1152244 +++ exited with 1 +++ KVM folks: should we expect that KVM_CREATE_VM might fail EINTR and need retrying? (I suspect the answer is "yes", given we do this in the generic code in kvm-all.c.) thanks -- PMM ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-12 9:25 ` Peter Maydell @ 2022-08-12 15:02 ` Marc Zyngier -1 siblings, 0 replies; 14+ messages in thread From: Marc Zyngier @ 2022-08-12 15:02 UTC (permalink / raw) To: Peter Maydell, Vitaly Chikunov Cc: qemu-arm, Dmitry V. Levin, kvmarm, QEMU Developers Hi Peter, On Fri, 12 Aug 2022 10:25:55 +0100, Peter Maydell <peter.maydell@linaro.org> wrote: > > I've added some more relevant mailing lists to the cc. > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > I noticed that we starting to get many errors like this: > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > strace shows in erroneous case: > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > if (vmfd < 0) { > > > goto err; > > > } > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > says "an unmasked signal is pending". > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > checked the strace log and it does not show evidence of arriving a signal, > > the log ends like this: > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > 1152244 close(9) = 0 > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > 1152244 exit_group(1) = ? > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > 1152245 +++ exited with 1 +++ > > 1152244 +++ exited with 1 +++ > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > and need retrying? In general, yes. But for this particular one, this is pretty odd. The only path I can so far see that would match this behaviour is if mm_take_all_locks() (called from __mmu_notifier_register()) was getting interrupted by a signal (I'm looking at a 5.19-ish kernel, which may slightly differ from the 5.15 mentioned above). But as Vitaly points out, it doesn't seem to be a signal delivered here. Vitaly: could you please share your exact test case (full qemu command line), and instrument your kernel to see if mm_take_all_locks() is the one failing? Thanks, M. -- Without deviation from the norm, progress is not possible. _______________________________________________ kvmarm mailing list kvmarm@lists.cs.columbia.edu https://lists.cs.columbia.edu/mailman/listinfo/kvmarm ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features @ 2022-08-12 15:02 ` Marc Zyngier 0 siblings, 0 replies; 14+ messages in thread From: Marc Zyngier @ 2022-08-12 15:02 UTC (permalink / raw) To: Peter Maydell, Vitaly Chikunov Cc: qemu-arm, kvmarm, QEMU Developers, Dmitry V. Levin Hi Peter, On Fri, 12 Aug 2022 10:25:55 +0100, Peter Maydell <peter.maydell@linaro.org> wrote: > > I've added some more relevant mailing lists to the cc. > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > I noticed that we starting to get many errors like this: > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > strace shows in erroneous case: > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > if (vmfd < 0) { > > > goto err; > > > } > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > says "an unmasked signal is pending". > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > checked the strace log and it does not show evidence of arriving a signal, > > the log ends like this: > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > 1152244 close(9) = 0 > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > 1152244 exit_group(1) = ? > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > 1152245 +++ exited with 1 +++ > > 1152244 +++ exited with 1 +++ > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > and need retrying? In general, yes. But for this particular one, this is pretty odd. The only path I can so far see that would match this behaviour is if mm_take_all_locks() (called from __mmu_notifier_register()) was getting interrupted by a signal (I'm looking at a 5.19-ish kernel, which may slightly differ from the 5.15 mentioned above). But as Vitaly points out, it doesn't seem to be a signal delivered here. Vitaly: could you please share your exact test case (full qemu command line), and instrument your kernel to see if mm_take_all_locks() is the one failing? Thanks, M. -- Without deviation from the norm, progress is not possible. ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-12 15:02 ` Marc Zyngier @ 2022-08-13 11:11 ` Vitaly Chikunov -1 siblings, 0 replies; 14+ messages in thread From: Vitaly Chikunov @ 2022-08-13 11:11 UTC (permalink / raw) To: Marc Zyngier; +Cc: qemu-arm, Dmitry V. Levin, kvmarm, QEMU Developers Marc, On Fri, Aug 12, 2022 at 04:02:37PM +0100, Marc Zyngier wrote: > On Fri, 12 Aug 2022 10:25:55 +0100, > Peter Maydell <peter.maydell@linaro.org> wrote: > > > > I've added some more relevant mailing lists to the cc. > > > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > > I noticed that we starting to get many errors like this: > > > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > > > strace shows in erroneous case: > > > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > > if (vmfd < 0) { > > > > goto err; > > > > } > > > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > > says "an unmasked signal is pending". > > > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > > checked the strace log and it does not show evidence of arriving a signal, > > > the log ends like this: > > > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > 1152244 close(9) = 0 > > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > > 1152244 exit_group(1) = ? > > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > > 1152245 +++ exited with 1 +++ > > > 1152244 +++ exited with 1 +++ > > > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > > and need retrying? > > In general, yes. But for this particular one, this is pretty odd. > > The only path I can so far see that would match this behaviour is if > mm_take_all_locks() (called from __mmu_notifier_register()) was > getting interrupted by a signal (I'm looking at a 5.19-ish kernel, > which may slightly differ from the 5.15 mentioned above). > > But as Vitaly points out, it doesn't seem to be a signal delivered > here. > > Vitaly: could you please share your exact test case (full qemu command > line), and instrument your kernel to see if mm_take_all_locks() is the > one failing? Full command is `qemu-system-aarch64 -M accel=kvm:tcg -m 4096M -smp cores=8 -nodefaults -nographic -no-reboot -fsdev local,id=root,path=/,security_model=none,multidevs=remap -device virtio-9p-pci,fsdev=root,mount_tag=/dev/root -device virtio-rng-pci -serial mon:stdio -kernel /boot/vmlinuz-5.18.16-un-def-alt1 -initrd /usr/src/tmp/initramfs-5.18.16-un-def-alt1.img -sandbox on,spawn=deny -M virt,gic-version=3 -cpu max -append 'console=ttyAMA0 mitigations=off nokaslr quiet panic=-1 SCRIPT=/usr/src/tmp/tmp.458pkF5r8d'`. But a minified reproducer is `qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe`. I traced with kprobe event tracer with the probes: echo 'p kvm_dev_ioctl' > kprobe_events echo 'r kvm_dev_ioctl $retval' >> kprobe_events echo 'p mm_take_all_locks' >> kprobe_events echo 'r mm_take_all_locks $retval' >> kprobe_events Then run reproducer in the loop for ((i=0;i<100;i++));do echo $i; strace -fvo bb.$i qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe 2>&1 | grep Failed && break; done And on 97th iteration it's failed, strace log to check that PID is the same with the following trace: 3611463 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) Event trace log: qemu-system-aar-3611463 [002] d.... 342920.535549: p_kvm_dev_ioctl_0: (kvm_dev_ioctl+0x0/0x910) qemu-system-aar-3611463 [002] d.... 342920.535635: p_mm_take_all_locks_0: (mm_take_all_locks+0x0/0x390) qemu-system-aar-3611463 [002] ..... 342920.535657: r_mm_take_all_locks_0: (__mmu_notifier_register+0x44/0x200 <- mm_take_all_locks) arg1=0xfffffffc qemu-system-aar-3611463 [002] ..... 342920.535695: r_kvm_dev_ioctl_0: (__arm64_sys_ioctl+0xcc/0x124 <- kvm_dev_ioctl) arg1=0xfffffffffffffffc So that's mm_take_all_locks returns EINTR. (I tried also to make C reproducer which opens /dev/kvm and call `ioctl(kvm, KVM_CREATE_VM, 0)` in the loop and it does not reproduce the problem, so it seems it's also something additional that QEMU does.) Thanks, _______________________________________________ kvmarm mailing list kvmarm@lists.cs.columbia.edu https://lists.cs.columbia.edu/mailman/listinfo/kvmarm ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features @ 2022-08-13 11:11 ` Vitaly Chikunov 0 siblings, 0 replies; 14+ messages in thread From: Vitaly Chikunov @ 2022-08-13 11:11 UTC (permalink / raw) To: Marc Zyngier Cc: Peter Maydell, qemu-arm, kvmarm, QEMU Developers, Dmitry V. Levin Marc, On Fri, Aug 12, 2022 at 04:02:37PM +0100, Marc Zyngier wrote: > On Fri, 12 Aug 2022 10:25:55 +0100, > Peter Maydell <peter.maydell@linaro.org> wrote: > > > > I've added some more relevant mailing lists to the cc. > > > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > > I noticed that we starting to get many errors like this: > > > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > > > strace shows in erroneous case: > > > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > > if (vmfd < 0) { > > > > goto err; > > > > } > > > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > > says "an unmasked signal is pending". > > > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > > checked the strace log and it does not show evidence of arriving a signal, > > > the log ends like this: > > > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > 1152244 close(9) = 0 > > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > > 1152244 exit_group(1) = ? > > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > > 1152245 +++ exited with 1 +++ > > > 1152244 +++ exited with 1 +++ > > > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > > and need retrying? > > In general, yes. But for this particular one, this is pretty odd. > > The only path I can so far see that would match this behaviour is if > mm_take_all_locks() (called from __mmu_notifier_register()) was > getting interrupted by a signal (I'm looking at a 5.19-ish kernel, > which may slightly differ from the 5.15 mentioned above). > > But as Vitaly points out, it doesn't seem to be a signal delivered > here. > > Vitaly: could you please share your exact test case (full qemu command > line), and instrument your kernel to see if mm_take_all_locks() is the > one failing? Full command is `qemu-system-aarch64 -M accel=kvm:tcg -m 4096M -smp cores=8 -nodefaults -nographic -no-reboot -fsdev local,id=root,path=/,security_model=none,multidevs=remap -device virtio-9p-pci,fsdev=root,mount_tag=/dev/root -device virtio-rng-pci -serial mon:stdio -kernel /boot/vmlinuz-5.18.16-un-def-alt1 -initrd /usr/src/tmp/initramfs-5.18.16-un-def-alt1.img -sandbox on,spawn=deny -M virt,gic-version=3 -cpu max -append 'console=ttyAMA0 mitigations=off nokaslr quiet panic=-1 SCRIPT=/usr/src/tmp/tmp.458pkF5r8d'`. But a minified reproducer is `qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe`. I traced with kprobe event tracer with the probes: echo 'p kvm_dev_ioctl' > kprobe_events echo 'r kvm_dev_ioctl $retval' >> kprobe_events echo 'p mm_take_all_locks' >> kprobe_events echo 'r mm_take_all_locks $retval' >> kprobe_events Then run reproducer in the loop for ((i=0;i<100;i++));do echo $i; strace -fvo bb.$i qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe 2>&1 | grep Failed && break; done And on 97th iteration it's failed, strace log to check that PID is the same with the following trace: 3611463 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) Event trace log: qemu-system-aar-3611463 [002] d.... 342920.535549: p_kvm_dev_ioctl_0: (kvm_dev_ioctl+0x0/0x910) qemu-system-aar-3611463 [002] d.... 342920.535635: p_mm_take_all_locks_0: (mm_take_all_locks+0x0/0x390) qemu-system-aar-3611463 [002] ..... 342920.535657: r_mm_take_all_locks_0: (__mmu_notifier_register+0x44/0x200 <- mm_take_all_locks) arg1=0xfffffffc qemu-system-aar-3611463 [002] ..... 342920.535695: r_kvm_dev_ioctl_0: (__arm64_sys_ioctl+0xcc/0x124 <- kvm_dev_ioctl) arg1=0xfffffffffffffffc So that's mm_take_all_locks returns EINTR. (I tried also to make C reproducer which opens /dev/kvm and call `ioctl(kvm, KVM_CREATE_VM, 0)` in the loop and it does not reproduce the problem, so it seems it's also something additional that QEMU does.) Thanks, ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-13 11:11 ` Vitaly Chikunov @ 2022-08-13 13:32 ` Marc Zyngier -1 siblings, 0 replies; 14+ messages in thread From: Marc Zyngier @ 2022-08-13 13:32 UTC (permalink / raw) To: Vitaly Chikunov; +Cc: qemu-arm, Dmitry V. Levin, kvmarm, QEMU Developers On Sat, 13 Aug 2022 12:11:37 +0100, Vitaly Chikunov <vt@altlinux.org> wrote: > > Marc, > > On Fri, Aug 12, 2022 at 04:02:37PM +0100, Marc Zyngier wrote: > > On Fri, 12 Aug 2022 10:25:55 +0100, > > Peter Maydell <peter.maydell@linaro.org> wrote: > > > > > > I've added some more relevant mailing lists to the cc. > > > > > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > > > I noticed that we starting to get many errors like this: > > > > > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > > > > > strace shows in erroneous case: > > > > > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > > > if (vmfd < 0) { > > > > > goto err; > > > > > } > > > > > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > > > says "an unmasked signal is pending". > > > > > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > > > checked the strace log and it does not show evidence of arriving a signal, > > > > the log ends like this: > > > > > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > 1152244 close(9) = 0 > > > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > > > 1152244 exit_group(1) = ? > > > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > > > 1152245 +++ exited with 1 +++ > > > > 1152244 +++ exited with 1 +++ > > > > > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > > > and need retrying? > > > > In general, yes. But for this particular one, this is pretty odd. > > > > The only path I can so far see that would match this behaviour is if > > mm_take_all_locks() (called from __mmu_notifier_register()) was > > getting interrupted by a signal (I'm looking at a 5.19-ish kernel, > > which may slightly differ from the 5.15 mentioned above). > > > > But as Vitaly points out, it doesn't seem to be a signal delivered > > here. > > > > Vitaly: could you please share your exact test case (full qemu command > > line), and instrument your kernel to see if mm_take_all_locks() is the > > one failing? > > Full command is `qemu-system-aarch64 -M accel=kvm:tcg -m 4096M -smp > cores=8 -nodefaults -nographic -no-reboot -fsdev > local,id=root,path=/,security_model=none,multidevs=remap -device > virtio-9p-pci,fsdev=root,mount_tag=/dev/root -device virtio-rng-pci > -serial mon:stdio -kernel /boot/vmlinuz-5.18.16-un-def-alt1 -initrd > /usr/src/tmp/initramfs-5.18.16-un-def-alt1.img -sandbox on,spawn=deny -M > virt,gic-version=3 -cpu max -append 'console=ttyAMA0 mitigations=off > nokaslr quiet panic=-1 SCRIPT=/usr/src/tmp/tmp.458pkF5r8d'`. > > But a minified reproducer is `qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe`. Ah, couldn't be smaller! ;-) Thanks for that! > > I traced with kprobe event tracer with the probes: > > echo 'p kvm_dev_ioctl' > kprobe_events > echo 'r kvm_dev_ioctl $retval' >> kprobe_events > echo 'p mm_take_all_locks' >> kprobe_events > echo 'r mm_take_all_locks $retval' >> kprobe_events > > Then run reproducer in the loop > > for ((i=0;i<100;i++));do echo $i; strace -fvo bb.$i qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe 2>&1 | grep Failed && break; done > > And on 97th iteration it's failed, strace log to check that PID is the same with > the following trace: > > 3611463 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > Event trace log: > > qemu-system-aar-3611463 [002] d.... 342920.535549: p_kvm_dev_ioctl_0: (kvm_dev_ioctl+0x0/0x910) > qemu-system-aar-3611463 [002] d.... 342920.535635: p_mm_take_all_locks_0: (mm_take_all_locks+0x0/0x390) > qemu-system-aar-3611463 [002] ..... 342920.535657: r_mm_take_all_locks_0: (__mmu_notifier_register+0x44/0x200 <- mm_take_all_locks) arg1=0xfffffffc > qemu-system-aar-3611463 [002] ..... 342920.535695: r_kvm_dev_ioctl_0: (__arm64_sys_ioctl+0xcc/0x124 <- kvm_dev_ioctl) arg1=0xfffffffffffffffc > > So that's mm_take_all_locks returns EINTR. > > (I tried also to make C reproducer which opens /dev/kvm and call > `ioctl(kvm, KVM_CREATE_VM, 0)` in the loop and it does not reproduce the > problem, so it seems it's also something additional that QEMU does.) On my fast test box, it takes several hundreds of iterations to fire, but that's not completely impossible to trigger (strace actually helps here). I was expecting it to fire more on a slow one, but that's not the case. And indeed, no signal seems to be delivered. I suspect that FIT_NOTIFY_SIGNAL is set, but I need to investigate more. With a reproducer, it should be easier to diagnose fully. But we probably need to handle EINTR when creating the mini VM. M. -- Without deviation from the norm, progress is not possible. _______________________________________________ kvmarm mailing list kvmarm@lists.cs.columbia.edu https://lists.cs.columbia.edu/mailman/listinfo/kvmarm ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features @ 2022-08-13 13:32 ` Marc Zyngier 0 siblings, 0 replies; 14+ messages in thread From: Marc Zyngier @ 2022-08-13 13:32 UTC (permalink / raw) To: Vitaly Chikunov Cc: Peter Maydell, qemu-arm, kvmarm, QEMU Developers, Dmitry V. Levin On Sat, 13 Aug 2022 12:11:37 +0100, Vitaly Chikunov <vt@altlinux.org> wrote: > > Marc, > > On Fri, Aug 12, 2022 at 04:02:37PM +0100, Marc Zyngier wrote: > > On Fri, 12 Aug 2022 10:25:55 +0100, > > Peter Maydell <peter.maydell@linaro.org> wrote: > > > > > > I've added some more relevant mailing lists to the cc. > > > > > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > > > I noticed that we starting to get many errors like this: > > > > > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > > > > > strace shows in erroneous case: > > > > > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > > > if (vmfd < 0) { > > > > > goto err; > > > > > } > > > > > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > > > says "an unmasked signal is pending". > > > > > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > > > checked the strace log and it does not show evidence of arriving a signal, > > > > the log ends like this: > > > > > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > 1152244 close(9) = 0 > > > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > > > 1152244 exit_group(1) = ? > > > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > > > 1152245 +++ exited with 1 +++ > > > > 1152244 +++ exited with 1 +++ > > > > > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > > > and need retrying? > > > > In general, yes. But for this particular one, this is pretty odd. > > > > The only path I can so far see that would match this behaviour is if > > mm_take_all_locks() (called from __mmu_notifier_register()) was > > getting interrupted by a signal (I'm looking at a 5.19-ish kernel, > > which may slightly differ from the 5.15 mentioned above). > > > > But as Vitaly points out, it doesn't seem to be a signal delivered > > here. > > > > Vitaly: could you please share your exact test case (full qemu command > > line), and instrument your kernel to see if mm_take_all_locks() is the > > one failing? > > Full command is `qemu-system-aarch64 -M accel=kvm:tcg -m 4096M -smp > cores=8 -nodefaults -nographic -no-reboot -fsdev > local,id=root,path=/,security_model=none,multidevs=remap -device > virtio-9p-pci,fsdev=root,mount_tag=/dev/root -device virtio-rng-pci > -serial mon:stdio -kernel /boot/vmlinuz-5.18.16-un-def-alt1 -initrd > /usr/src/tmp/initramfs-5.18.16-un-def-alt1.img -sandbox on,spawn=deny -M > virt,gic-version=3 -cpu max -append 'console=ttyAMA0 mitigations=off > nokaslr quiet panic=-1 SCRIPT=/usr/src/tmp/tmp.458pkF5r8d'`. > > But a minified reproducer is `qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe`. Ah, couldn't be smaller! ;-) Thanks for that! > > I traced with kprobe event tracer with the probes: > > echo 'p kvm_dev_ioctl' > kprobe_events > echo 'r kvm_dev_ioctl $retval' >> kprobe_events > echo 'p mm_take_all_locks' >> kprobe_events > echo 'r mm_take_all_locks $retval' >> kprobe_events > > Then run reproducer in the loop > > for ((i=0;i<100;i++));do echo $i; strace -fvo bb.$i qemu-system-aarch64 -M virt,accel=kvm -cpu max -kernel qwe 2>&1 | grep Failed && break; done > > And on 97th iteration it's failed, strace log to check that PID is the same with > the following trace: > > 3611463 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > Event trace log: > > qemu-system-aar-3611463 [002] d.... 342920.535549: p_kvm_dev_ioctl_0: (kvm_dev_ioctl+0x0/0x910) > qemu-system-aar-3611463 [002] d.... 342920.535635: p_mm_take_all_locks_0: (mm_take_all_locks+0x0/0x390) > qemu-system-aar-3611463 [002] ..... 342920.535657: r_mm_take_all_locks_0: (__mmu_notifier_register+0x44/0x200 <- mm_take_all_locks) arg1=0xfffffffc > qemu-system-aar-3611463 [002] ..... 342920.535695: r_kvm_dev_ioctl_0: (__arm64_sys_ioctl+0xcc/0x124 <- kvm_dev_ioctl) arg1=0xfffffffffffffffc > > So that's mm_take_all_locks returns EINTR. > > (I tried also to make C reproducer which opens /dev/kvm and call > `ioctl(kvm, KVM_CREATE_VM, 0)` in the loop and it does not reproduce the > problem, so it seems it's also something additional that QEMU does.) On my fast test box, it takes several hundreds of iterations to fire, but that's not completely impossible to trigger (strace actually helps here). I was expecting it to fire more on a slow one, but that's not the case. And indeed, no signal seems to be delivered. I suspect that FIT_NOTIFY_SIGNAL is set, but I need to investigate more. With a reproducer, it should be easier to diagnose fully. But we probably need to handle EINTR when creating the mini VM. M. -- Without deviation from the norm, progress is not possible. ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-13 13:32 ` Marc Zyngier @ 2022-08-16 12:31 ` Peter Maydell -1 siblings, 0 replies; 14+ messages in thread From: Peter Maydell @ 2022-08-16 12:31 UTC (permalink / raw) To: Marc Zyngier Cc: Vitaly Chikunov, qemu-arm, Dmitry V. Levin, kvmarm, QEMU Developers On Sat, 13 Aug 2022 at 14:32, Marc Zyngier <maz@kernel.org> wrote: > But we probably need to handle EINTR when creating the mini VM. It's easy enough to add a retry-on-EINTR loop to the KVM_CREATE_VM ioctl in the target/arm/ code. But do we need to do that more widely ? At the moment QEMU seems to assume that KVM ioctls will never fail EINTR except for the one special-cased KVM_CREATE_VM, plus (more obviously) KVM_RUN... thanks -- PMM _______________________________________________ kvmarm mailing list kvmarm@lists.cs.columbia.edu https://lists.cs.columbia.edu/mailman/listinfo/kvmarm ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features @ 2022-08-16 12:31 ` Peter Maydell 0 siblings, 0 replies; 14+ messages in thread From: Peter Maydell @ 2022-08-16 12:31 UTC (permalink / raw) To: Marc Zyngier Cc: Vitaly Chikunov, qemu-arm, kvmarm, QEMU Developers, Dmitry V. Levin On Sat, 13 Aug 2022 at 14:32, Marc Zyngier <maz@kernel.org> wrote: > But we probably need to handle EINTR when creating the mini VM. It's easy enough to add a retry-on-EINTR loop to the KVM_CREATE_VM ioctl in the target/arm/ code. But do we need to do that more widely ? At the moment QEMU seems to assume that KVM ioctls will never fail EINTR except for the one special-cased KVM_CREATE_VM, plus (more obviously) KVM_RUN... thanks -- PMM ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features 2022-08-12 9:25 ` Peter Maydell @ 2022-08-12 15:10 ` Marc Zyngier -1 siblings, 0 replies; 14+ messages in thread From: Marc Zyngier @ 2022-08-12 15:10 UTC (permalink / raw) To: Peter Maydell Cc: Vitaly Chikunov, qemu-arm, Dmitry V. Levin, kvmarm, QEMU Developers On Fri, 12 Aug 2022 10:25:55 +0100, Peter Maydell <peter.maydell@linaro.org> wrote: > > I've added some more relevant mailing lists to the cc. > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > I noticed that we starting to get many errors like this: > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > strace shows in erroneous case: > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > if (vmfd < 0) { > > > goto err; > > > } > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > says "an unmasked signal is pending". > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > checked the strace log and it does not show evidence of arriving a signal, > > the log ends like this: > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > 1152244 close(9) = 0 > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > 1152244 exit_group(1) = ? > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > 1152245 +++ exited with 1 +++ > > 1152244 +++ exited with 1 +++ > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > and need retrying? > > (I suspect the answer is "yes", given we do this in the generic > code in kvm-all.c.) Interestingly, this has cropped up in the (distant) past: https://lists.gnu.org/archive/html/qemu-devel/2014-01/msg01031.html and seems to point at the path I was mentioning earlier (the code hasn't changed too much since, apparently). I'd still like to understand the underlying reason though. Thanks, M. -- Without deviation from the norm, progress is not possible. _______________________________________________ kvmarm mailing list kvmarm@lists.cs.columbia.edu https://lists.cs.columbia.edu/mailman/listinfo/kvmarm ^ permalink raw reply [flat|nested] 14+ messages in thread
* Re: qemu-system-aarch64: Failed to retrieve host CPU features @ 2022-08-12 15:10 ` Marc Zyngier 0 siblings, 0 replies; 14+ messages in thread From: Marc Zyngier @ 2022-08-12 15:10 UTC (permalink / raw) To: Peter Maydell Cc: Vitaly Chikunov, qemu-arm, kvmarm, QEMU Developers, Dmitry V. Levin On Fri, 12 Aug 2022 10:25:55 +0100, Peter Maydell <peter.maydell@linaro.org> wrote: > > I've added some more relevant mailing lists to the cc. > > On Fri, 12 Aug 2022 at 09:45, Vitaly Chikunov <vt@altlinux.org> wrote: > > On Fri, Aug 12, 2022 at 05:14:27AM +0300, Vitaly Chikunov wrote: > > > I noticed that we starting to get many errors like this: > > > > > > qemu-system-aarch64: Failed to retrieve host CPU features > > > > > > Where many is 1-2% per run, depends on host, host is Kunpeng-920, and > > > Linux kernel is v5.15.59, but it started to appear months before that. > > > > > > strace shows in erroneous case: > > > > > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > > > > > And I see in target/arm/kvm.c:kvm_arm_create_scratch_host_vcpu: > > > > > > vmfd = ioctl(kvmfd, KVM_CREATE_VM, max_vm_pa_size); > > > if (vmfd < 0) { > > > goto err; > > > } > > > > > > Maybe it should restart ioctl on EINTR? > > > > > > I don't see EINTR documented in ioctl(2) nor in Linux' > > > Documentation/virt/kvm/api.rst for KVM_CREATE_VM, but for KVM_RUN it > > > says "an unmasked signal is pending". > > > > I am suggested that almost any blocking syscall could return EINTR, so I > > checked the strace log and it does not show evidence of arriving a signal, > > the log ends like this: > > > > 1152244 openat(AT_FDCWD, "/dev/kvm", O_RDWR|O_CLOEXEC) = 9 > > 1152244 ioctl(9, KVM_CHECK_EXTENSION, KVM_CAP_ARM_VM_IPA_SIZE) = 48 > > 1152244 ioctl(9, KVM_CREATE_VM, 0x30) = -1 EINTR (Interrupted system call) > > 1152244 close(9) = 0 > > 1152244 newfstatat(2, "", {st_dev=makedev(0, 0xd), st_ino=57869925, st_mode=S_IFIFO|0600, st_nlink=1, st_uid=517, st_gid=517, st_blksize=4096, st_blocks=0, st_size=0, st_atime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_atime_nsec=850436293, st_mtime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_mtime_nsec=850436293, st_ctime=1660268019 /* 2022-08-12T01:33:39.850436293+0000 */, st_ctime_nsec=850436293}, AT_EMPTY_PATH) = 0 > > 1152244 write(2, "qemu-system-aarch64: Failed to r"..., 58) = 58 > > 1152244 exit_group(1) = ? > > 1152245 <... clock_nanosleep resumed> <unfinished ...>) = ? > > 1152245 +++ exited with 1 +++ > > 1152244 +++ exited with 1 +++ > > KVM folks: should we expect that KVM_CREATE_VM might fail EINTR > and need retrying? > > (I suspect the answer is "yes", given we do this in the generic > code in kvm-all.c.) Interestingly, this has cropped up in the (distant) past: https://lists.gnu.org/archive/html/qemu-devel/2014-01/msg01031.html and seems to point at the path I was mentioning earlier (the code hasn't changed too much since, apparently). I'd still like to understand the underlying reason though. Thanks, M. -- Without deviation from the norm, progress is not possible. ^ permalink raw reply [flat|nested] 14+ messages in thread
end of thread, other threads:[~2022-08-16 12:39 UTC | newest] Thread overview: 14+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2022-08-12 2:14 qemu-system-aarch64: Failed to retrieve host CPU features Vitaly Chikunov 2022-08-12 8:45 ` Vitaly Chikunov 2022-08-12 9:25 ` Peter Maydell 2022-08-12 9:25 ` Peter Maydell 2022-08-12 15:02 ` Marc Zyngier 2022-08-12 15:02 ` Marc Zyngier 2022-08-13 11:11 ` Vitaly Chikunov 2022-08-13 11:11 ` Vitaly Chikunov 2022-08-13 13:32 ` Marc Zyngier 2022-08-13 13:32 ` Marc Zyngier 2022-08-16 12:31 ` Peter Maydell 2022-08-16 12:31 ` Peter Maydell 2022-08-12 15:10 ` Marc Zyngier 2022-08-12 15:10 ` Marc Zyngier
This is an external index of several public inboxes, see mirroring instructions on how to clone and mirror all data and code used by this external index.