FreeBSD crash "VERIFY(msp->ms_weight & METASLAB_ACTIVE_MASK)"

w0w · Oct 30, 2023, 4:19 AM

Something unusual happened this night, I've never seen such crashes before.

Crash report begins.  Anonymous machine information:

amd64
14.0-CURRENT
FreeBSD 14.0-CURRENT amd64 1400094 #0 plus-RELENG_23_09-n256160-b373d8da4a4: Fri Oct 27 02:23:29 UTC 2023     root@freebsd:/var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/obj/amd64/ERwoNEbB/var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/

Crash report details:

No PHP errors found.

Filename: /var/crash/info.0
Dump header from device: /dev/ada0p3
  Architecture: amd64
  Architecture Version: 4
  Dump Length: 379392
  Blocksize: 512
  Compression: none
  Dumptime: 2023-10-30 02:13:28 +0200
  Hostname: _primary._
  Magic: FreeBSD Text Dump
  Version String: FreeBSD 14.0-CURRENT amd64 1400094 #0 plus-RELENG_23_09-n256156-2c92a95f469: Mon Oct 23 17:35:00 UTC 2023
    root@freebsd:/var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/obj/amd64/
  Panic String: VERIFY(msp->ms_weight & METASLAB_ACTIVE_MASK) failed

  Dump Parity: 1373055245
  Bounds: 0
  Dump Status: good

Filename: /var/crash/textdump.tar.0
ddb.txt���������������������������������������������������������������������������������������������0600����0�������0�������1231616�����14517572450�  7203� �����������������������������������������������������������������������������������������������������ustar���root����������������������������wheel������������������������������������������������������������������������������������������������������������������������������������������������������������������������������������������������������������������db:0:kdb.enter.default>  run pfs
db:1:pfs> bt
Tracing pid 48173 tid 341489 td 0xfffffe0153e14740
kdb_enter() at kdb_enter+0x32/frame 0xfffffe01543696e0
vpanic() at vpanic+0x163/frame 0xfffffe0154369810
spl_panic() at spl_panic+0x3a/frame 0xfffffe0154369870
metaslab_alloc_dva() at metaslab_alloc_dva+0x14ef/frame 0xfffffe0154369990
metaslab_alloc() at metaslab_alloc+0x240/frame 0xfffffe0154369a30
zio_alloc_zil() at zio_alloc_zil+0x190/frame 0xfffffe0154369b10
zil_lwb_write_close() at zil_lwb_write_close+0x3a3/frame 0xfffffe0154369b80
zil_commit_impl() at zil_commit_impl+0x904/frame 0xfffffe0154369d10
zfs_fsync() at zfs_fsync+0x8f/frame 0xfffffe0154369d50
vop_stdfdatasync() at vop_stdfdatasync+0x34/frame 0xfffffe0154369d80
kern_fsync() at kern_fsync+0x8d/frame 0xfffffe0154369e00
amd64_syscall() at amd64_syscall+0x138/frame 0xfffffe0154369f30
fast_syscall_common() at fast_syscall_common+0xf8/frame 0xfffffe0154369f30
--- syscall (550, FreeBSD ELF64, fdatasync), rip = 0x825c4056a, rsp = 0x834d68da8, rbp = 0x834d68dc0 ---
db:1:pfs>  show registers
cs                        0x20
ds                        0x3b
es                        0x3b
fs                        0x13
gs                        0x1b
ss                        0x28
rax                       0x12
rcx         0xffffffff814b1aaf
rdx         0xffffffff814a2070
rbx                      0x100
rsp         0xfffffe01543696e0
rbp         0xfffffe01543696e0
rsi                       0x80
rdi         0xffffffff83024090  cnputs_mtx
r8                           0
r9                           0
r10                          0
r11                          0
r12                          0
r13         0xfffff80009603c40
r14         0xffffffff838815f8  .L.str.23+0xc5
r15         0xfffffe0153e14740
rip         0xffffffff80d33712  kdb_enter+0x32
rflags                    0x82
kdb_enter+0x32: movq    $0,0x234c173(%rip)
db:1:pfs>  show pcpu
cpuid        = 7
dynamic pcpu = 0xfffffe009ca69cc0
curthread    = 0xfffffe0153e14740: pid 48173 tid 341489 critnest 1 "unbound"
curpcb       = 0xfffffe0153e14c60
fpcurthread  = 0xfffffe0153e14740: pid 48173 "unbound"
idlethread   = 0xfffffe00c636b560: tid 100010 "idle: cpu7"
self         = 0xffffffff84217000
curpmap      = 0xfffff80009ed3ad0
tssp         = 0xffffffff84217384
rsp0         = 0xfffffe015436a000
kcr3         = 0x800000039df26227
ucr3         = 0x800000013eb82a27
scr3         = 0x13eb82a27
gs32p        = 0xffffffff84217404
ldt          = 0xffffffff84217444
tss          = 0xffffffff84217434
curvnet      = 0
spin locks held:
db:1:pfs>  run lockinfo
db:2:lockinfo> show locks
shared lockmgr zfs (zfs) r = 0 (0xfffff801154c2930) locked @ /var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/sources/FreeBSD-src-plus-RELENG_23_09/sys/kern/vfs_syscalls.c:3549
db:2:lockinfo>  show alllocks
Process 48173 (unbound) thread 0xfffffe0153e14740 (341489)
shared lockmgr zfs (zfs) r = 0 (0xfffff801154c2930) locked @ /var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/sources/FreeBSD-src-plus-RELENG_23_09/sys/kern/vfs_syscalls.c:3549
Process 65161 (dpinger) thread 0xfffffe0153eab740 (200799)
exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffff80014759cc0) locked @ /var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/sources/FreeBSD-src-plus-RELENG_23_09/sys/kern/uipc_socket.c:4036
Process 64755 (dpinger) thread 0xfffffe0153966740 (200795)
exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffff800148ea180) locked @ /var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/sources/FreeBSD-src-plus-RELENG_23_09/sys/kern/uipc_socket.c:4036
Process 64236 (dpinger) thread 0xfffffe01519671e0 (200791)
exclusive sx so_rcv_sx (so_rcv_sx) r = 0 (0xfffff800148f2900) locked @ /var/jenkins/workspace/pfSense-Plus-snapshots-23_09-main/sources/FreeBSD-src-plus-RELENG_23_09/sys/kern/uipc_socket.c:4036

As I understand, this can be ZFS related?
Found something similar:
https://github.com/openzfs/zfs/issues/15435

stephenw10 · Nov 1, 2023, 8:52 PM

Anything in the message buffer before it panicked?

It does look very much like that bug report.

What is your ZFS install? A mirror? Anything custom?

w0w · Nov 2, 2023, 3:23 AM

@stephenw10
Yes it is two drive mirror, nothing unusual in message buffer.

stephenw10 · Nov 3, 2023, 4:44 AM

Have you only seen it one time? Nothing special happening at the time?

w0w · Nov 3, 2023, 4:44 AM

@stephenw10
Yes it happened one time only, at night, when I was asleep, According to the logs no large events like pfBlocker update or anything happened. Almost no network activity at this time.
But… earlier in the evening I have seen some slowness of the internet, like pages loaded too slow, YouTube showed some lags. I really don't think it's related to the crash. Perhaps it's just a glitch of the provider.

stephenw10 · Nov 3, 2023, 1:21 PM

Hmm, Ok. I'll see what else I can find. As far as I know though we haven't seen any other reports of that.