Bug 255048

Summary: arm64/ROCKPRO64 freeze during heavy IO on external USB 3 disk
Product: Base System Reporter: Henri Hennebert <hlh>
Component: kernAssignee: freebsd-arm (Nobody) <freebsd-arm>
Status: New ---    
Severity: Affects Only Me CC: diizzy, hlh
Priority: ---    
Version: 13.0-STABLE   
Hardware: arm64   
OS: Any   

Description Henri Hennebert 2021-04-14 11:17:26 UTC

    
Comment 1 Henri Hennebert 2021-04-14 11:41:29 UTC
FreeBSD keystone.lab.bel 13.0-STABLE FreeBSD 13.0-STABLE #0 stable/13-n245189-236d1f8c1773

The disk is under zfs

During a `git pull` in /usr/ports the system show the da0 disk 100% busy and
afer ~2 minutes the system freeze.

The system respond to ping

I connect on the serial console (CR ~ ^B) to ddb:

db> show msgbuf
...
swap_pager: cannot allocate bio
swap_pager: cannot allocate bio
swap_pager: cannot allocate bio
swap_pager: cannot allocate bio
swap_pager: cannot allocate bio
swap_pager: cannot allocate bio

db> show allchains
chain 1:
 thread 115444 (pid 87479, git) is sleeping on 0xffff0000ef3dfc08 "aw.aew_cv"
chain 2:
 thread 115446 (pid 87479, git) is sleeping on 0xffffa00058d653e8 "zio->io_cv"
chain 3:
 thread 115447 (pid 87479, git) is sleeping on 0xffffa000b26cf3e8 "zio->io_cv"
chain 4:
 thread 115450 (pid 87479, git) is sleeping on 0xffff0000ef3cbc08 "aw.aew_cv"
chain 5:
 thread 115452 (pid 87479, git) is sleeping on 0xffffa000091518b8 "zio->io_cv"
chain 6:
 thread 115453 (pid 87479, git) is sleeping on 0xffff0000ef3e9c08 "aw.aew_cv"
chain 7:
 thread 115455 (pid 87479, git) is sleeping on 0xffffa00058d028b8 "zio->io_cv"
chain 8:
 thread 115458 (pid 87479, git) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 115455 (pid 87479, git) is sleeping on 0xffffa00058d028b8 "zio->io_cv"
chain 9:
 thread 115459 (pid 87479, git) is sleeping on 0xffffa000971718b8 "zio->io_cv"
chain 10:
 thread 115460 (pid 87479, git) is sleeping on 0xffff00010420dc08 "aw.aew_cv"
chain 11:
 thread 115462 (pid 87479, git) is sleeping on 0xffff000104217c08 "aw.aew_cv"
chain 12:
 thread 115463 (pid 87479, git) is sleeping on 0xffff00010421cc08 "aw.aew_cv"
chain 13:
 thread 101506 (pid 1214, god.plugin) is sleeping on 0xffff0000ecdb70a8 "aw.aew_cv"
chain 14:
 thread 101508 (pid 1214, god.plugin) is sleeping on 0xffffa000e430da80 "vmpfw"
chain 15:
 thread 101510 (pid 1214, god.plugin) is sleeping on 0xffff0000ecc5e0a8 "aw.aew_cv"
chain 16:
 thread 101513 (pid 1214, god.plugin) is sleeping on 0xffff0000ecd990a8 "aw.aew_cv"
chain 17:
 thread 101352 (pid 1211, apps.plugin) is sleeping on 0xffffa00058d658b8 "zio->io_cv"
chain 18:
 thread 101448 (pid 1195, httpd) is sleeping on 0xffff0000ecc9f0a8 "aw.aew_cv"
chain 19:
 thread 101366 (pid 1179, httpd) is sleeping on 0xffffa0008c253d88 "zio->io_cv"
chain 20:
 thread 101346 (pid 1141, netdata) is sleeping on 0xffff0000e9424cb8 "aw.aew_cv"
chain 21:
 thread 101355 (pid 1121, sshd) is sleeping on 0xffff000000b24d80 "pfault"
chain 22:
 thread 101350 (pid 1083, sendmail) is sleeping on 0xffff000000b24d80 "vmwait"
chain 23:
 thread 101349 (pid 1079, inetd) is sleeping on 0xffffa00027577b40 "select"
chain 24:
 thread 101347 (pid 1050, ntpd) is sleeping on 0xffff0000e93fd0a8 "aw.aew_cv"
chain 25:
 thread 101314 (pid 970, syslogd) is sleeping on 0xffff000000b24d80 "pfault"
chain 26:
 thread 100152 (pid 31, syncer) is sleeping on 0xffff000000d5f480 "syncer"
chain 27:
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
 thread 100151 (pid 30, vnlru) is blocked on lockmgr  DEXCL
... 
...continue for at least 1400 lines.
...
db> show proc 30
Process 30 (vnlru) at 0xffffa00006449000:
 state: NORMAL
 uid: 0  gids: 0
 parent: pid 0 at 0xffff000000cf1828
 ABI: null
 flag: 0x10000204  flag2: 0
 reaper: 0xffff000000cf1828 reapsubtree: 30
 sigparent: 20
 vmspace: 0xffff000000cf22c8
   (map 0xffff000000cf22c8)
   (map.pmap 0xffff000000cf2388)
   (pmap 0xffff000000cf23e8)
 threads: 1
100151                   D       vlruwt  0xffffa00006449000  [vnlru]
db> tr 100151
Tracing pid 30 tid 100151 td 0xffffa0000660f580
sched_switch() at mi_switch+0xf0
         pc = 0xffff0000003dc7c0  lr = 0xffff0000003b2544
         sp = 0xffff0000da1fc760  fp = 0xffff0000da1fc7b0
 
mi_switch() at sleepq_timedwait+0x28
         pc = 0xffff0000003b2544  lr = 0xffff00000040ce64
         sp = 0xffff0000da1fc7c0  fp = 0xffff0000da1fc7f0
 
sleepq_timedwait() at _sleep+0x194
         pc = 0xffff00000040ce64  lr = 0xffff0000003b1960
         sp = 0xffff0000da1fc800  fp = 0xffff0000da1fc830
 
_sleep() at vnlru_proc+0xc54
         pc = 0xffff0000003b1960  lr = 0xffff0000004a4c18
         sp = 0xffff0000da1fc840  fp = 0xffff0000da1fc8f0
 
vnlru_proc() at fork_exit+0x88
         pc = 0xffff0000004a4c18  lr = 0xffff0000003547d0
         sp = 0xffff0000da1fc900  fp = 0xffff0000da1fc950
--More--
fork_exit() at fork_trampoline+0x10
         pc = 0xffff0000003547d0  lr = 0xffff0000007cfef8
         sp = 0xffff0000da1fc960  fp = 0x0000000000000000

db> show mount
0xffff0000e663e100 keystone/ROOT/default on / (zfs)
0xffff0000bbb25100 devfs on /dev (devfs)
0xffff0000e663d600 procfs on /proc (procfs)
0xffff0000e663cb00 fdescfs on /dev/fd (fdescfs)
0xffff0000e9a4e100 keystone/var/spool on /var/spool (zfs)
0xffff0000e9a4d600 keystone/var/log on /var/log (zfs)
0xffff0000bbb24600 keystone/tmp on /tmp (zfs)
0xffff0000e9a48100 keystone/usr/local on /usr/local (zfs)
0xffff0000e663c000 keystone/var/db on /var/db (zfs)
0xffff0000e9a47600 keystone/home on /home (zfs)
0xffff0000bbb23b00 keystone/usr/ports on /usr/ports (zfs)
0xffff0000e9a4c000 keystone/usr/src on /usr/src (zfs)
0xffff0000e9a59100 keystone/var/tmp on /var/tmp (zfs)
0xffff0000e9a68100 keystone/usr/obj on /usr/obj (zfs)
0xffff0000e9a4cb00 keystone/var/imap on /var/imap (zfs)
0xffff0000e9a4b100 keystone/var/audit on /var/audit (zfs)
0xffff0000bbb23000 keystone/var/spool/openldap on /var/spool/openldap (zfs)
0xffff0000e9a58600 keystone/var/spool/httpd on /var/spool/httpd (zfs)
0xffff0000e9a46b00 keystone/var/spool/imap on /var/spool/imap (zfs)
0xffff0000ea23a100 keystone/var/spool/postgres on /var/spool/postgres (zfs)
0xffff0000ea2ef100 keystone/poudriere on /usr/local/poudriere (zfs)
0xffff0000ea239600 keystone/poudriere/data on /usr/local/poudriere/data (zfs)
0xffff0000e9a57b00 keystone/poudriere/ports on /usr/local/poudriere/ports (zfs)
0xffff0000e9a4a600 keystone/poudriere/jails on /usr/local/poudriere/jails (zfs)
0xffff0000ea238b00 keystone/poudriere/ports/default on /usr/local/poudriere/ports/default (zfs)
0xffff0000ea238000 keystone/poudriere/data/packages on /usr/local/poudriere/data/packages (zfs)
0xffff0000ea2ee600 keystone/poudriere/data/cache on /usr/local/poudriere/data/cache (zfs)
0xffff0000ea2edb00 keystone/poudriere/data/logs on /usr/local/poudriere/data/logs (zfs)
0xffff0000e9a57000 keystone/poudriere/data/images on /usr/local/poudriere/data/images (zfs)
0xffff0000e9a66b00 keystone/poudriere/data/.m on /usr/local/poudriere/data/.m (zfs)
0xffff0000e9a49b00 keystone/poudriere/jails/13aarch64 on /usr/local/poudriere/jails/13aarch64 (zfs)
0xffff0000e9a66000 keystone/poudriere/data/wrkdirs on /usr/local/poudriere/data/wrkdirs (zfs)
0xffff0000e9a49000 keystone/usr/ports/distfiles on /usr/ports/distfiles (zfs)

More info: show mount <addr>

db> show page
vm_cnt.v_free_count: 3095
vm_cnt.v_inactive_count: 80
vm_cnt.v_active_count: 287
vm_cnt.v_laundry_count: 57
vm_cnt.v_wire_count: 979462
vm_cnt.v_free_reserved: 1347
vm_cnt.v_free_min: 6266
vm_cnt.v_free_target: 21023
vm_cnt.v_inactive_target: 31534
db> show pageq
pq_free 3095
dom 0 page_cnt 983828 free 3095 pq_act 287 pq_inact 80 pq_laund 57 pq_unsw 0

I encounter the same problem on another ROCKPRO64 under 13.0-RELEASE
Comment 2 Henri Hennebert 2021-04-14 11:52:24 UTC
In case it may be important to the problem:

[root@keystone ~]# sysctl dev.cpu.{0,1,2,3,4,5}.freq
dev.cpu.0.freq: 1416
dev.cpu.1.freq: 1416
dev.cpu.2.freq: 1416
dev.cpu.3.freq: 1416
dev.cpu.4.freq: 1800
dev.cpu.5.freq: 1800
Comment 3 Henri Hennebert 2021-04-14 17:40:41 UTC
I reproduce the freeze, same output _without_ 

"swap_pager: cannot allocate bio"

in msgbuf.

db> sysctl vfs.numvnodes
vfs.numvnodes: 151830
db> sysctl kern.maxvnodes
kern.maxvnodes: 800000
Comment 4 Henri Hennebert 2021-04-15 10:09:58 UTC
After Adding the debugging parafernalia:

options         DEADLKRES
options         INVARIANTS
options         INVARIANT_SUPPORT
options         WITNESS
options         WITNESS_SKIPSPIN
options         DEBUG_LOCKS
options         DEBUG_VFS_LOCKS
options         DIAGNOSTIC

I run the `git pull` which complete successfully.

During this I run:

while :; do  sysctl vfs.numvnodes; sleep 5; done

vfs.numvnodes: 2109
vfs.numvnodes: 2111
vfs.numvnodes: 2111
vfs.numvnodes: 2149
vfs.numvnodes: 5803
vfs.numvnodes: 10623
vfs.numvnodes: 13623
vfs.numvnodes: 18365
vfs.numvnodes: 20625
vfs.numvnodes: 24242
vfs.numvnodes: 28920
vfs.numvnodes: 31991
vfs.numvnodes: 36363
vfs.numvnodes: 38773
vfs.numvnodes: 42396
vfs.numvnodes: 46801
vfs.numvnodes: 47240
vfs.numvnodes: 48841
vfs.numvnodes: 53090
vfs.numvnodes: 54835
vfs.numvnodes: 56418
vfs.numvnodes: 60929
vfs.numvnodes: 63236
vfs.numvnodes: 65361
vfs.numvnodes: 69478
vfs.numvnodes: 71030
vfs.numvnodes: 74277
vfs.numvnodes: 78259
vfs.numvnodes: 78271
vfs.numvnodes: 80496
vfs.numvnodes: 84368
vfs.numvnodes: 86060  /* disk I/O stall */
vfs.numvnodes: 86060
vfs.numvnodes: 86060
vfs.numvnodes: 86060
vfs.numvnodes: 88370
vfs.numvnodes: 91792
vfs.numvnodes: 92484
vfs.numvnodes: 93071
vfs.numvnodes: 97131
vfs.numvnodes: 100652
vfs.numvnodes: 101711
vfs.numvnodes: 105396
vfs.numvnodes: 107957 /* disk I/O stall */
vfs.numvnodes: 107957
vfs.numvnodes: 107957
vfs.numvnodes: 107957
vfs.numvnodes: 107957
vfs.numvnodes: 108053
vfs.numvnodes: 111744
vfs.numvnodes: 115265
vfs.numvnodes: 115265
vfs.numvnodes: 115265
vfs.numvnodes: 115265
vfs.numvnodes: 115265
vfs.numvnodes: 117571
vfs.numvnodes: 121308
vfs.numvnodes: 122212 /* disk I/O stall */
vfs.numvnodes: 122212
vfs.numvnodes: 122212
vfs.numvnodes: 122212
vfs.numvnodes: 122212
vfs.numvnodes: 122212
vfs.numvnodes: 123161
vfs.numvnodes: 126698
vfs.numvnodes: 129217
vfs.numvnodes: 129219 /* disk I/O stall */
vfs.numvnodes: 129219
vfs.numvnodes: 129219
vfs.numvnodes: 129219
vfs.numvnodes: 129219
vfs.numvnodes: 129219
vfs.numvnodes: 131464
vfs.numvnodes: 134805
vfs.numvnodes: 136529
vfs.numvnodes: 136529
vfs.numvnodes: 136529
vfs.numvnodes: 137909
vfs.numvnodes: 141831
vfs.numvnodes: 143280
vfs.numvnodes: 143280
vfs.numvnodes: 143280
vfs.numvnodes: 143355
vfs.numvnodes: 146508
vfs.numvnodes: 149563
vfs.numvnodes: 149567
vfs.numvnodes: 149567
vfs.numvnodes: 149567
vfs.numvnodes: 152239
vfs.numvnodes: 106275
vfs.numvnodes: 666
vfs.numvnodes: 670
vfs.numvnodes: 3239
vfs.numvnodes: 3272
vfs.numvnodes: 3273
vfs.numvnodes: 3273
vfs.numvnodes: 3277
vfs.numvnodes: 3277
vfs.numvnodes: 3277
vfs.numvnodes: 3277
vfs.numvnodes: 3277
vfs.numvnodes: 3277
vfs.numvnodes: 3277
vfs.numvnodes: 3277

And on dmesg I get:

Expensive timeout(9) function: 0xffff0000003e9654(0) 11.542417707 s

Going to ddb:

db> br 0xffff0000003e9654
db> show br
 Map      Count    Address
*ffff000000da1190     1    pffasttimo
db> del 0xffff0000003e9654
db> c
Comment 5 Henri Hennebert 2021-04-17 10:08:05 UTC
New freeze, new info after git pull:

dmesg:
pid 1736 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1391 (squid), jid 0, uid 100, was killed: out of swap space
pid 1168 (named), jid 0, uid 53, was killed: out of swap space
pid 3059 (postgres), jid 0, uid 770, was killed: out of swap space
pid 24693 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1661 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1663 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1658 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1659 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1660 (postgres), jid 0, uid 770, was killed: out of swap space
pid 1655 (postgres), jid 0, uid 770, was killed: out of swap space
KDB: enter: Break to debugger

db> show allchains
...
thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
 thread 101295 (pid 27517, bash) is blocked on lockmgr EXCL
...
more than 16000 lines...

db> show freepages
DOMAIN: 0
FREE LIST 0:

  ORDER (SIZE)  |  NUMBER
                |  POOL 0  |  POOL 1
--            -- --      -- --      --
  11 (008192K)  |  000000  |  000000
  10 (004096K)  |  000000  |  000000
  09 (002048K)  |  000000  |  000000
  08 (001024K)  |  000000  |  000000
  07 (000512K)  |  000000  |  000000
  06 (000256K)  |  000000  |  000000
  05 (000128K)  |  000000  |  000000
  04 (000064K)  |  000000  |  000001
  03 (000032K)  |  000000  |  000003
  02 (000016K)  |  000019  |  000020
  01 (000008K)  |  000094  |  000083
  00 (000004K)  |  001060  |  000605
db> panic
Comment 6 Henri Hennebert 2021-04-22 09:21:58 UTC
New freeze with different ddb

For a complete log of ddb see http://tignes.restart.be/Xfer/keystone-2021-04-22.log

Some extract from this log:

db> show alllocks
Process 76413 (git) thread 0xffffa0009ae9e580 (102119)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009d05d070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa0009ae9e000 (102120)
shared lockmgr zfs (zfs) r = 0 (0xffffa00090e88440) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000c45bf580 (102121)
shared lockmgr zfs (zfs) r = 0 (0xffffa00023c7b628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000c45bf000 (102122)
shared lockmgr zfs (zfs) r = 0 (0xffffa00023c7b628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa00008f1f000 (102124)
shared lockmgr zfs (zfs) r = 0 (0xffffa00098c2d440) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000ebf14580 (102125)
shared lockmgr zfs (zfs) r = 0 (0xffffa0005725a810) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa00023e8f580 (102126)
shared lockmgr zfs (zfs) r = 0 (0xffffa0001472f9f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000b2a80580 (102127)
shared lockmgr zfs (zfs) r = 0 (0xffffa000b51ae628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000b2a80000 (102128)
shared lockmgr zfs (zfs) r = 0 (0xffffa000b51ae440) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000ce44f580 (102129)
shared lockmgr zfs (zfs) r = 0 (0xffffa000a5491258) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000ce44f000 (102130)
shared lockmgr zfs (zfs) r = 0 (0xffffa000b51ae9f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000bee77580 (102131)
shared lockmgr zfs (zfs) r = 0 (0xffffa000948b9070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000bee77000 (102132)
shared lockmgr zfs (zfs) r = 0 (0xffffa00099eed440) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000665df580 (102133)
shared lockmgr zfs (zfs) r = 0 (0xffffa000b51ae810) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa000665df000 (102134)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009566cbe0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa00040981580 (102135)
shared lockmgr zfs (zfs) r = 0 (0xffffa0004c0ef810) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa00040981000 (102136)
shared lockmgr zfs (zfs) r = 0 (0xffffa0002f3f8258) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 76413 (git) thread 0xffffa00048c3b000 (102138)
shared lockmgr zfs (zfs) r = 0 (0xffffa000f0ee9628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1213 (god.plugin) thread 0xffffa000a9c86580 (101479)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009ae859f8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1213 (god.plugin) thread 0xffffa000a9d37000 (101483)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009ae859f8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1213 (god.plugin) thread 0xffffa000a9c86000 (101484)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009ae859f8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1213 (god.plugin) thread 0xffffa000eb352580 (101486)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009ae859f8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1213 (god.plugin) thread 0xffffa00074fae000 (101537)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009ae859f8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1202 (sshd) thread 0xffffa0001c2c5580 (101328)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000a7fc070) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1201 (getty) thread 0xffffa0000a605580 (100543)
shared lockmgr zfs (zfs) r = 0 (0xffffa00070c2f9f8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1137 (netdata) thread 0xffffa0009ae88580 (101439)
shared lockmgr zfs (zfs) r = 0 (0xffffa00023fe3070) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1137 (netdata) thread 0xffffa00074e35580 (101440)
shared lockmgr zfs (zfs) r = 0 (0xffffa00023fe3070) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1137 (netdata) thread 0xffffa0001c2c5000 (101442)
shared lockmgr zfs (zfs) r = 0 (0xffffa0002384bbe0) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1137 (netdata) thread 0xffffa000975fe580 (101446)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000a661628) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1082 (sendmail) thread 0xffffa0001c375580 (101334)
shared lockmgr zfs (zfs) r = 0 (0xffffa00023da2628) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 966 (syslogd) thread 0xffffa0000c93c580 (100548)
shared lockmgr zfs (zfs) r = 0 (0xffffa0001c0e6810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 784 (devd) thread 0xffffa0000c82d580 (100546)
shared lockmgr zfs (zfs) r = 0 (0xffffa0002380b070) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 26 (pagedaemon) thread 0xffffa000056ba580 (100152)
shared lockmgr zfs (zfs) r = 0 (0xffffa00037740dc8) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 0 (kernel) thread 0xffffa0000537e000 (100104)
exclusive lockmgr zfs (zfs) r = 0 (0xffffa00036915070) locked @ /usr/src/sys/kern/vfs_subr.c:1589
exclusive sx arc vnlru lock (arc vnlru lock) r = 0 (0xffff00000146bc38) locked @ /usr/src/sys/contrib/openzfs/module/os/freebsd/zfs/arc_os.c:163
db> show lockedvnods
Locked vnodes
vnode 0xffffa0000a6615b8: type VREG
    usecount 2, writecount 0, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0000a52a840 ref 138 pages 6 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa0000a7fc000: type VREG
    usecount 2, writecount 0, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0000c9fa948 ref 91 pages 5 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa0002380b000: type VREG
    usecount 3, writecount -4, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa000239d3318 ref 5 pages 1 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa0001c0e67a0: type VREG
    usecount 3, writecount -3, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0001c1b5210 ref 4 pages 1 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa00023da25b8: type VREG
    usecount 4, writecount -6, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0001c1b0318 ref 7 pages 1 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa00037740d58: type VREG
    usecount 3, writecount 2, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0003777fe70 ref 2 pages 8 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa00070c2f988: type VREG
    usecount 3, writecount -4, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0003712cc60 ref 5 pages 1 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa00023fe3000: type VREG
    usecount 5, writecount -10, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa000372b1528 ref 11 pages 42 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 2)
vnode 0xffffa0002384bb70: type VREG
    usecount 2, writecount 0, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0002387b840 ref 20 pages 1 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009ae85988: type VREG
    usecount 7, writecount -3, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa00070eb2108 ref 9 pages 38 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 5)
vnode 0xffffa0001472f988: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00023c7b5b8: type VDIR
    usecount 2, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 2)
vnode 0xffffa0004c0ef7a0: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0002f3f81e8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0005725a7a0: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00036915000: type VREG
    usecount 0, writecount 0, refcount 1 seqc users 1
    hold count flags ()
    flags (VIRF_DOOMED)
    lock type zfs: EXCL by thread 0xffffa0000537e000 (pid 0, kernel, tid 100104)
vnode 0xffffa00090e883d0: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000948b9000: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00098c2d3d0: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009d05d000: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00099eed3d0: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000a54911e8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000f0ee95b8: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009566cb70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000b51ae3d0: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000b51ae5b8: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000b51ae7a0: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000b51ae988: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
db> show allchains
...
chain 2:
 thread 102119 (pid 76413, git) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102131 (pid 76413, git) is sleeping on 0xffffa0009b04bd88 "zio->io_cv"
chain 3:
 thread 102120 (pid 76413, git) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102131 (pid 76413, git) is sleeping on 0xffffa0009b04bd88 "zio->io_cv"
...
chain 11:
 thread 102129 (pid 76413, git) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102131 (pid 76413, git) is sleeping on 0xffffa0009b04bd88 "zio->io_cv"
...
chain 17:
 thread 102135 (pid 76413, git) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102131 (pid 76413, git) is sleeping on 0xffffa0009b04bd88 "zio->io_cv"
...
chain 388:
 thread 100102 (pid 0, arc_prune_0) is blocked on sx "arc vnlru lock" XLOCK
 thread 100104 (pid 0, arc_prune_2) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102124 (pid 76413, git) is sleeping on 0xffffa0009b6493e8 "zio->io_cv"
chain 389:
 thread 100103 (pid 0, arc_prune_1) is blocked on sx "arc vnlru lock" XLOCK
 thread 100104 (pid 0, arc_prune_2) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102124 (pid 76413, git) is sleeping on 0xffffa0009b6493e8 "zio->io_cv"
chain 390:
 thread 100104 (pid 0, arc_prune_2) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102124 (pid 76413, git) is sleeping on 0xffffa0009b6493e8 "zio->io_cv"
chain 391:
 thread 100105 (pid 0, arc_prune_3) is blocked on sx "arc vnlru lock" XLOCK
 thread 100104 (pid 0, arc_prune_2) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102124 (pid 76413, git) is sleeping on 0xffffa0009b6493e8 "zio->io_cv"
chain 392:
 thread 100106 (pid 0, arc_prune_4) is blocked on sx "arc vnlru lock" XLOCK
 thread 100104 (pid 0, arc_prune_2) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102124 (pid 76413, git) is sleeping on 0xffffa0009b6493e8 "zio->io_cv"
chain 393:
 thread 100107 (pid 0, arc_prune_5) is blocked on sx "arc vnlru lock" XLOCK
 thread 100104 (pid 0, arc_prune_2) is blocked on sx "zfsvfs->z_hold_mtx[i]" XLOCK
 thread 102124 (pid 76413, git) is sleeping on 0xffffa0009b6493e8 "zio->io_cv"
...
db> show msgbuf
...
KDB: enter: Break to debugger
lock order reversal:
 1st 0xffffa00063d67070 zfs (zfs, lockmgr) @ /usr/src/sys/kern/vfs_mount.c:1071
 2nd 0xffffa000eb5ed9f8 devfs (devfs, lockmgr) @ /usr/src/sys/kern/vfs_mount.c:1083
lock order devfs -> zfs established at:
#0 0xffff0000003968fc at witness_checkorder+0x40c
#1 0xffff00000030b5cc at lockmgr_xlock+0x40
#2 0xffff0000004104a4 at _vn_lock+0x54
#3 0xffff0000003f2c5c at vfs_domount+0xfc4
#4 0xffff0000003f13f8 at vfs_donmount+0x794
#5 0xffff0000003f523c at kernel_mount+0x48
#6 0xffff0000003f7790 at parse_mount+0x494
#7 0xffff0000003f5e4c at vfs_mountroot+0x3d8
#8 0xffff0000002ce638 at start_init+0x24
#9 0xffff0000002f6ec0 at fork_exit+0x64
#10 0xffff0000006aff28 at fork_trampoline+0x10
lock order zfs -> devfs attempted at:
#0 0xffff0000003970e8 at witness_checkorder+0xbf8
#1 0xffff00000030b5cc at lockmgr_xlock+0x40
#2 0xffff0000004104a4 at _vn_lock+0x54
#3 0xffff0000003f2c5c at vfs_domount+0xfc4
#4 0xffff0000003f13f8 at vfs_donmount+0x794
#5 0xffff0000003f0c24 at sys_nmount+0x60
#6 0xffff0000006b0b34 at do_el0_sync+0x7f8
#7 0xffff000000696a1c at handle_el0_sync+0x90
db> dump
Dumping 3481 out of 3941 MB:..1%..11%..21%..31%..41%..51%..61%..71%..81%..91%
Dump complete
Comment 7 Henri Hennebert 2021-05-22 14:08:34 UTC
Maybe this one can ring a bell for someone?

db> show alllocks
Process 2194 (awk) thread 0xffffa0003325c000 (101360)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000eb80be0) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 2193 (sysctl) thread 0xffffa0003304f000 (101352)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000529e810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 2174 (sleep) thread 0xffffa0000ec52580 (101308)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000529e810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 2044 (sh) thread 0xffffa0000eb77580 (100550)
shared lockmgr zfs (zfs) r = 0 (0xffffa00078461810) locked @ /usr/src/sys/kern/vfs_vnops.c:1111
Process 1716 (git) thread 0xffffa0002eb1b580 (101615)
shared lockmgr zfs (zfs) r = 0 (0xffffa000a02c9628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0002eb1b000 (101616)
shared lockmgr zfs (zfs) r = 0 (0xffffa0006a2db070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0004e1c0580 (101617)
shared lockmgr zfs (zfs) r = 0 (0xffffa000a3835be0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000b7cf4580 (101618)
shared lockmgr zfs (zfs) r = 0 (0xffffa000350d29f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000b7cf4000 (101619)
shared lockmgr zfs (zfs) r = 0 (0xffffa000bcef89f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000bcb90580 (101620)
shared lockmgr zfs (zfs) r = 0 (0xffffa000dd3d8be0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000bcb90000 (101621)
shared lockmgr zfs (zfs) r = 0 (0xffffa000b230ebe0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0004897d580 (101622)
shared lockmgr zfs (zfs) r = 0 (0xffffa000d254a9f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0004897d000 (101623)
shared lockmgr zfs (zfs) r = 0 (0xffffa0005bd29dc8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0004897c580 (101624)
shared lockmgr zfs (zfs) r = 0 (0xffffa00068a71440) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0004897c000 (101625)
shared lockmgr zfs (zfs) r = 0 (0xffffa000ed81a628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0009db0f580 (101626)
shared lockmgr zfs (zfs) r = 0 (0xffffa00051459be0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa0009db0f000 (101627)
shared lockmgr zfs (zfs) r = 0 (0xffffa0002654b810) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000a34dd580 (101628)
shared lockmgr zfs (zfs) r = 0 (0xffffa0001f862070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000a34dd000 (101629)
shared lockmgr zfs (zfs) r = 0 (0xffffa00013453628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000a3186580 (101630)
shared lockmgr zfs (zfs) r = 0 (0xffffa0007fb3adc8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000a3186000 (101631)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009d4d2be0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000a22d7580 (101632)
shared lockmgr zfs (zfs) r = 0 (0xffffa000a3b7a9f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa000a22d7000 (101633)
shared lockmgr zfs (zfs) r = 0 (0xffffa0007616b258) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1716 (git) thread 0xffffa00048db7580 (101634)
shared lockmgr zfs (zfs) r = 0 (0xffffa000084b79f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa0001b377000 (101595)
shared lockmgr zfs (zfs) r = 0 (0xffffa0003e36c070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253b7580 (101596)
shared lockmgr zfs (zfs) r = 0 (0xffffa000403809f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253e6000 (101597)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009e11e9f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253b7000 (101598)
shared lockmgr zfs (zfs) r = 0 (0xffffa0006a3d8628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000251b5580 (101599)
shared lockmgr zfs (zfs) r = 0 (0xffffa00068a71628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000251b5000 (101600)
shared lockmgr zfs (zfs) r = 0 (0xffffa0001c092dc8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253bf000 (101601)
shared lockmgr zfs (zfs) r = 0 (0xffffa000564af9f8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000d9196000 (101602)
shared lockmgr zfs (zfs) r = 0 (0xffffa000aaa47258) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000d943f580 (101603)
shared lockmgr zfs (zfs) r = 0 (0xffffa00024628628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa0001b324000 (101604)
shared lockmgr zfs (zfs) r = 0 (0xffffa000576a1440) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000251b3580 (101605)
shared lockmgr zfs (zfs) r = 0 (0xffffa000a9c19628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000251b3000 (101606)
shared lockmgr zfs (zfs) r = 0 (0xffffa00068a71810) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253e5580 (101607)
shared lockmgr zfs (zfs) r = 0 (0xffffa0003cad4628) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253e5000 (101608)
shared lockmgr zfs (zfs) r = 0 (0xffffa0001818f258) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253e2580 (101609)
shared lockmgr zfs (zfs) r = 0 (0xffffa00061525070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253e2000 (101610)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009d081258) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa000253e6580 (101611)
shared lockmgr zfs (zfs) r = 0 (0xffffa0005bda6070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa0004e1c0000 (101612)
shared lockmgr zfs (zfs) r = 0 (0xffffa000395b9070) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa0000ec4b580 (101613)
shared lockmgr zfs (zfs) r = 0 (0xffffa000d68b0be0) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1710 (git) thread 0xffffa0000ec4b000 (101614)
shared lockmgr zfs (zfs) r = 0 (0xffffa000b6631dc8) locked @ /usr/src/sys/kern/vfs_cache.c:4854
Process 1599 (git) thread 0xffffa000253bf580 (101585)
shared sx vm map (user) (vm map (user)) r = 0 (0xffffa0001b684b88) locked @ /usr/src/sys/vm/vm_map.c:4960
Process 1220 (god.plugin) thread 0xffffa0009e62e580 (101488)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009264a628) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1220 (god.plugin) thread 0xffffa0009e6b3000 (101493)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009264a628) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1220 (god.plugin) thread 0xffffa0001b32f580 (101496)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009264a628) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1220 (god.plugin) thread 0xffffa0009e5ca580 (101497)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009264a628) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1217 (python3.8) thread 0xffffa000d943f000 (101555)
shared lockmgr zfs (zfs) r = 0 (0xffffa0009264a440) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1133 (netdata) thread 0xffffa000926b7580 (101457)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000529e810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1133 (netdata) thread 0xffffa000926b7000 (101458)
shared lockmgr zfs (zfs) r = 0 (0xffffa00021237810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1133 (netdata) thread 0xffffa000926b6000 (101467)
shared lockmgr zfs (zfs) r = 0 (0xffffa00021237810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1133 (netdata) thread 0xffffa000926f8580 (101468)
shared lockmgr zfs (zfs) r = 0 (0xffffa0000529e810) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 1083 (sendmail) thread 0xffffa0003304f580 (101346)
shared lockmgr zfs (zfs) r = 0 (0xffffa00021686070) locked @ /usr/src/sys/kern/vfs_subr.c:2974
Process 0 (kernel) thread 0xffffa0000537b000 (100106)
exclusive lockmgr zfs (zfs) r = 0 (0xffffa0009e2ba258) locked @ /usr/src/sys/kern/vfs_subr.c:1589
exclusive sx arc vnlru lock (arc vnlru lock) r = 0 (0xffff00000146cc38) locked @ /usr/src/sys/contrib/openzfs/module/os/freebsd/zfs/arc_os.c:163
db> show lockedvnods
Locked vnodes
vnode 0xffffa0000529e7a0: type VREG
    usecount 5, writecount 0, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0000084c738 ref 193 pages 144 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 4)
vnode 0xffffa0000eb80b70: type VREG
    usecount 3, writecount 0, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0000b215948 ref 30 pages 2 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa00021686000: type VREG
    usecount 4, writecount -6, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0002166a318 ref 7 pages 14 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa0001c092d58: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000395b9000: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000246285b8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0003cad45b8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00040380988: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000b6631d58: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0001818f1e8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000d68b0b70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0003e36c000: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000aaa471e8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009d0811e8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000a9c195b8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000576a13d0: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000564af988: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00061525000: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0005bda6000: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009e11e988: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0006a3d85b8: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00068a717a0: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00068a715b8: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000212377a0: type VREG
    usecount 5, writecount -10, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa00033224840 ref 14 pages 105 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 2)
vnode 0xffffa0009264a5b8: type VREG
    usecount 6, writecount -3, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0008bbb3e70 ref 9 pages 99 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 4)
vnode 0xffffa0009264a3d0: type VREG
    usecount 2, writecount 0, refcount 2 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0009e06a948 ref 6 pages 161 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
vnode 0xffffa000bcef8988: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009e2ba1e8: type VREG
    usecount 0, writecount 0, refcount 1 seqc users 1
    hold count flags ()
    flags (VIRF_DOOMED)
    lock type zfs: EXCL by thread 0xffffa0000537b000 (pid 0, kernel, tid 100106)
vnode 0xffffa0001f862000: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000a02c95b8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000dd3d8b70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000ed81a5b8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0002654b7a0: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000134535b8: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00051459b70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000084b7988: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000d254a988: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000b230eb70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0007fb3ad58: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0009d4d2b70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000a3b7a988: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000a3835b70: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0005bd29d58: type VDIR
    usecount 1, writecount 0, refcount 2 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0006a2db000: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000350d2988: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa00068a713d0: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa0007616b1e8: type VDIR
    usecount 1, writecount 0, refcount 1 seqc users 0 mountedhere 0
    hold count flags ()
    flags ()
    lock type zfs: SHARED (count 1)
vnode 0xffffa000784617a0: type VREG
    usecount 1, writecount 1, refcount 1 seqc users 0
    hold count flags ()
    flags ()
    v_object 0xffffa0006a896c60 ref 0 pages 0 cleanbuf 0 dirtybuf 0
    lock type zfs: SHARED (count 1)
db> dump
Dumping 3242 out of 3941 MB:..1%..11%..21%..31%..41%..51%..61%..71%..81%..91%
Dump complete
Comment 8 Daniel Engberg freebsd_committer 2021-06-21 07:41:28 UTC
(In reply to Henri Hennebert from comment #2)
Hi, this is most likely one of the reasons.
https://wiki.freebsd.org/arm/RockChip#Known_issues (last section)
Comment 9 Henri Hennebert 2021-06-21 07:49:02 UTC
(In reply to Daniel Engberg from comment #8)
On another ROCKPRO64 running with:

# sysctl dev.cpu|grep freq:
dev.cpu.5.freq: 1416
dev.cpu.4.freq: 1416
dev.cpu.3.freq: 1416
dev.cpu.2.freq: 1416
dev.cpu.1.freq: 1416
dev.cpu.0.freq: 1416

I encounter the same problem :-(
Comment 10 Daniel Engberg freebsd_committer 2021-06-21 08:25:55 UTC
To be honest I think you're expecting a bit much out of a device with 4Gb of RAM. I think we need to establish a few data points going forward.

I have a "buildbox" similar to yours with a few exceptions,

* Runs FreeBSD-13-STABLE-n245283-70a2e9a3d44 (no debugging enabled)
* Only uses UFS simply because of the memory usage ZFS imposes especially when running Poudriere.
* A USB 3 2.5" HDD attached to it (spinning rust), USB-powered
* Rather beefy PSU, Meanwell 5A 12V
* Largest heatsink Pine64 offers
* Dual port ethernet Intel PCIe NIC
Running fine for weeks (with powerd), I also have a few "clients" without a USB-HDD that's also been working fine for weeks (smaller PSU, 3A)

Since these boards doesn't need a lot of packages I simply use ports and generate packages via pkg which works fine.

I'd suggest that you try a similar setup to make it easier to track down including using the same revision. I have a generic sd-card image if you want to save some time. It needs some polishing but works fine for me at least.

https://projects.pyret.net/files/public/freebsd/IMAGES/FreeBSD-13-STABLE-n245283-70a2e9a3d44/ --> Write image to SD card (see README file), install git (see README file) --> mount HDD (go with UFS for initial testing) --> pull repo using git
Does that work or does the system freeze?
You should be fine without a swap partition despite ports or base being rather large. I only use the Intel PCIe NIC but the dwc if should be fine too.
Comment 11 Daniel Engberg freebsd_committer 2021-06-21 08:29:06 UTC
Looking at the above you seem to run out of memory frequently (which will cause issues). Since you say it freezes I don't think its hardware related but I think it's probably best to test something that is known to work to rule out such issues.
Comment 12 Henri Hennebert 2021-06-21 08:49:38 UTC
(In reply to Daniel Engberg from comment #10)
On one ROCKPRO64 with this problem I am running 13.0-RELEASE.

On my test config I encounter the problem with 13.0-STABLE
n244864, n245095, n245189, n245705, n246023.

I encounter the problem only during git pull (and not at every git pull) and during this the swap is generally not used.

When running poudriere with:

cpuset -c -l 4-5 poudriere bulk -j 13aarch64 -z pine64 -f /usr/local/poudriere/pine64-pkglst

I never encounter a memory problem during those builds.

I want to stay with zfs because I heavily use snapshots.

I will test with ncpu=4 to rule out the big.LITTLE problem.
Comment 13 Daniel Engberg freebsd_committer 2021-06-21 09:01:30 UTC
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=255048#c1
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=255048#c5
Both points to memory related issues as in memory starvation which is why I think it's a better approach to test something we know works and go for from there but since you seem to be deadset on running zfs, a lot of services and poudriere I guess you have to live the with issues.

I can tell you beforehand that there's no chance that you'll be able to build rust for instance without using at max 2 jobs and a lot of swap, ZFS will increase usage with a lot.
Comment 14 Henri Hennebert 2021-06-21 09:16:53 UTC
(In reply to Daniel Engberg from comment #13)

I was previously running a PINE64+ (2GB) under 12.0-RELEASE, 12.1-RELEASE and 12.2-RELEASE and zfs without problem. The /usr/ports being under subversion and the ports being updated with portupgrade. The uptime being >150 days.

I switch to git and poudriere when I replace the PINE64+ by ROCKPRO64.

I am convinced that 4GB for just a git pull under zfs should be OK.
Comment 15 Henri Hennebert 2021-06-21 11:21:39 UTC
With hw.ncpu=4

while :
do
zfs rollback /usr/ports@xxxxx
git pull
done

after at least 5 iterations the system freeze with 23% memory used (netdata).

show alllocks
and
show lockedvnods

are the same as in comment 7

Just before the freeze vfs.numvnodes: 140484

and 

Process 0 (kernel) thread 0xffffa00004ac9580 (100091)
exclusive lockmgr zfs (zfs) r = 0 (0xffffa000dd157be0) locked @ /usr/src/sys/kern/vfs_subr.c:1589
exclusive sx arc vnlru lock (arc vnlru lock) r = 0 (0xffff000001480530) locked @ /usr/src/sys/contrib/openzfs/module/os/freebsd/zfs/
arc_os.c:165

vnode 0xffffa000dd157b70: type VREG
    usecount 0, writecount 0, refcount 1 seqc users 1
    hold count flags ()
    flags (VIRF_DOOMED)
    lock type zfs: EXCL by thread 0xffffa00004ac9580 (pid 0, kernel, tid 100091)
Comment 16 Henri Hennebert 2021-09-18 09:46:35 UTC
I replace the "metal" usb3 disk "WD My Passport 2606 1024" with a "Samsung
Portable SSD T5 512MB" disk and the problem disappear.
So I think that disk latency at IO time induce the problem.