Re: [PATCH] KVM: arm64: vgic: Fix soft lockup during VM teardown

Shanker Donthineni
2023-01-19T13:01:34Z

On 1/19/23 01:11, Marc Zyngier wrote:
> External email: Use caution opening links or attachments
>
>
> [dropping the now dead old kvmarm list]
>
> On Wed, 18 Jan 2023 19:24:01 +0000,
> Shanker Donthineni <sdonthineni@nvidia.com> wrote:
>>
>>
>>
>> On 1/18/23 05:54, Marc Zyngier wrote:
>>> External email: Use caution opening links or attachments
>>>
>>>
>>> Shanker,
>>>
>>> Please Cc all the KVM/arm64 reviewers when sending KVM/arm64 patches.
>>>
>>> On Wed, 18 Jan 2023 02:23:48 +0000,
>>> Shanker Donthineni <sdonthineni@nvidia.com> wrote:
>>>>
>>>> Getting intermittent CPU soft lockups during the virtual machines
>>>> teardown on a system with GICv4 features enabled. The function
>>>> __synchronize_hardirq() has been waiting for IRQD_IRQ_INPROGRESS
>>>> to be cleared forever as per the current implementation.
>>>>
>>>> CPU stuck here for a long time leads to soft lockup:
>>>> while (irqd_irq_inprogress(&desc->irq_data))
>>>> cpu_relax();
>>>
>>> Is it a soft-lockup from which the system recovers? or a livelock
>>> which leaves the system dead?
>>>
>> The system is not recovering, did a power cycle to recover.
>
> This isn't a soft-lockup then. This is at best a livelock.
>
>>> Are these two traces an indication of concurrent events? Or are they
>>> far apart?
>>>
>> Concurrent.
>
> So you can see the VM being torn down while the vgic save sequence is
> still in progress?
>
> If you can actually see that, then this is a much bigger bug than the
> simple race you are describing, and we're missing a reference on the
> kvm structure. This would be a *MAJOR* bug.
>
How do we know vGIC save sequence is in progress while VM is being teardown?
I'm launching/terminating ~32 VMs in a loop to reproduce the issue.

> Please post the full traces, not snippets. The absolutely full kernel
> log, the configuration, what you run, how you run it, *EVERYTHING*. I
> need to be able to reproduce this.
Sure, I'll share the complete boot log messages of host kernel next run.

>
>>
>>>>
>>>> irqreturn_t handle_irq_event(struct irq_desc *desc)
>>>> {
>>>> irqd_set(&desc->irq_data, IRQD_IRQ_INPROGRESS);
>>>> raw_spin_unlock(&desc->lock);
>>>>
>>>> ret = handle_irq_event_percpu(desc);
>>>>
>>>> raw_spin_lock(&desc->lock);
>>>> irqd_clear(&desc->irq_data, IRQD_IRQ_INPROGRESS);
>>>> }
>>>
>>> How is that relevant to this trace? Do you see this function running
>>> concurrently with the teardown? If it matters here, it must be a VPE
>>> doorbell, right? But you claim that this is on a GICv4 platform, while
>>> this would only affect GICv4.1... Or are you using GICv4.1?
>>>
>> handle_irq_event() is running concurrently with irq_domain_activate_irq()
>> which happens before free_irq() called. Corruption at [78.983544] and
>> teardown started at [87.360891].
>
> But that doesn't match the description you made of concurrent
> events. Does it take more than 9 seconds for the vgic state to be
> saved to memory?

Are there any other possibilities of corrupting IRQD_IRQ_INPROGRESS
state bit other than concurrent accesses?

I did another experiment, changed the bit manipulation of the IRQD
state to atomic operations, the issue is not reproducible.

struct irq_common_data {
- unsigned int __private state_use_accessors;
+ atomic_t __private state_use_accessors;

+#define __irqd_to_state(d) ACCESS_PRIVATE((d)->common, state_use_accessors)
+#define __irqd_get_state(d) atomic_read(&__irqd_to_state(d))
+#define __irqd_set_state(d, m) atomic_or((m), &__irqd_to_state(d))
+#define __irqd_clear_state(d, m) atomic_andnot((m), &__irqd_to_state(d))
>
>>
>> [ 78.983544] irqd_set_activated: lost IRQD_IRQ_INPROGRESS old=0x10401400, new=0x10441600
>>
>> [ 87.360891] __synchronize_hardirq+0x48/0x140
>>
>> Yes, I'm using GICv4.1, used these 2 functions to trace the issue.
>
> Then *please* be precise in your descriptions. You send people in the
> wrong direction.
>
It was my mistake not to mention the exact GIC version.

> [...]
>
>> I ran stress test launch/teardown multiple VMs for 3hrs. The issue
>> is not reproducible. The same test fails in 10-30min without code
>> changes.
>
> That doesn't add up with the earlier description of concurrent events,
> with the VM teardown and the vgic saving running in parallel. My patch
> doesn't prevent this.
>
> So either your testing is insufficient, or your description of
> concurrent events is inaccurate.
>

I'm using the unmodified 6.2.rc3/v6.0 from kernel.org and QEMU to
reproduce the issue.

Using the below steps for launching/terminating 32 VMs in loop. The
failure is intermittent. The same issue is reproducible with KVMTOOL
also.

numvms=32
socketcnt=1
iterations=100
while [ ${iterations} -ne 0 ]; do
iterations=$(( iterations - 1 ))
for idx in `seq 1 ${numvms}`; do
vmname=vm${idx}
cpunode=$((idx % socketcnt))
cpuset=`lscpu | grep "NUMA node${cpunode} CPU(s)" | awk -F' ' '{ print $4 }'`
qemu-img create -f qcow2 -F raw -b /var/lib/libvirt/images/cloudimg.raw /var/lib/libvirt/images/${vmname}.qcow2
virt-sysprep -a /var/lib/libvirt/images/${vmname}.qcow2 --hostname ${vmname}
virt-install \
--name ${vmname} \
--numatune ${cpunode},mode=preferred \
--vcpus vcpus=16,maxvcpus=16,cpuset=${cpuset} \
--memory 4096 \
--import \
--noautoconsole \
--os-variant name=ubuntu22.04 \
--disk path=/var/lib/libvirt/images/${vmname}.qcow2 \
--boot loader=/usr/share/AAVMF/AAVMF_CODE.fd,loader_ro=yes,loader_type=pflash
if [ $? -ne 0 ]; then
echo "Failed to create vm${idx}"
while true ; do sleep 1; done
fi
sleep 5
done

for idx in `seq 1 ${numvms}`; do
echo -n "Checking vm${idx} boot: "
while true; do
ghostname=`virsh guestinfo vm${idx} --hostname 2>/dev/null | awk '{ print $3 }'`
[ "${ghostname}" == "vm${idx}" ] && echo "done" && break
sleep 1
done
done

for idx in `seq 1 ${numvms}`; do
virsh domstate vm${idx} >/dev/null 2>&1 || continue
echo "Started shutdown & undefine vm${idx}..."
virsh shutdown "vm${idx}" --mode agent >/dev/null 2>&1
while true; do
virsh domstate vm${idx} 2>/dev/null 2>&1 | grep -w "^shut off" >/dev/null 2>&1
[ $? -eq 0 ] && break
sleep 1
virsh shutdown "vm${idx}" --mode agent >/dev/null 2>&1
done
virsh undefine --nvram --remove-all-storage vm${idx} 2>/dev/null
done
done

> M.
>
> --
> Without deviation from the norm, progress is not possible.