Subject: Re: port-alpha/25599: Alpha SMP system hangs hard
To: NetBSD/alpha Discussion List <port-alpha@NetBSD.ORG>
From: Greg A. Woods <woods@planix.com>
List: port-alpha
Date: 03/23/2005 01:29:42
It's probably a little bit early to finally report success with this
since I'm only a couple of hours into the test, but that's about an hour
longer than it ever ran before.

It seems this bug is much more aggressive on 4-CPU machines and on
duals, which I suppose should only have been expected.  With the
original fix from this PR I have built all of NetBSD multiple times over
from source to ISO, and over 400 packages twice over, all with sources
or distfiles on NFS, on my PC264DP (with a LOCKDEBUG kernel) and never
once encountered this bug (or any other).  My old dual AS4000 only
rarely encountered it after the patch, and not once in the past couple
of months since it's been relieved of build duties and now just serves
NFS, CVS, DNS, shell accounts, mail reading, etc. (and no more mozilla,
etc. since they won't currently install on alpha due to more new LP64 or
similar bugs in recent releases)

However in the process of starting to move user data over onto my
client's 4-CPU ES40 I never got much more than an hour into an rcp or
rsync before it would crash.  I hadn't crashed it before in any earlier
testing, but getting both networking and file I/O busy has always been
my favourite trigger for it.

simple_lock: locking against myself
lock: 0xfffffc000078f0d0, currently at: /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
on cpu 0
last locked: /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
last unlocked: /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2240
alpha trace requires known PC =eject=
Stopped in pid 14 (aiodoned) at cpu_Debugger+0x4:       ret     zero,(ra)
db{0}> trace
cpu_Debugger() at cpu_Debugger+0x4
_simple_lock() at _simple_lock+0x130
pmap_extract() at pmap_extract+0x50
uvm_km_pgremove_intrsafe() at uvm_km_pgremove_intrsafe+0x48
uvm_unmap_remove() at uvm_unmap_remove+0x1b8
uvm_unmap() at uvm_unmap+0x148
uvm_km_free() at uvm_km_free+0x34
free() at free+0xc8
softdep_disk_write_complete() at softdep_disk_write_complete+0x290
biodone() at biodone+0xa0
scsipi_complete() at scsipi_complete+0x5b8
scsipi_done() at scsipi_done+0x1b4
isp_done() at isp_done+0x128
isp_intr() at isp_intr+0x1260
isp_pci_intr() at isp_pci_intr+0x70
alpha_shared_intr_dispatch() at alpha_shared_intr_dispatch+0x6c
dec_6600_iointr() at dec_6600_iointr+0x68
interrupt() at interrupt+0x314
XentInt() at XentInt+0x1c
--- interrupt (from ipl 0) ---
_simple_lock() at _simple_lock+0x2f8
pmap_extract() at pmap_extract+0x50
uvm_km_pgremove_intrsafe() at uvm_km_pgremove_intrsafe+0x48
uvm_unmap_remove() at uvm_unmap_remove+0x1b8
uvm_pagermapout() at uvm_pagermapout+0x1f8
uvm_aio_aiodone() at uvm_aio_aiodone+0x158
end() at 0xfffffc00059c5480
frame size botch: adjust register offsets?
prologue botch: displacement 8192
frame size botch: adjust register offsets?
prologue botch: displacement 16384
prologue botch: displacement 24576
frame size botch: adjust register offsets?
frame size botch: adjust register offsets?
frame size botch: adjust register offsets?
frame size botch: adjust register offsets?
frame size botch: adjust register offsets?
f30save() at          0
--- root of call graph ---
db{0}> machine slock 0xfffffc000078f0d0
lock_data=1 holder=0
 last locked=/building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
 last unlocked=/building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2240

db{0}> 



[[ the next time around I remembered to call simple_lock_debug(), only
to discover that it appears the locks are all on one CPU! ]]

simple_lock: locking against myself
lock: 0xfffffc000078f0d0, currently at: /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
on cpu 0
last locked: /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
last unlocked: /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2240
alpha trace requires known PC =eject=
Stopped in pid 14 (aiodoned) at cpu_Debugger+0x4:       ret     zero,(ra)
db{0}> slock 0xfffffc000078f0d0
No such command
db{0}> machine slock 0xfffffc000078f0d0
lock_data=1 holder=0
 last locked=/building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
 last unlocked=/building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2240

db{0}> call simple_lock_dump
all simple locks:
0xfffffc000078f0d0 CPU 0 /building/work/woods/m-NetBSD-1.6/sys/arch/alpha/alpha/pmap.c:2220
0xfffffc00005edb10 CPU 0 /building/work/woods/m-NetBSD-1.6/sys/uvm/uvm_map.h:373
       0x6
db{0}> machine slock 0xfffffc00005edb10
lock_data=1 holder=0
 last locked=/building/work/woods/m-NetBSD-1.6/sys/uvm/uvm_map.h:373
 last unlocked=/building/work/woods/m-NetBSD-1.6/sys/uvm/uvm_map_i.h:158

db{0}> machine cpu 
addr            dev     id      flags   ipis    curproc         fpcurproc
0xfffffc0000789c48      cpu0    0       5       0       0xfffffc00875ca5c8      0xfffffc
0185438030
0xfffffe0000037c00      cpu3    3       c       0       0xfffffc00b9824018      0xfffffc
00c3292300
0xfffffe0000037d00      cpu2    2       c       0       0xfffffc0185439730      0x0
0xfffffe0000037e00      cpu1    1       c       0       0xfffffc00c32928c0      0x0
db{0}> reboot
syncing disks... wm0: Receive overrun
tlp1: receive ring overrun
panic: softdep_lock: lock held by -2
Stopped in pid 14 (aiodoned) at cpu_Debugger+0x4:       ret     zero,(ra)
db{0}>


That pretty much confirmed my (naive) suspicions that I should try a
similar hack around the locks in pmap_extract() [where this panic is
happening]

I suspect Chuck Silvers' earlier suggestion of a more complete and
proper fix may still be apropos, but if this hack solves the
crashes/hangs for now then I'll be happy enough.

In any case with the following additional patch I've now moved several
hundred thousand more files with rsync (small files from a Cyrus IMAP
spool, about 5GB more in total), which is about twice as many as it ever
managed in one go prior to making the latest changes.  I still don't
have any high degree of confidence that it might not cause more harm
than good, but so far everything looks very good!  :-)


Note the line numbers will be way off here -- I've added lots of
debugging stuff above this section, and remember this is in addition to
the similar changes in pmap_activate() already noted in this PR -- this
is all in pmap_extract().

(note also some of these changes try to make the code look a little more
like that in -current by eliminating one of the ugly gotos and saving
one local variable)

Index: sys/arch/alpha/alpha/pmap.c
===================================================================
RCS file: /cvs/master/m-NetBSD/main/src/sys/arch/alpha/alpha/pmap.c,v
retrieving revision 1.191.8.1
diff -u -r1.191.8.1 pmap.c
--- sys/arch/alpha/alpha/pmap.c	24 Nov 2002 15:38:39 -0000	1.191.8.1
+++ sys/arch/alpha/alpha/pmap.c	22 Mar 2005 22:32:46 -0000
@@ -2131,12 +2211,14 @@
 {
 	pt_entry_t *l1pte, *l2pte, *l3pte;
 	paddr_t pa;
-	boolean_t rv = FALSE;
 
 #ifdef DEBUG
 	if (pmapdebug & PDB_FOLLOW)
 		printf("pmap_extract(%p, %lx) -> ", pmap, va);
 #endif
+#ifdef MULTIPROCESSOR			/* another part of MP deadlock debug? PR#25599 */
+    if (pmap != pmap_kernel())		/* another part of MP deadlock debug? PR#25599 */
+#endif					/* another part of MP deadlock debug? PR#25599 */
 	PMAP_LOCK(pmap);
 
 	l1pte = pmap_l1pte(pmap, va);
@@ -2152,21 +2234,28 @@
 		goto out;
 
 	pa = pmap_pte_pa(l3pte) | (va & PGOFSET);
+#ifdef MULTIPROCESSOR			/* another part of MP deadlock debug? PR#25599 */
+    if (pmap != pmap_kernel())		/* another part of MP deadlock debug? PR#25599 */
+#endif					/* another part of MP deadlock debug? PR#25599 */
+	PMAP_UNLOCK(pmap);
 	if (pap != NULL)
 		*pap = pa;
-	rv = TRUE;
+#ifdef DEBUG
+	if (pmapdebug & PDB_FOLLOW)
+		printf("0x%lx\n", pa);
+#endif
+	return (TRUE);
 
  out:
+#ifdef MULTIPROCESSOR			/* another part of MP deadlock debug? PR#25599 */
+    if (pmap != pmap_kernel())		/* another part of MP deadlock debug? PR#25599 */
+#endif					/* another part of MP deadlock debug? PR#25599 */
 	PMAP_UNLOCK(pmap);
 #ifdef DEBUG
-	if (pmapdebug & PDB_FOLLOW) {
-		if (rv)
-			printf("0x%lx\n", pa);
-		else
-			printf("failed\n");
-	}
+	if (pmapdebug & PDB_FOLLOW)
+		printf("failed\n");
 #endif
-	return (rv);
+	return (FALSE);
 }
 
 /*

-- 
						Greg A. Woods

H:+1 416 218-0098  W:+1 416 489-5852 x122  VE3TCP  RoboHack <woods@robohack.ca>
Planix, Inc. <woods@planix.com>          Secrets of the Weird <woods@weird.com>