On 01/06/17(Thu) 23:09, Stuart Henderson wrote:
> I rebooted a couple of machines in the "wrong" order, NFS server
> first, followed by clients.
>
> On one of the clients I then mistyped a command and it tried to
> search for it in an NFS directory in the path, so it was stalled
> pending the NFS server coming back.
>
> Then in another window I issued a reboot and hit this.
It's a known race. I managed to trigger it while working on the
NET_LOCK(). Problem is that fixing it leads to another panic because
NFS nodes aren't locked.
> Self-built i386 MP kernel from head of the tree as of about
> 10 hours ago. (Not that it's likely to be anything recent,
> it's not something I'd do very often).
>
> login: [-- MARK -- Thu Jun 1 06:00:00 2017]
> [-- MARK -- Thu Jun 1 07:00:00 2017 .. Thu Jun 1 15:00:00 2017 -- MARK --]
> syncing disks... uvm_fault(0xd0bcffc0, 0xefff1000, 0, 1) -> e
> kernel: page fault trap, code=0
> Stopped at solock+0xc: movl 0x4(%eax),%eax
> ddb{0}> [-- sthen@localhost attached -- Thu Jun 1 15:58:44 2017]
> ps
> PID TID PPID UID S FLAGS WAIT COMMAND
> 12003 212609 1 0 2 0x3 reboot
> *28175 224927 1 0 7 0x102037 doas
> 10627 504005 0 0 3 0x14280 nfsidl nfsio
> 24110 388618 0 0 3 0x14280 nfsidl nfsio
> 57979 18934 0 0 3 0x14280 nfsidl nfsio
> 47178 289785 0 0 3 0x14280 nfsidl nfsio
> 38998 74857 0 0 3 0x14280 nfsidl nfsio
> 4068 387681 0 0 3 0x14280 nfsidl nfsio
> 18772 220491 0 0 3 0x14280 nfsidl nfsio
> 17506 446748 0 0 3 0x14280 nfsidl nfsio
> 68328 451968 0 0 2 0x14200 zerothread
> 17973 87009 0 0 3 0x14200 aiodoned aiodoned
> 90679 434708 0 0 3 0x14200 syncer update
> 50941 190454 0 0 3 0x14200 cleaner cleaner
> 84887 320266 0 0 3 0x14200 reaper reaper
> 40106 400998 0 0 3 0x14200 pgdaemon pagedaemon
> 64018 107467 0 0 3 0x14200 bored crynlk
> 14749 448513 0 0 3 0x14200 bored crypto
> 55284 395100 0 0 3 0x14200 pftm pfpurge
> 97314 97574 0 0 3 0x14200 usbtsk usbtask
> 40659 442434 0 0 3 0x14200 usbatsk usbatsk
> 73875 175284 0 0 3 0x14200 bored sensors
> 51157 352523 0 0 3 0x40014200 acpi0 acpi0
> 42890 369596 0 0 7 0x40014200 idle3
> 31561 183664 0 0 7 0x40014200 idle2
> 36877 114398 0 0 7 0x40014200 idle1
> 20858 196756 0 0 3 0x14200 bored softnet
> 74600 291067 0 0 3 0x14200 bored systqmp
> 62533 360102 0 0 3 0x14200 bored systq
> 42790 105222 0 0 3 0x40014200 bored softclock
> 50699 456949 0 0 3 0x40014200 idle0
> 75000 223342 0 0 3 0x14200 bored sbar
> 40611 471609 0 0 3 0x14200 kmalloc kmthread
> 1 296897 0 0 3 0x82 wait init
> 0 0 -1 0 3 0x10200 scheduler swapper
> ddb{0}> tr
> solock(d684ec7c,1,0,d08ac619,1000) at solock+0xc
> soreceive(d684ec7c,0,d4c768a8,d4c76918,0) at soreceive+0xc3
> nfs_receive(fae0a008,d4c76938,d4c76918,fae0a008,fae0a008) at nfs_receive+0xb9
> nfs_reply(fae0a008,daa14b00,daa01600,fae0a008,d6a09010) at nfs_reply+0x4e
> nfs_request(d65be994,3,d4c76ab0,4,d0b14e54) at nfs_request+0x384
> nfs_lookup(d4c76afc,0,d65be994,d4c76e90,d4c76eb8) at nfs_lookup+0x2fe
> VOP_LOOKUP(d65be994,d4c76e90,d4c76eb8,d4c76b44,d0697989) at VOP_LOOKUP+0x39
> vfs_lookup(d4c76e74,d4c76e74,d4c26000,d4c76e98,d0bd06c0) at vfs_lookup+0x2cc
> namei(d4c76e74,0,d4c76c0c,d0208a52,d0bd06c0) at namei+0x310
> check_exec(d6a09010,d4c76cb8,1,0,ffffff9c) at check_exec+0x3c
> sys_execve(d6a09010,d4c76f54,d4c76f7c,0,d4c76fa8) at sys_execve+0x1aa
> syscall() at syscall+0x250
> --- syscall (number -2058191488) ---
> 0x6:
> ddb{0}> sh reg
> ds 0x10
> es 0x10
> fs 0x20 clean_idt
> gs 0
> edi 0
> esi 0xd684ec7c end+0x5bb3c7c
> ebp 0xd4c767dc end+0x3fdb7dc
> ebx 0xd684eccc end+0x5bb3ccc
> edx 0x1
> ecx 0
> eax 0xefff1133
> eip 0xd0364e5c solock+0xc
> cs 0x8
> eflags 0x10282 mp_startup+0x25b
> esp 0xd4c767c4 end+0x3fdb7c4
> ss 0x10
> solock+0xc: movl 0x4(%eax),%eax
> ddb{0}> mach ddbcpu 1
> Stopped at db_enter+0x7: leave
> ddb{1}> tr
> db_enter(d6a6b800,fb315224,12b,f936febc,5bb71) at db_enter+0x7
> i386_ipi_handler(0,d6a60020,d6a10000,f9360010,d0350010) at
> i386_ipi_handler+0x5
> f
>
> Xintripi() at Xintripi+0x49
> --- interrupt ---
> acpicpu_idle(d07eb6ca,d6a6b834,d6a6b800,d07eb5c0,f936ff90) at
> acpicpu_idle+0x22
> 2
>
> cpu_idle_cycle(d6a6b800) at cpu_idle_cycle+0xc
> ddb{1}> mach ddbcpu 2
> Stopped at db_enter+0x7: leave
> ddb{2}> tr
> db_enter(d6a6d000,fb315224,12b,f9371ebc,5bb71) at db_enter+0x7
> i386_ipi_handler(0,d6a60020,d6a10000,f9370010,d0350010) at
> i386_ipi_handler+0x5
> f
>
> Xintripi() at Xintripi+0x49
> --- interrupt ---
> acpicpu_idle(d07eb6ca,d6a6d034,d6a6d000,d07eb5c0,f9371f90) at
> acpicpu_idle+0x22
> 2
>
> cpu_idle_cycle(d6a6d000) at cpu_idle_cycle+0xc
> ddb{2}> mach ddbcpu 3
> Stopped at db_enter+0x7: leave
> ddb{3}> tr
> db_enter(d6a6d800,fb315224,12b,f9373ebc,5bb71) at db_enter+0x7
> i386_ipi_handler(0,d6a60020,d6a10000,f9370010,d0350010) at
> i386_ipi_handler+0x5
> f
>
> Xintripi() at Xintripi+0x49
> --- interrupt ---
> acpicpu_idle(d07eb6ca,d6a6d834,d6a6d800,d07eb5c0,f9373f90) at
> acpicpu_idle+0x22
> 2
>
> cpu_idle_cycle(d6a6d800) at cpu_idle_cycle+0xc
> ddb{3}> sh uvmexp
> Current UVM status:
> pagesize=4096 (0x1000), pagemask=0xfff, pageshift=12
> 760702 VM pages: 391 active, 5272 inactive, 48 wired, 719435 free (83399
> zero
> )
>
> min 10% (25) anon, 10% (25) vnode, 5% (12) vtext
> pages 0 anon, 0 vnode, 0 vtext
> freemin=25356, free-target=33808, inactive-target=72378, wired-max=253567
> faults=298901797, traps=300653176, intrs=4072834, ctxswitch=22129797
> fpuswitc
> h=233909
>
> softint=6205583, syscalls=221497670, kmapent=27
> fault counts:
> noram=0, noanon=0, noamap=0, pgwait=0, pgrele=0
> ok relocks(total)=272855(272855), anget(retries)=100505411(0),
> amapcopy=110
> 454654
>
> neighbor anon/obj pg=14754221/170190292, gets(lock/unlock)=49246566/272855
> cases: anon=84294682, anoncow=16210729, obj=43932813, prcopy=5313753,
> przer
> o=149149793
>
> daemon and swap counts:
> woke=5, revs=1, scans=76428, obscans=76428, anscans=0
> busy=0, freed=76428, reactivate=0, deactivate=0
> pageouts=0, pending=0, nswget=0
> nswapdev=1, nanon=0, nanonneeded=0 nfreeanon=0
> swpages=844100, swpginuse=0, swpgonly=0 paging=0
> kernel pointers:
> objs(kern)=0xd0bb6f40
> ddb{3}> sh bcst
> Current Buffer Cache status:
> numbufs 5146 busymapped 1, delwri 0
> kvaslots 1216 avail kva slots 1215
> bufpages 21673, dmapages 21673, dirtypages 0
> pendingreads 0, pendingwrites 0
> highflips 0, highflops 0, dmaflips 0
>
