Re: arm64 panic uvm_fault failed: ffffff80002619b4 with bonus panic: netlock: lock not held
On 2017 Dec 14 (Thu) at 12:23:00 +0100 (+0100), Martin Pieuchot wrote:
:On 14/12/17(Thu) 12:03, Peter Hessler wrote:
:> This is the normal arm64 "pmap bug" panic.
:
:Thanks Peter, the diff below should fix the two problems present in your
:trace:
:
:> ddb> show panic
:> uvm_fault failed: ff80002619b4
:
:I love that arm64 is doing the right thing and call panic(9) for UVM
:faults.
:
:> ddb> bo re
:> panic: mtx 0xff8000928138: locking against myself
:
:This happens when faulting/panic'ing with a mutex held. The diff below
:contains the same trick I added for rwlock, close the eyes and try
:harder.
:
:Note that the mutex part of the diff below is only for ARM64, I'll
:generalize it if we reach a consensus.
:
:> ddb> # holding down enter, repeats last command 'bo re'
:> panic: netlock: lock not held
:> Stopped at panic+0x154:db_enter() at panic+0x150
:> panic() at if_downall+0x74
:> if_downall() at boot+0x68
:
:This is new to me. My previous fix for rwlock() did not include a check
:for the slow path of rw_exit_write(9)! Diff below should fix that.
:
:
This reads fine to me. While I haven't triggered a panic on arm64 yet, I
think it should go in.
OK
:Index: kern/kern_rwlock.c
:===
:RCS file: /cvs/src/sys/kern/kern_rwlock.c,v
:retrieving revision 1.32
:diff -u -p -r1.32 kern_rwlock.c
:--- kern/kern_rwlock.c 24 Oct 2017 08:53:15 - 1.32
:+++ kern/kern_rwlock.c 14 Dec 2017 11:16:29 -
:@@ -287,6 +287,10 @@ _rw_exit(struct rwlock *rwl LOCK_FL_VARS
: int wrlock = owner & RWLOCK_WRLOCK;
: unsigned long set;
:
:+ /* Avoid deadlocks after panic */
:+ if (panicstr)
:+ return;
:+
: if (wrlock)
: rw_assert_wrlock(rwl);
: else
:Index: arch/arm64/arm64/arm64_mutex.c
:===
:RCS file: /cvs/src/sys/arch/arm64/arm64/arm64_mutex.c,v
:retrieving revision 1.2
:diff -u -p -r1.2 arm64_mutex.c
:--- arch/arm64/arm64/arm64_mutex.c 30 Apr 2017 16:45:45 - 1.2
:+++ arch/arm64/arm64/arm64_mutex.c 14 Dec 2017 11:13:57 -
:@@ -57,6 +57,10 @@ mtx_enter(struct mutex *mtx)
: int ticks = __mp_lock_spinout;
: #endif
:
:+ /* Avoid deadlocks after panic */
:+ if (panicstr)
:+ return;
:+
: while (mtx_enter_try(mtx) == 0) {
: #ifdef MP_LOCKDEBUG
: if (--ticks == 0) {
:@@ -73,7 +77,7 @@ mtx_enter_try(struct mutex *mtx)
: {
: struct cpu_info *owner, *ci = curcpu();
: int s;
:-
:+
: if (mtx->mtx_wantipl != IPL_NONE)
: s = splraise(mtx->mtx_wantipl);
:
:@@ -102,6 +106,10 @@ void
: mtx_leave(struct mutex *mtx)
: {
: int s;
:+
:+ /* Avoid deadlocks after panic */
:+ if (panicstr)
:+ return;
:
: MUTEX_ASSERT_LOCKED(mtx);
:
:
--
In those days he was wiser than he is now -- he used to frequently take
my advice.
-- Winston Churchill
Re: mp deadlock on 6.2 running on kvm
On Fri, Dec 15, 2017 at 06:21:08PM +1000, Jonathan Matthew wrote:
> On Tue, Dec 12, 2017 at 09:11:40PM +1000, Jonathan Matthew wrote:
> > On Mon, Dec 11, 2017 at 09:34:00AM +0100, Landry Breuil wrote:
> > > On Mon, Dec 11, 2017 at 06:21:01PM +1000, Jonathan Matthew wrote:
> > > > On 10/12/17 03:26, Landry Breuil wrote:
> > > > > On Sat, Dec 09, 2017 at 04:33:28PM +0100, Juan Francisco Cantero
> > > > > Hurtado wrote:
> > > > > > On Thu, Dec 07, 2017 at 02:27:29PM +0100, Landry Breuil wrote:
> > > > > > > On Thu, Dec 07, 2017 at 11:52:46AM +0100, Martin Pieuchot wrote:
> > > > > > > > On 07/12/17(Thu) 08:34, Landry Breuil wrote:
> > > > > > > > > Hi,
> > > > > > > > >
> > > > > > > > > i've been having kvm VMs running 6.2 hardlocking/deadlocking
> > > > > > > > > since a
> > > > > > > > > while, all those running on proxmox 5.1 using linux 4.13.8 &
> > > > > > > > > qemu-kvm
> > > > > > > > > 2.9.1. There were hardlocks upon reboot which were 'solved'
> > > > > > > > > by disabling
> > > > > > > > > x2apic emulation in kvm (args: -cpu=kvm64,-x2apic) or giving
> > > > > > > > > the host
> > > > > > > > > cpu flags to the vm (args: -cpu host) but there still remains
> > > > > > > > > deadlocks
> > > > > > > > > during normal operation.
> > > > > > > > >
> > > > > > > > > I'm now running a kernel with MP_LOCKDEBUG, so i'm collecting
> > > > > > > > > traces in
> > > > > > > > > the vain hope that it might help someone interested in
> > > > > > > > > locking issues.
> > > > > > > > > Here's the latest one:
> > > > > > > >
> > > > > > > > Let me add that when you had x2apic enabled the kernel 'froze'
> > > > > > > > inside
> > > > > > > > x2apic_readreg, trace below:
> > > > > > > >
> > > > > > > >ddb{0}> tr
> > > > > > > >x2apic_readreg(10) at x2apic_readreg+0xf
> > > > > > > >lapic_delay(800022136900) at lapic_delay+0x5c
> > > > > > > >rtcput(800022136960) at rtcput+0x65
> > > > > > > >resettodr() at resettodr+0x1d6
> > > > > > > >perform_resettodr(81769b29) at perform_resettodr+0x9
> > > > > > > >taskq_thread(0) at taskq_thread+0x67
> > > > > > > >end trace frame: 0x0, count: -6
> > > > > > > >
> > > > > > > > What you're seeing with a MP_LOCKDEBUG kernel is just a
> > > > > > > > symptom. A CPU
> > > > > > > > enters DDB because another one is 'frozen' while holding the
> > > > > > > > KERNEL_LOCK(). What's interesting is that in both case the
> > > > > > > > frozen CPU
> > > > > > > > is trying to execute apic related code:
> > > > > > > >- x2apic_readreg
> > > > > > > >- lapic_delay
> > > > > > > >
> > > > > > > > I believe this issue should be reported to KVM developers as
> > > > > > > > well.
> > > > > > >
> > > > > > > *very* interestingly, i had a new lock, running bsd.sp.. So i
> > > > > > > think that
> > > > > > > rules out openbsd mp.
> > > > > > >
> > > > > > > ddb> tr
> > > > > > > i82489_readreg(0) at i82489_readreg+0xd
> > > > > > > lapic_delay(81a84090) at lapic_delay+0x5c
> > > > > > > rtcget(81a84090) at rtcget+0x1a
> > > > > > > resettodr() at resettodr+0x3a
> > > > > > > perform_resettodr(81659e99) at perform_resettodr+0x9
> > > > > > > taskq_thread(0) at taskq_thread+0x57
> > > > > > > end trace frame: 0x0, count: -6
> > > > > >
> > > > > > Try running with "-machine q35". It changes the emulated machine to
> > > > > > a modern platform.
> > > > >
> > > > > Right, i suppose that matches https://wiki.qemu.org/Features/Q35,
> > > > > interesting. Will definitely try, mailed the kvm mailing list but got
> > > > > no
> > > > > feedback so far.
> > > >
> > > > I've been seeing this for a while too, on VMs that are already run with
> > > > -machine q35 and -cpu host. I was blaming my (still unfinished) pvclock
> > > > code, but now I can fairly easily trigger it on single cpu VMs without
> > > > that,
> > > > mostly by running kernel compiles in a loop in a couple of different
> > > > guests.
> > > > I'm using a Fedora 25 (4.10.15-200.fc25.x86_64) kernel.
> > > >
> > > > Adding some debug output to lapic_delay, it appears the KVM virtualized
> > > > lapic counter hits zero and doesn't reset, so the lapic_delay loop in
> > > > the
> > > > guest never terminates. KVM has several different ways it can provide
> > > > the
> > > > lapic counter and I'm not sure which one I'm using yet.
> > > >
> > > > I just tried making lapic_delay give up after a million zero reads, and
> > > > it
> > > > seems to recover after a minute or so. I'll leave it running to see if
> > > > it
> > > > happens again.
> > >
> > > Hah, interesting. So i know i can try q35 just for the sake of emulating
> > > a newer hw platform, but that wont fix this issue.
> > >
> > > I see upstream this thread/patchset: https://lkml.org/lkml/2017/9/28/773
> > > But i'm not sure that's the same issue.
> > > https://patchwork.kernel.org/patch/9036161/ might be too ?
> > >
> > > When you say you modified lapic_delay, i
Re: mp deadlock on 6.2 running on kvm
On Tue, Dec 12, 2017 at 09:11:40PM +1000, Jonathan Matthew wrote:
> On Mon, Dec 11, 2017 at 09:34:00AM +0100, Landry Breuil wrote:
> > On Mon, Dec 11, 2017 at 06:21:01PM +1000, Jonathan Matthew wrote:
> > > On 10/12/17 03:26, Landry Breuil wrote:
> > > > On Sat, Dec 09, 2017 at 04:33:28PM +0100, Juan Francisco Cantero
> > > > Hurtado wrote:
> > > > > On Thu, Dec 07, 2017 at 02:27:29PM +0100, Landry Breuil wrote:
> > > > > > On Thu, Dec 07, 2017 at 11:52:46AM +0100, Martin Pieuchot wrote:
> > > > > > > On 07/12/17(Thu) 08:34, Landry Breuil wrote:
> > > > > > > > Hi,
> > > > > > > >
> > > > > > > > i've been having kvm VMs running 6.2 hardlocking/deadlocking
> > > > > > > > since a
> > > > > > > > while, all those running on proxmox 5.1 using linux 4.13.8 &
> > > > > > > > qemu-kvm
> > > > > > > > 2.9.1. There were hardlocks upon reboot which were 'solved' by
> > > > > > > > disabling
> > > > > > > > x2apic emulation in kvm (args: -cpu=kvm64,-x2apic) or giving
> > > > > > > > the host
> > > > > > > > cpu flags to the vm (args: -cpu host) but there still remains
> > > > > > > > deadlocks
> > > > > > > > during normal operation.
> > > > > > > >
> > > > > > > > I'm now running a kernel with MP_LOCKDEBUG, so i'm collecting
> > > > > > > > traces in
> > > > > > > > the vain hope that it might help someone interested in locking
> > > > > > > > issues.
> > > > > > > > Here's the latest one:
> > > > > > >
> > > > > > > Let me add that when you had x2apic enabled the kernel 'froze'
> > > > > > > inside
> > > > > > > x2apic_readreg, trace below:
> > > > > > >
> > > > > > >ddb{0}> tr
> > > > > > >x2apic_readreg(10) at x2apic_readreg+0xf
> > > > > > >lapic_delay(800022136900) at lapic_delay+0x5c
> > > > > > >rtcput(800022136960) at rtcput+0x65
> > > > > > >resettodr() at resettodr+0x1d6
> > > > > > >perform_resettodr(81769b29) at perform_resettodr+0x9
> > > > > > >taskq_thread(0) at taskq_thread+0x67
> > > > > > >end trace frame: 0x0, count: -6
> > > > > > >
> > > > > > > What you're seeing with a MP_LOCKDEBUG kernel is just a symptom.
> > > > > > > A CPU
> > > > > > > enters DDB because another one is 'frozen' while holding the
> > > > > > > KERNEL_LOCK(). What's interesting is that in both case the
> > > > > > > frozen CPU
> > > > > > > is trying to execute apic related code:
> > > > > > >- x2apic_readreg
> > > > > > >- lapic_delay
> > > > > > >
> > > > > > > I believe this issue should be reported to KVM developers as well.
> > > > > >
> > > > > > *very* interestingly, i had a new lock, running bsd.sp.. So i think
> > > > > > that
> > > > > > rules out openbsd mp.
> > > > > >
> > > > > > ddb> tr
> > > > > > i82489_readreg(0) at i82489_readreg+0xd
> > > > > > lapic_delay(81a84090) at lapic_delay+0x5c
> > > > > > rtcget(81a84090) at rtcget+0x1a
> > > > > > resettodr() at resettodr+0x3a
> > > > > > perform_resettodr(81659e99) at perform_resettodr+0x9
> > > > > > taskq_thread(0) at taskq_thread+0x57
> > > > > > end trace frame: 0x0, count: -6
> > > > >
> > > > > Try running with "-machine q35". It changes the emulated machine to
> > > > > a modern platform.
> > > >
> > > > Right, i suppose that matches https://wiki.qemu.org/Features/Q35,
> > > > interesting. Will definitely try, mailed the kvm mailing list but got no
> > > > feedback so far.
> > >
> > > I've been seeing this for a while too, on VMs that are already run with
> > > -machine q35 and -cpu host. I was blaming my (still unfinished) pvclock
> > > code, but now I can fairly easily trigger it on single cpu VMs without
> > > that,
> > > mostly by running kernel compiles in a loop in a couple of different
> > > guests.
> > > I'm using a Fedora 25 (4.10.15-200.fc25.x86_64) kernel.
> > >
> > > Adding some debug output to lapic_delay, it appears the KVM virtualized
> > > lapic counter hits zero and doesn't reset, so the lapic_delay loop in the
> > > guest never terminates. KVM has several different ways it can provide the
> > > lapic counter and I'm not sure which one I'm using yet.
> > >
> > > I just tried making lapic_delay give up after a million zero reads, and it
> > > seems to recover after a minute or so. I'll leave it running to see if it
> > > happens again.
> >
> > Hah, interesting. So i know i can try q35 just for the sake of emulating
> > a newer hw platform, but that wont fix this issue.
> >
> > I see upstream this thread/patchset: https://lkml.org/lkml/2017/9/28/773
> > But i'm not sure that's the same issue.
> > https://patchwork.kernel.org/patch/9036161/ might be too ?
> >
> > When you say you modified lapic_delay, i guess that's on the guest side ?
>
> yeah, I haven't changed anything on the host side yet.
>
> I have a sort of working theory now. It looks like polling the lapic counter
> in a tight loop starves whatever bit of kvm is responsible for resetting the
> counter. If the counter hits 0 and then we enter lapic_delay before
