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

[Shanker Donthineni]

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@xxxxxxxxxx> 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@xxxxxxxxxx> 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.