Subject: Re: port-alpha/25599: Alpha SMP system hangs hard
To: None <port-alpha-maintainer@netbsd.org, gnats-admin@netbsd.org,>
From: Greg A. Woods <woods@planix.com>
List: netbsd-bugs
Date: 03/23/2005 06:30:01
The following reply was made to PR port-alpha/25599; it has been noted by GNATS.

From: "Greg A. Woods" <woods@planix.com>
To: NetBSD/alpha Discussion List <port-alpha@NetBSD.ORG>
Cc: "Michael L. Hitch" <mhitch@netbsd.org>,
	NetBSD GNATS submissions and followups <gnats-bugs@netbsd.org>
Subject: Re: port-alpha/25599: Alpha SMP system hangs hard
Date: Wed, 23 Mar 2005 01:29:42 -0500 (EST)

 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>