"panic: pool_do_get: mcl2k2 free list modified" under sustained iperf3 server load

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
1 message Options
Reply | Threaded
Open this post in threaded view
|

"panic: pool_do_get: mcl2k2 free list modified" under sustained iperf3 server load

Troy Martin
Hello,

I have discovered a replicable crash in pool_do_get on an OpenBSD machine being used as a
server for iperf3 tests within a private network. I first encountered on 6.5-release, then
upgraded to 6.8-current to see if that would resolve it but I can still cause the panic.
It appears to happen between 500 and 800 seconds into an iperf3 stress test; system uptime
does not seem to be a factor. Topology of the network is as follows:

host720 (iperf3 server on openbsd 6.8) <-> L2 switch <-> L3 gateway <-> L2 switch <->
host710 (iperf3 client on openbsd 6.8)

iperf3 server command: host720# iperf3 -s
iperf3 client command: host710# iperf3 -t 0 -c 10.107.20.10

If any additional ddb commands need to be run besides the ones listed below I can easily
replicate the crash for them; this is my first time submitting a bug report to the list
and I can't sendbug(1) from this particular box.

Cheers,

Troy Martin
[hidden email]

----

dmesg (from serial console):

OpenBSD 6.8 (GENERIC) #5: Mon Feb 22 04:04:49 MST 2021
    [hidden email]:/usr/src/sys/arch/amd64/compile/GENERIC
real mem = 1056899072 (1007MB)
avail mem = 1009983488 (963MB)
random: good seed from bootblocks
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.5 @ 0xe1000 (10 entries)
bios0: vendor innotek GmbH version "VirtualBox" date 12/01/2006
bios0: innotek GmbH VirtualBox
acpi0 at bios0: ACPI 4.0
acpi0: sleep states S0 S5
acpi0: tables DSDT FACP APIC SSDT
acpi0: wakeup devices
acpitimer0 at acpi0: 3579545 Hz, 32 bits
acpimadt0 at acpi0 addr 0xfee00000: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Core(TM) i7-8700K CPU @ 3.70GHz, 3696.50 MHz, 06-9e-0a
cpu0:
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,MMX,FXSR,SS
E,SSE2,HTT,SSE3,PCLMUL,MWAIT,SSSE3,CX16,PCID,SSE4.1,SSE4.2,MOVBE,POPCNT,AES,XSAVE,AVX,RDRA
ND,NXE,RDTSCP,LONG,LAHF,ABM,3DNOWP,ITSC,FSGSBASE,AVX2,INVPCID,RDSEED,CLFLUSHOPT,MD_CLEAR,L
1DF,MELTDOWN
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: smt 0, core 0, package 0
mtrr: CPU supports MTRRs but not enabled by BIOS
cpu0: apic clock running at 1000MHz
cpu0: mwait min=64, max=64
ioapic0 at mainbus0: apid 1 pa 0xfec00000, version 20, 24 pins, remapped
acpiprt0 at acpi0: bus 0 (PCI0)
acpipci0 at acpi0 PCI0: 0x00000000 0x00000011 0x00000001
acpiac0 at acpi0: AC unit online
acpicpu0 at acpi0: C1(@1 halt!)
acpivideo0 at acpi0: GFX0
cpu0: using VERW MDS workaround (except on vmm entry)
pci0 at mainbus0 bus 0
pchb0 at pci0 dev 0 function 0 "Intel 82441FX" rev 0x02
pcib0 at pci0 dev 1 function 0 "Intel 82371SB ISA" rev 0x00
pciide0 at pci0 dev 1 function 1 "Intel 82371AB IDE" rev 0x01: DMA, channel 0 configured
to compatibility, channel 1 configured to compatibility
wd0 at pciide0 channel 0 drive 0: <VBOX HARDDISK>
wd0: 128-sector PIO, LBA, 16384MB, 33554432 sectors
wd0(pciide0:0:0): using PIO mode 4, Ultra-DMA mode 2
atapiscsi0 at pciide0 channel 1 drive 0
scsibus1 at atapiscsi0: 2 targets
cd0 at scsibus1 targ 0 lun 0: <VBOX, CD-ROM, 1.0> removable
cd0(pciide0:1:0): using PIO mode 4, Ultra-DMA mode 2
vga1 at pci0 dev 2 function 0 "InnoTek VirtualBox Graphics Adapter" rev 0x00
wsdisplay at vga1 not configured
em0 at pci0 dev 3 function 0 "Intel 82540EM" rev 0x02: apic 1 int 19, address
08:00:27:46:e1:02
"InnoTek VirtualBox Guest Service" rev 0x00 at pci0 dev 4 function 0 not configured
auich0 at pci0 dev 5 function 0 "Intel 82801AA AC97" rev 0x01: apic 1 int 21, ICH
ac97: codec id 0x83847600 (SigmaTel STAC9700)
audio0 at auich0
ohci0 at pci0 dev 6 function 0 "Apple Intrepid USB" rev 0x00: apic 1 int 22, version 1.0
piixpm0 at pci0 dev 7 function 0 "Intel 82371AB Power" rev 0x08: apic 1 int 23
iic0 at piixpm0
em1 at pci0 dev 8 function 0 "Intel 82540EM" rev 0x02: apic 1 int 16, address
08:00:27:43:c6:70
ehci0 at pci0 dev 11 function 0 "Intel 82801FB USB" rev 0x00: apic 1 int 19
usb0 at ehci0: USB revision 2.0
uhub0 at usb0 configuration 1 interface 0 "Intel EHCI root hub" rev 2.00/1.00 addr 1
isa0 at pcib0
isadma0 at isa0
com0 at isa0 port 0x3f8/8 irq 4: ns16550a, 16 byte fifo
com0: console
pckbc0 at isa0 port 0x60/5 irq 1 irq 12
pckbd0 at pckbc0 (kbd slot)
wskbd0 at pckbd0 mux 1
pms0 at pckbc0 (aux slot)
wsmouse0 at pms0 mux 0
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
usb1 at ohci0: USB revision 1.0
uhub1 at usb1 configuration 1 interface 0 "Apple OHCI root hub" rev 1.00/1.00 addr 1
vscsi0 at root
scsibus2 at vscsi0: 256 targets
softraid0 at root
scsibus3 at softraid0: 256 targets
root on wd0a (891d4cfcef7cbcc1.a) swap on wd0b dump on wd0b
WARNING: / was not properly unmounted
Automatic boot in progress: starting file system checks.
/dev/wd0a (891d4cfcef7cbcc1.a): 1805 files, 47809 used, 172894 free (102 frags, 21599
blocks, 0.0% fragmentation)
/dev/wd0a (891d4cfcef7cbcc1.a): MARKING FILE SYSTEM CLEAN
/dev/wd0k (891d4cfcef7cbcc1.k): 3 files, 4 used, 1536851 free (19 frags, 192104 blocks,
0.0% fragmentation)
/dev/wd0k (891d4cfcef7cbcc1.k): MARKING FILE SYSTEM CLEAN
/dev/wd0d (891d4cfcef7cbcc1.d): UNREF FILE I=3  OWNER=root MODE=100600
/dev/wd0d: SIZE=131072 MTIME=Apr  7 23:26 2021  (CLEARED)
/dev/wd0d (891d4cfcef7cbcc1.d): FREE BLK COUNT(S) WRONG IN SUPERBLK (SALVAGED)
/dev/wd0d (891d4cfcef7cbcc1.d): SUMMARY INFORMATION BAD (SALVAGED)
/dev/wd0d (891d4cfcef7cbcc1.d): BLK(S) MISSING IN BIT MAPS (SALVAGED)
/dev/wd0d (891d4cfcef7cbcc1.d): 6 files, 5 used, 292930 free (34 frags, 36612 blocks, 0.0%
fragmentation)
/dev/wd0d (891d4cfcef7cbcc1.d): MARKING FILE SYSTEM CLEAN
/dev/wd0f (891d4cfcef7cbcc1.f): 17332 files, 591646 used, 209217 free (1225 frags, 25999
blocks, 0.2% fragmentation)
/dev/wd0f (891d4cfcef7cbcc1.f): MARKING FILE SYSTEM CLEAN
/dev/wd0g (891d4cfcef7cbcc1.g): 9186 files, 126172 used, 153819 free (4571 frags, 18656
blocks, 1.6% fragmentation)
/dev/wd0g (891d4cfcef7cbcc1.g): MARKING FILE SYSTEM CLEAN
/dev/wd0h (891d4cfcef7cbcc1.h): 5276 files, 53297 used, 899766 free (118 frags, 112456
blocks, 0.0% fragmentation)
/dev/wd0h (891d4cfcef7cbcc1.h): MARKING FILE SYSTEM CLEAN
/dev/wd0j (891d4cfcef7cbcc1.j): 2 files, 524425 used, 2171438 free (14 frags, 271428
blocks, 0.0% fragmentation)
/dev/wd0j (891d4cfcef7cbcc1.j): MARKING FILE SYSTEM CLEAN
/dev/wd0i (891d4cfcef7cbcc1.i): 1 files, 1 used, 713462 free (14 frags, 89181 blocks, 0.0%
fragmentation)
/dev/wd0i (891d4cfcef7cbcc1.i): MARKING FILE SYSTEM CLEAN
/dev/wd0e (891d4cfcef7cbcc1.e): 501 files, 31335 used, 387240 free (88 frags, 48394
blocks, 0.0% fragmentation)
/dev/wd0e (891d4cfcef7cbcc1.e): MARKING FILE SYSTEM CLEAN
pf enabled
starting network
add net 0.0.0.0/0: gateway 10.107.20.254
reordering libraries: done.
starting early daemons: syslogd pflogd ntpd.
starting RPC daemons:.
savecore: no core dump
checking quotas: done.
clearing /tmp
kern.securelevel: 0 -> 1
creating runtime link editor directory cache.
preserving editor files.
starting network daemons: sshd smtpd sndiod.
starting local daemons: cron.
Wed Apr  7 20:24:44 PDT 2021

----

Scrollback:

[  5] 550.00-551.01 sec  41.0 MBytes   342 Mbits/sec
[  5] 551.01-552.00 sec  40.0 MBytes   338 Mbits/sec
[  5] 552.00-553.00 sec  40.6 MBytes   341 Mbits/sec
[  5] 553.00-554.01 sec  40.7 MBytes   340 Mbits/sec
[  5] 554.01-555.00 sec  40.3 MBytes   339 Mbits/sec
[  5] 555.00-556.00 sec  40.6 MBytes   341 Mbits/sec
[  5] 556.00-557.00 sec  41.0 MBytes   344 Mbits/sec
panic: pool_do_get: mcl2k2 free list modified: page 0xfffffd80308e8000; item addr
0xfffffd80308ee6c0; offset 0x0=0x2e14627000851e2 != 0x131b283cee7e51e2
Stopped at      db_enter+0x10:  popq    %rbp
    TID    PID    UID     PRFLAGS     PFLAGS  CPU  COMMAND
db_enter() at db_enter+0x10
panic(ffffffff81e63d13) at panic+0x12a
pool_do_get(ffffffff82186c08,2,ffff800014e12ca4) at pool_do_get+0x321
pool_get(ffffffff82186c08,2) at pool_get+0x75
m_clget(0,2,802) at m_clget+0x18a
em_get_buf(ffff80000002ee00,f2) at em_get_buf+0x59
em_rxfill(ffff80000002ee00) at em_rxfill+0xc4
em_intr(ffff80000009c000) at em_intr+0xaa
intr_handler(ffff800014e12e90,ffff800000074280) at intr_handler+0x38
Xintr_ioapic_level16_untramp() at Xintr_ioapic_level16_untramp+0x1a3
Xspllower() at Xspllower+0x19
softintr_dispatch(0) at softintr_dispatch+0xc4
Xsoftclock() at Xsoftclock+0x1f
acpicpu_idle() at acpicpu_idle+0x25d
end trace frame: 0xffff800014e13110, count: 0
https://www.openbsd.org/ddb.html describes the minimum info required in bug
reports.  Insufficient info makes it difficult to find and fix bugs.
ddb> ps
   PID     TID   PPID    UID  S       FLAGS  WAIT          COMMAND
 15220  216128  79774      0  3        0x83  select        iperf3
 79774  401118  78090      0  3    0x10008b  pause         ksh
 78090  334892  63275      0  3        0x82  select        sshd
 80035  223623      1      0  3    0x100098  poll          cron
  7448  383767      1    110  3    0x100090  poll          sndiod
 67776  402027      1     99  3    0x100090  poll          sndiod
 34532  491704  52998     95  3    0x100092  kqread        smtpd
 25805  456398  52998    103  3    0x100092  kqread        smtpd
 94953  279979  52998     95  3    0x100092  kqread        smtpd
 75900   72327  52998     95  3    0x100092  kqread        smtpd
   525    2320  52998     95  3    0x100092  kqread        smtpd
 24155  480349  52998     95  3    0x100092  kqread        smtpd
 52998  134926      1      0  3    0x100080  kqread        smtpd
 63275  292624      1      0  3        0x80  select        sshd
 45721  215373      1      0  3    0x100080  poll          ntpd
 74593  426430  57619     83  3    0x100092  poll          ntpd
 57619  442923      1     83  3    0x100092  poll          ntpd
 62053  193710  18976     74  3    0x100092  bpf           pflogd
 18976  132414      1      0  3        0x80  netio         pflogd
 45540  370213  38999     73  3    0x100090  kqread        syslogd
 38999  119947      1      0  3    0x100082  netio         syslogd
 40523  382349  19856    115  3    0x100092  kqread        slaacd
 15649  313003  19856    115  3    0x100092  kqread        slaacd
 19856  154355      1      0  3    0x100080  kqread        slaacd
 99341  142700      0      0  3     0x14200  bored         smr
 60709  394946      0      0  3     0x14200  pgzero        zerothread
 75632  416007      0      0  3     0x14200  aiodoned      aiodoned
 76858  398479      0      0  3     0x14200  syncer        update
 98827  503027      0      0  3     0x14200  cleaner       cleaner
 10641  280519      0      0  3     0x14200  reaper        reaper
 76881   73775      0      0  3     0x14200  pgdaemon      pagedaemon
 57951  480893      0      0  3     0x14200  bored         crynlk
 49825  183771      0      0  3     0x14200  bored         crypto
 11173  279315      0      0  3     0x14200  usbtsk        usbtask
  8587  406910      0      0  3     0x14200  usbatsk       usbatsk
  8370  446960      0      0  3  0x40014200  acpi0         acpi0
 59659  307189      0      0  2     0x14200                softnet
 80651  258220      0      0  3     0x14200  bored         systqmp
 24726  343136      0      0  3     0x14200  bored         systq
 21646  421831      0      0  3  0x40014200  bored         softclock
*86057   50562      0      0  7  0x40014200                idle0
     1  289975      0      0  3        0x82  wait          init
     0       0     -1      0  3     0x10200  scheduler     swapper
ddb> show registers
rdi               0xffffffff820ba288    kprintf_mutex
rsi                              0x5
rbp               0xffff800014e12b40
rbx               0xffff800014e12b50
rdx                            0x3fd
rcx               0x4800000000001812
rax                              0x1
r8                0xffff800014e12b00
r9                                 0
r10               0xff2c77b6a77211dd
r11               0xcc76eb5cbe87dbfe
r12                     0x3000000008
r13               0xffff800014e12bf0
r14                            0x100
r15               0xffffffff81e63d13    cy_pio_rec+0x137e8
rip               0xffffffff81991370    db_enter+0x10
cs                               0x8
rflags                         0x282
rsp               0xffff800014e12b40
ss                              0x10
db_enter+0x10:  popq    %rbp