Re: 5.8-stable: panic: mtx_enter locking against myself

[mxb]

Looks like I found the root cause.
At least it is stable as it suppose to be.
In need to reproduce this in lab before making next move.

//mxb

> On 17 sep. 2015, at 10:35, mxb  wrote:
> 
> 
> Hey,
> getting panics with 5.8-STABLE kernel.
> 
> panic: mix_enter: locking against myself
> Starting stack trace…
> panic() at panic+0x10b
> mtx_enter() at mtx_enter+0x60
> sofree() at sofree+0xa0
> in_pcbdetach() at in_pcbdetach+0x40
> tcp_close() at tcp_close+0xad
> tcp_timer_2msl() at tcp_timer_2msl+0x90
> softclock() at softclock+0x315
> softintr_dispatch() at softintr_dispatch+0x8b
> Xsoftclock() at Xsoftclock+0x1f
> ——interrupt———
> (null)() at 0x8
> end of kernel
> end trace frame: 0x1120001, count: 247
> end of stack trace

Re: 5.8-stable: panic: mtx_enter locking against myself

[mxb]

It is from CVS.
dmesg below.

OpenBSD 5.8-stable (GENERIC.MP) #0: Tue Sep 15 22:38:07 CEST 2015
r...@fw1.home.unixconn.com:/usr/src/sys/arch/amd64/compile/GENERIC.MP
real mem = 17051418624 (16261MB)
avail mem = 16530747392 (15764MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: SMBIOS rev. 2.8 @ 0xed8a0 (122 entries)
bios0: vendor American Megatrends Inc. version "1.0b" date 01/06/2015
bios0: Supermicro X10DRT-PT
acpi0 at bios0: rev 2
acpi0: sleep states S0 S4 S5
acpi0: tables DSDT FACP APIC FPDT FIDT SPMI MCFG UEFI BDAT HPET MSCT PMCT SLIT 
SRAT WDDT SSDT SSDT SSDT PRAD DMAR HEST BERT ERST EINJ
acpi0: wakeup devices IP2P(S4) EHC1(S4) EHC2(S4) RP01(S4) RP02(S4) RP03(S4) 
RP04(S4) RP05(S4) RP06(S4) RP07(S4) RP08(S4) BR1A(S4) BR1B(S4) BR2A(S4) 
BR2B(S4) BR2C(S4) [...]
acpitimer0 at acpi0: 3579545 Hz, 24 bits
acpimadt0 at acpi0 addr 0xfee0: PC-AT compat
cpu0 at mainbus0: apid 0 (boot processor)
cpu0: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.45 MHz
cpu0: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu0: 256KB 64b/line 8-way L2 cache
cpu0: smt 0, core 0, package 0
mtrr: Pentium Pro MTRR support, 10 var ranges, 88 fixed ranges
cpu0: apic clock running at 100MHz
cpu0: mwait min=64, max=64, C-substates=0.2.1.2, IBE
cpu1 at mainbus0: apid 2 (application processor)
cpu1: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.01 MHz
cpu1: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu1: 256KB 64b/line 8-way L2 cache
cpu1: smt 0, core 1, package 0
cpu2 at mainbus0: apid 8 (application processor)
cpu2: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.01 MHz
cpu2: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu2: 256KB 64b/line 8-way L2 cache
cpu2: smt 0, core 4, package 0
cpu3 at mainbus0: apid 10 (application processor)
cpu3: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.00 MHz
cpu3: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu3: 256KB 64b/line 8-way L2 cache
cpu3: smt 0, core 5, package 0
cpu4 at mainbus0: apid 16 (application processor)
cpu4: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3495.42 MHz
cpu4: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu4: 256KB 64b/line 8-way L2 cache
cpu4: smt 0, core 0, package 1
cpu5 at mainbus0: apid 18 (application processor)
cpu5: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.00 MHz
cpu5: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu5: 256KB 64b/line 8-way L2 cache
cpu5: smt 0, core 1, package 1
cpu6 at mainbus0: apid 24 (application processor)
cpu6: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.00 MHz
cpu6: 
FPU,VME,DE,PSE,TSC,MSR,PAE,MCE,CX8,APIC,SEP,MTRR,PGE,MCA,CMOV,PAT,PSE36,CFLUSH,DS,ACPI,MMX,FXSR,SSE,SSE2,SS,HTT,TM,PBE,SSE3,PCLMUL,DTES64,MWAIT,DS-CPL,VMX,SMX,EST,TM2,SSSE3,FMA3,CX16,xTPR,PDCM,PCID,DCA,SSE4.1,SSE4.2,x2APIC,MOVBE,POPCNT,DEADLINE,AES,XSAVE,AVX,F16C,RDRAND,NXE,PAGE1GB,LONG,LAHF,ABM,PERF,ITSC,FSGSBASE,BMI1,AVX2,SMEP,BMI2,ERMS,INVPCID,SENSOR,ARAT
cpu6: 256KB 64b/line 8-way L2 cache
cpu6: smt 0, core 4, package 1
cpu7 at mainbus0: apid 26 (application processor)
cpu7: Intel(R) Xeon(R) CPU E5-2637 v3 @ 3.50GHz, 3500.00 MHz
cpu7: 

5.8-stable: panic: mtx_enter locking against myself

[mxb]

Hey,
getting panics with 5.8-STABLE kernel.

panic: mix_enter: locking against myself
Starting stack trace…
panic() at panic+0x10b
mtx_enter() at mtx_enter+0x60
sofree() at sofree+0xa0
in_pcbdetach() at in_pcbdetach+0x40
tcp_close() at tcp_close+0xad
tcp_timer_2msl() at tcp_timer_2msl+0x90
softclock() at softclock+0x315
softintr_dispatch() at softintr_dispatch+0x8b
Xsoftclock() at Xsoftclock+0x1f
——interrupt———
(null)() at 0x8
end of kernel
end trace frame: 0x1120001, count: 247
end of stack trace

Re: 5.8-stable: panic: mtx_enter locking against myself

[mxb]

and this is for a crash just 10min ago.

(gdb) file /var/crash/bsd.0
Reading symbols from /var/crash/bsd.0...(no debugging symbols found)...done.
(gdb) target kvm /var/crash/bsd.0.core
#0  0x8131cae4 in dumpsys ()
(gdb) where
#0  0x8131cae4 in dumpsys ()
#1  0x00030272 in ?? ()
#2  0x0005 in ?? ()
#3  0x8135e990 in sd_flush ()
Previous frame inner to this frame (corrupt stack?)


Any ideas?

> On 17 sep. 2015, at 10:35, mxb  wrote:
> 
> 
> Hey,
> getting panics with 5.8-STABLE kernel.
> 
> panic: mix_enter: locking against myself
> Starting stack trace…
> panic() at panic+0x10b
> mtx_enter() at mtx_enter+0x60
> sofree() at sofree+0xa0
> in_pcbdetach() at in_pcbdetach+0x40
> tcp_close() at tcp_close+0xad
> tcp_timer_2msl() at tcp_timer_2msl+0x90
> softclock() at softclock+0x315
> softintr_dispatch() at softintr_dispatch+0x8b
> Xsoftclock() at Xsoftclock+0x1f
> ——interrupt———
> (null)() at 0x8
> end of kernel
> end trace frame: 0x1120001, count: 247
> end of stack trace

Re: 5.8-stable: panic: mtx_enter locking against myself

[koko]

On Thu, 17 Sep 2015 10:35:46 +0200
mxb  wrote:

> getting panics with 5.8-STABLE kernel.
> 
5.8-STABLE not released yet. you mean 5.8-CURRENT?

Re: 5.8-stable: panic: mtx_enter locking against myself

[Stuart Henderson]

On 2015-09-17, mxb  wrote:
> Hey,
> getting panics with 5.8-STABLE kernel.
>
> panic: mix_enter: locking against myself
> Starting stack trace…
> panic() at panic+0x10b
> mtx_enter() at mtx_enter+0x60
> sofree() at sofree+0xa0
> in_pcbdetach() at in_pcbdetach+0x40
> tcp_close() at tcp_close+0xad
> tcp_timer_2msl() at tcp_timer_2msl+0x90
> softclock() at softclock+0x315
> softintr_dispatch() at softintr_dispatch+0x8b
> Xsoftclock() at Xsoftclock+0x1f
> ——interrupt———
> (null)() at 0x8
> end of kernel
> end trace frame: 0x1120001, count: 247
> end of stack trace
>
>

A bit more information about when this is happening might be useful..

Re: 5.8-stable: panic: mtx_enter locking against myself

[mxb]

Seems to happen very random.
I have two systems which do this. Both are 2-node CARP.
It is only kernel which is -STABLE on those two. Userland is from a snap 
approx. 14 days old.
Update to stable kernel is done recently, because of those crashes.
Kernel before is running OK on more heavily loaded machines.

Here is a trace from a crash just 50min ego.
I can’t do any thing directly in gdb (ddb.panic=1) as this is IPMI console and 
kbd not working.

(gdb) file /var/crash/bsd.0
Reading symbols from /var/crash/bsd.0...(no debugging symbols found)...done.
(gdb) target kvm /var/crash/bsd.0.core
#0  0x8131c7d4 in dumpsys ()
(gdb) where
#0  0x8131c7d4 in dumpsys ()
#1  0x00038000 in ?? ()
#2  0x0003024c in ?? ()
#3  0x0005 in ?? ()
#4  0x8135e680 in chopen ()
#5  0x8131c90b in dumpsys ()
#6  0x0021 in ?? ()
#7  0x80002127be68 in ?? ()
#8  0x81328434 in amd_cpu_cacheinfo ()
#9  0x81328340 in x86_print_cacheinfo ()
#10 0x80002127be68 in ?? ()
#11 0x811958d6 in srp_enter ()
#12 0x811958d6 in srp_enter ()
#13 0x811a4986 in addlog ()
#14 0x0038 in ?? ()
#15 0x80002127bf78 in ?? ()
#16 0x80002127be98 in ?? ()
#17 0x757ff7a94f468953 in ?? ()
#18 0x in ?? ()
(gdb)

[prdsrv0003.sto1.se]-[21:42:31]# ps -N /var/crash/bsd.0 -M 
/var/crash/bsd.0.core -O paddr
  PIDPADDR TT  STAT   TIME COMMAND
25250 ff0401574dc0 ??  Is+ 0:00.00 (ksh)
12560 ff0401574280 ??  Is+ 0:00.01 (getty)
30357 ff04015744c0 ??  Is+ 0:00.01 (getty)
12471 ff0401574700 ??  Is+ 0:00.01 (getty)
 8797 ff0401574940 ??  Is+ 0:00.01 (getty)
21030 ff0401574b80 ??  Is+ 0:00.01 (getty)

[prdsrv0003.sto1.se]-[21:45:12]# vmstat -N /var/crash/bsd.0 -M 
/var/crash/bsd.0.core -m
Memory statistics by bucket size
Size   In Use   Free   Requests  HighWater  Couldfree
  16 3320264  223931280  0
  32 1226 54   4254 640  0
  64 2992 80   6582 320  0
 12823616   1056  65855 160292
 256  339 29   4879  80  0
 512  284 12930  40  0
1024  318  6     20 36
2048   51   1027   1618  10757
4096   36  2442   5  0
8192   17  8 47   5  2
   163844  0  6   5  0
   327686  0  9   5  0
   655363  0543   5  0
  1310723  0  3   5  0
  2621441  0  1   5  0
  5242882  0  2   5  0

Memory usage type by bucket size
Size  Type(s)
  16  devbuf, pcb, routetbl, UFS mount, dirhash, ACPI, ip_moptions, exec,
  VM swap, UVM amap, UVM aobj, USB, USB device, temp
  32  devbuf, pcb, routetbl, ifaddr, UFS mount, sem, dirhash, ACPI,
  in_multi, exec, UVM amap, USB, USB device, temp
  64  devbuf, routetbl, ifaddr, vnodes, UFS mount, dirhash, ACPI, proc,
  in_multi, ether_multi, VM swap, UVM amap, USB, NDP, temp
 128  devbuf, pcb, routetbl, ifaddr, sem, dirhash, ACPI, NFS srvsock,
  ip_moptions, in_multi, ttys, pfkey data, UVM amap, USB, USB device,
  temp
 256  devbuf, routetbl, ifaddr, ioctlops, iov, vnodes, UFS mount, shm,
  VM map, ACPI, exec, xform_data, UVM amap, USB, USB device, NDP, temp
 512  devbuf, ifaddr, ioctlops, iov, UFS mount, dirhash, ACPI, file desc,
  ttys, xform_data, newblk, UVM amap, USB device, temp
1024  devbuf, pcb, ioctlops, iov, mount, shm, ACPI, file desc, proc, ttys,
  exec, UVM amap, USB device, crypto data, temp
2048  devbuf, pcb, ioctlops, UFS mount, ACPI, VM swap, UVM amap, UVM aobj,
  temp
4096  devbuf, pcb, ifaddr, ioctlops, UFS mount, proc, UVM amap, USB,
  memdesc, temp
8192  devbuf, pcb, ttys, pagedep, UVM amap, USB, temp
   16384  devbuf, pcb, NFS daemon, MSDOSFS mount, temp
   32768  devbuf, pcb, UFS quota, UFS mount, ISOFS mount, inodedep
   65536  devbuf, pcb, temp
  131072  devbuf, pcb
  262144  devbuf
  524288  VM swap

Memory statistics by type   Type  Kern
  Type InUse MemUse HighUse  Limit Requests Limit Limit Size(s)
devbuf  1326   838K   3078K 78644K 61420 0  
16,32,64,128,256,512,1024,2048,4096,8192,16384,32768,65536,131072,262144
   pcb   119   276K404K 78644K  1770 0  
16,32,128,1024,2048,4096,8192,16384,32768,65536,131072
  routetbl   23211K 12K 78644K  9990 0  16,32,64,128,256
ifaddr   11629K 29K