Re: NFS swap on current appears to deadlock

[Paul Ripke <stix%stix.id.au@localhost>]

On Mon, May 18, 2020 at 09:41:17PM +0000, Andrew Doran wrote:
> Hi,
> 
> Finally got around to trying this.  Having beaten on it for a while with
> real hardware I don't see any problem with swapping over NFS on 9.99.63.

Sorry for the delay, finally getting around to trying this again.

I wonder - was your test unicore or multi? I have qemu configured with
a single core.

> On Sat, May 02, 2020 at 12:06:48PM +1000, Paul Ripke wrote:
> 
> > I have a qemu guest for experimenting with -current, 1 CPU & 64MiB RAM.
> 
> 64 megs, I'm surprised it makes to the login prompt.

Ok, it's 128MiB now for a KASAN kernel... and still appears to lock up
fairly easily. Note, this is via tmpfs, but I can get the same lockup
just allocating anonymous memory, as below:

qemu:ksh$ uname -a
NetBSD qemu 9.99.67 NetBSD 9.99.67 (QEMU) #29: Wed Jun 17 09:44:35 AEST 2020  stix@slave:/home/netbsd/current/obj.amd64/home/netbsd/current/src/sys/arch/amd64/compile/QEMU amd64
qemu:ksh$ swapctl -lk
Device      1K-blocks     Used    Avail Capacity  Priority
/dev/wd0b      131040     2224   128816     2%    0
qemu:ksh$ df -k /tmp
Filesystem    1K-blocks       Used      Avail %Cap Mounted on
tmpfs            128104          4     128100   0% /tmp
qemu:ksh$ dd if=/dev/zero of=/tmp/zz bs=64k count=1600
1600+0 records in
1600+0 records out
104857600 bytes transferred in 27.861 secs (3763597 bytes/sec)
qemu:ksh$ rm /tmp/zz
qemu:ksh$ sudo swapctl -a /swap
qemu:ksh$ swapctl -lk
Device      1K-blocks     Used    Avail Capacity  Priority
/dev/wd0b      131040     9472   121568     7%    0
/swap         1048576        0  1048576     0%    0
Total         1179616     9472  1170144     1%
qemu:ksh$ dd if=/dev/zero of=/tmp/zz bs=64k count=1600
<lockup>

Or, via anonymous:

qemu:ksh$ swapctl -lk
Device      1K-blocks     Used    Avail Capacity  Priority
/dev/wd0b      131040     9596   121444     7%    0
qemu:ksh$ dd if=/dev/zero of=/dev/null bs=20m count=1
1+0 records in
1+0 records out
20971520 bytes transferred in 4.242 secs (4943781 bytes/sec)
qemu:ksh$ sudo swapctl -a /swap
qemu:ksh$ swapctl -lk                                
Device      1K-blocks     Used    Avail Capacity  Priority
/dev/wd0b      131040    10468   120572     8%    0
/swap         1048576        0  1048576     0%    0
Total         1179616    10468  1169148     1%
qemu:ksh$ dd if=/dev/zero of=/dev/null bs=20m count=1
<lockup>

Once locked up, there's a <30% chance the an NMI will drop me into ddb.
When it does, I see a variety of stacks, which change if I continue and
retrigger an NMI, eg:

binuptime() at netbsd:binuptime+0xbe
mi_switch() at netbsd:mi_switch+0xdd
sleepq_block() at netbsd:sleepq_block+0xf1
mtsleep() at netbsd:mtsleep+0x1bb
uao_get() at netbsd:uao_get+0x643
ubc_alloc() at netbsd:ubc_alloc+0x49d
ubc_uiomove() at netbsd:ubc_uiomove+0x280
tmpfs_write() at netbsd:tmpfs_write+0x2a4
VOP_WRITE() at netbsd:VOP_WRITE+0x11f
vn_write() at netbsd:vn_write+0x16b
dofilewrite() at netbsd:dofilewrite+0x19e
sys_write() at netbsd:sys_write+0x78
syscall() at netbsd:syscall+0x4d2
--- syscall (number 4) ---
netbsd:syscall+0x4d2:

lockdebug_unlocked() at netbsd:lockdebug_unlocked+0x439
mutex_exit() at netbsd:mutex_exit+0x1b8
uvm_pageout() at netbsd:uvm_pageout+0x1f7

binuptime() at netbsd:binuptime+0xbe
mi_switch() at netbsd:mi_switch+0xdd
sleepq_block() at netbsd:sleepq_block+0xf1
mtsleep() at netbsd:mtsleep+0x1bb
uvmfault_anonget() at netbsd:uvmfault_anonget+0x5c9
uvm_fault_internal() at netbsd:uvm_fault_internal+0x1f78
trap() at netbsd:trap+0x814
--- trap (number 6) ---
_ustore_8() at netbsd:_ustore_8+0x21
ttread() at netbsd:ttread+0x6ab
cdev_read() at netbsd:cdev_read+0xca
cnread() at netbsd:cnread+0xe3
cdev_read() at netbsd:cdev_read+0xca
spec_read() at netbsd:spec_read+0x1ce
VOP_READ() at netbsd:VOP_READ+0x11f
vn_read() at netbsd:vn_read+0xd7
dofileread() at netbsd:dofileread+0x1a9
sys_read() at netbsd:sys_read+0x78
syscall() at netbsd:syscall+0x4d2
--- syscall (number 3) ---
netbsd:syscall+0x4d2:

And from an older kernel:

binuptime() at netbsd:binuptime+0xbe
mi_switch() at netbsd:mi_switch+0xe1
sleepq_block() at netbsd:sleepq_block+0xed
mtsleep() at netbsd:mtsleep+0x1b8
uvm_pageout() at netbsd:uvm_pageout+0xa3c

mutex_enter() at netbsd:mutex_enter+0x1ab
uvmpdpol_tune() at netbsd:uvmpdpol_tune+0x15
uvm_pageout() at netbsd:uvm_pageout+0x1f7

binuptime() at netbsd:binuptime+0xbe
mi_switch() at netbsd:mi_switch+0xe1
sleepq_block() at netbsd:sleepq_block+0xed
mtsleep() at netbsd:mtsleep+0x1b8
uvmfault_anonget() at netbsd:uvmfault_anonget+0x5c9
uvm_fault_internal() at netbsd:uvm_fault_internal+0x1f78
trap() at netbsd:trap+0x814
--- trap (number 6) ---
copyout() at netbsd:copyout+0x33
sys___kevent50() at netbsd:sys___kevent50+0x8a
syscall() at netbsd:syscall+0x4d7
--- syscall (number 435) ---
netbsd:syscall+0x4d7:

lockdebug_wantlock() at netbsd:lockdebug_wantlock+0xbb
mutex_enter() at netbsd:mutex_enter+0x6a8
sleepq_remove() at netbsd:sleepq_remove+0x289
sleepq_wake() at netbsd:sleepq_wake+0xa2
uvm_wait() at netbsd:uvm_wait+0x61
uvmfault_anonget() at netbsd:uvmfault_anonget+0x5c9
uvm_fault_internal() at netbsd:uvm_fault_internal+0x1f78
trap() at netbsd:trap+0x814
--- trap (number 6) ---
copyout() at netbsd:copyout+0x33
syscall() at netbsd:syscall+0x4d7
--- syscall (number 430) ---
netbsd:syscall+0x4d7:

-- 
Paul Ripke
"Great minds discuss ideas, average minds discuss events, small minds
 discuss people."
-- Disputed: Often attributed to Eleanor Roosevelt. 1948.