You are right, there were two interrupts. Here is the latest crash trace,
ps, show registers, and dmesg. (There was also another crash which just
died and never went to ddb.)
>> OpenBSD/i386 BOOT 3.26
boot>
booting hd0a:/bsd: 9698780+1068300 [72+408176+402760]=0xb0ac84
entry point at 0x200120
[ using 811420 bytes of bsd ELF symbol table ]
Copyright (c) 1982, 1986, 1989, 1991, 1993
The Regents of the University of California. All rights reserved.
Copyright (c) 1995-2015 OpenBSD. All rights reserved.
http://www.OpenBSD.org
OpenBSD 5.7-current (GENERIC) #753: Thu Mar 26 14:56:52 MDT 2015
t...@i386.openbsd.org:/usr/src/sys/arch/i386/compile/GENERIC
cpu0: Intel Pentium (P54C) ("GenuineIntel" 586-class) 91 MHz
cpu0: FPU,V86,DE,PSE,TSC,MSR,MCE,CX8
real mem = 150487040 (143MB)
avail mem = 135761920 (129MB)
mpath0 at root
scsibus0 at mpath0: 256 targets
mainbus0 at root
bios0 at mainbus0: date 04/07/97
apm0 at bios0: Power Management spec V1.1 (BIOS management disabled)
apm0: APM power management enable: unrecognized device ID (9)
pcibios at bios0 function 0x1a not configured
bios0: ROM list: 0xc0000/0x8000 0xc8000/0x2800!
cpu0 at mainbus0: (uniprocessor)
cpu0: F00F bug workaround installed
pci0 at mainbus0 bus 0: configuration mode 1 (bios)
0:0:0: mem address conflict 0xffffff0/0x10
0:0:0: io address conflict 0x10000e10/0x10
0:0:0: io address conflict 0x62000146/0x2
"Compaq Triflex PCI" rev 0x01 at pci0 dev 0 function 0 not configured
pcn0 at pci0 dev 11 function 0 "AMD 79c970 PCnet-PCI" rev 0x02, Am79c970,
rev 1:
irq 11, address 00:80:5f:d8:8b:a0
pcscp0 at pci0 dev 12 function 0 "AMD 53c974 PCscsi-PCI" rev 0x02: irq 15
pcscp0: AM53C974, 40MHz
scsibus1 at pcscp0: 8 targets, initiator 7
vga1 at pci0 dev 13 function 0 "Matrox MGA Millenium 2064W" rev 0x01
wsdisplay0 at vga1 mux 1: console (80x25, vt100 emulation)
wsdisplay0: screen 1-5 added (80x25, vt100 emulation)
malo0 at pci0 dev 14 function 0 "Marvell Libertas 88W8335" rev 0x03: irq 7,
addr
ess 00:1e:2a:46:ac:e3
"Compaq EISA" rev 0x03 at pci0 dev 15 function 0 not configured
eisa0 at mainbus0
ep1 at eisa0 slot 2: 3Com 3C509-TP Ethernet, irq 5, address
00:a0:24:4b:e1:14, u
tp/aui (default utp)
eisa0: can't map i/o space for slot 7
isa0 at mainbus0
isadma0 at isa0
fdc0 at isa0 port 0x3f0/6 irq 6 drq 2
fd0 at fdc0 drive 0: 1.44MB 80 cyl, 2 head, 18 sec
com0 at isa0 port 0x3f8/8 irq 4: ns16550a, 16 byte fifo
com0: console
com1 at isa0 port 0x2f8/8 irq 3: ns16550a, 16 byte fifo
com1: probed fifo depth: 0 bytes
pckbc0 at isa0 port 0x60/5
pckbd0 at pckbc0 (kbd slot)
pckbc0: using irq 1 for kbd slot
wskbd0 at pckbd0: console keyboard, using wsdisplay0
pms0 at pckbc0 (aux slot)
pckbc0: using irq 12 for aux slot
wsmouse0 at pms0 mux 0
wdc0 at isa0 port 0x1f0/8 irq 14
wd0 at wdc0 channel 0 drive 0: <Maxtor 91152D8>
wd0: 16-sector PIO, LBA, 10991MB, 22510656 sectors
atapiscsi0 at wdc0 channel 0 drive 1
scsibus2 at atapiscsi0: 2 targets
cd0 at scsibus2 targ 0 lun 0: <MITSUMI, CD-ROM FX140S !B, e12> ATAPI
5/cdrom rem
ovable
wd0(wdc0:0:0): using BIOS timings
cd0(wdc0:0:1): using BIOS timings
pcppi0 at isa0 port 0x61
spkr0 at pcppi0
npx0 at isa0 port 0xf0/16: reported by CPUID; using exception 16
vscsi0 at root
scsibus3 at vscsi0: 256 targets
softraid0 at root
scsibus4 at softraid0: 256 targets
root on wd0a (061ee26df5e9f130.a) swap on wd0b dump on wd0b
WARNING: / was not properly unmounted
Automatic boot in progress: starting file system checks.
/dev/wd0a (061ee26df5e9f130.a): 2429 files, 36216 used, 98695 free (159
frags, 1
2317 blocks, 0.1% fragmentation)
/dev/wd0a (061ee26df5e9f130.a): MARKING FILE SYSTEM CLEAN
/dev/wd0k (061ee26df5e9f130.k): 6066 files, 291052 used, 1071467 free (331
frags
, 133892 blocks, 0.0% fragmentation)
/dev/wd0k (061ee26df5e9f130.k): MARKING FILE SYSTEM CLEAN
/dev/wd0d (061ee26df5e9f130.d): 6 files, 5 used, 212722 free (34 frags,
26586 bl
ocks, 0.0% fragmentation)
/dev/wd0d (061ee26df5e9f130.d): MARKING FILE SYSTEM CLEAN
/dev/wd0f (061ee26df5e9f130.f): 13269 files, 187820 used, 359851 free (4963
frag
s, 44361 blocks, 0.9% fragmentation)
/dev/wd0f (061ee26df5e9f130.f): MARKING FILE SYSTEM CLEAN
/dev/wd0g (061ee26df5e9f130.g): 9200 files, 89526 used, 224321 free (7073
frags,
27156 blocks, 2.3% fragmentation)
/dev/wd0g (061ee26df5e9f130.g): MARKING FILE SYSTEM CLEAN
/dev/wd0h (061ee26df5e9f130.h): 9592 files, 110008 used, 1112319 free (111
frags
, 139026 blocks, 0.0% fragmentation)
/dev/wd0h (061ee26df5e9f130.h): MARKING FILE SYSTEM CLEAN
/dev/wd0j (061ee26df5e9f130.j): 50 files, 683092 used, 46755 free (27
frags, 584
1 blocks, 0.0% fragmentation)
/dev/wd0j (061ee26df5e9f130.j): MARKING FILE SYSTEM CLEAN
/dev/wd0i (061ee26df5e9f130.i): 1 files, 1 used, 553126 free (14 frags,
69139 bl
ocks, 0.0% fragmentation)
/dev/wd0i (061ee26df5e9f130.i): MARKING FILE SYSTEM CLEAN
/dev/wd0e (061ee26df5e9f130.e): FREE BLK COUNT(S) WRONG IN SUPERBLK
(SALVAGED)
/dev/wd0e (061ee26df5e9f130.e): SUMMARY INFORMATION BAD (SALVAGED)
/dev/wd0e (061ee26df5e9f130.e): BLK(S) MISSING IN BIT MAPS (SALVAGED)
/dev/wd0e (061ee26df5e9f130.e): 658 files, 203557 used, 83066 free (186
frags, 1
0360 blocks, 0.1% fragmentation)
/dev/wd0e (061ee26df5e9f130.e): MARKING FILE SYSTEM CLEAN
setting tty flags
pf enabled
machdep.allowaperture: 0 -> 2
net.inet.ip.forwarding: 0 -> 1
starting network
malo0: timeout while waiting for cmd response!
malo0: setting long slot failed
starting early daemons: syslogd pflogd.
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 dhcpd smtpd sndiod.
wsdisplay0: screen 5 deleted
wsdisplay0: screen 5 added (80x50, vt100 emulation)
starting local daemons: cron wsmoused.
Mon Mar 30 07:14:51 CDT 2015
OpenBSD/i386 (strait.middle-earth.lan) (tty00)
login: ppp0: got 28 bytes
ff03c02101020018010405ea0206ffffffff0506e737b6ad07020802
ppp0 output: ff03c0210101000e05061a19995d07020802
ppp0 output: ff03c02102020018010405ea0206ffffffff0506e737b6ad07020802
ppp0: got 18 bytes
ff03c0210201000e05061a19995d07020802
ppp0 output: ff03c021090000081a19995d
ppp0: got 20 bytes
ff038021010300100206002d0f000306a55b4040
ppp0 output: ff038021010100100306000000000206002d0f01
ppp0: got 12 bytes
ff03c0210a000008e737b6ad
[lines deleted]
ppp0: got 142 bytes
ff03002d3f1ac5003d8e643d75b60519d280c441bc7afd1ee2c98d561e4a3ab94fc25356e479cb86
27d6086bfe652f42d1eedc0df4b67ef949b439f49569a46d8112e3dc31b3b369a5506c865a379baf
01780c924dc896ae6f5655edcf68a24564bc2b09a91d27ddb1bbb23f60697170440f0c695c1a7fda
865f9d899409dafff49c728d7b120769f1e2f65847c6
ppp0 output:
ff0300214510003427f640004006216aa55b410380c28a3362880016f92af95637c
a9dfe80100f7d3f2e00000101080ab189ec016f8afebe
ppp0: got 1504 bytes
ff03002f450005dc564840003800f57f80c28a33a55b41030016628837ca9dfef92af9568010c050
12d500000101080a6f8aff12b189ebf85c3ff2f0ed02f60ea00ba83e582528245f1eee2a0c6a65db
a124f4825a175a11e3b138ce98c0bf39d73bbbfe9e87271bd569c4811d3b5d8a410de175d4c21d5d
ad2118e4c5cbfadca755a1587c2ede496fd3ddc769f0096cb8837be12f66502dc82647bd8171b835
9553a4a01c82568898fdd9f5dbb9a06e45d1aa6d790c98bbc9bfcef5d79907e991>
ppp0 output:
ff030021451000342af5400040061e6ba55b410380c28a3362880016f92af95637c
aa3a680101043386b00000101080ab189ec026f8aff12
ppp0: got 1504 bytes
ff03002f450005dcdafd4000380070ca80c28a33a55b41030016628837caa3a6f92af9568010c050
095100000101080a6f8aff66b189ebf9d88ea63afc93626a88dcf45be42d429f698a9f3dae982f74
b9b459ec95710c1fad04c73e4516412d3499057c66b5b1ec7d8f3ce9f8f29c2da01d86fbe533fbeb
0cd5a629d9a3e426dc77d5c7ea685a454e400b59a3b778f35f3aaf650343198ad2ab23769defd50b
b100d81183675533f0b3700229f319ac741fc09fffe8b35c3593e5037f7f1b1041>
ppp0: got 610 bytes
ff03002d3f90f500efa4bc945ab7715cb8e588dc86eccfcd351444c2e2598d8121c95bcf09284317
0d61f319ed4f7b631133e552421c9cd4e2f0bb4318785dd1122bf59634f0ce07428d9a7d6d865b14
edcb2592e6bbfb9d69cefdc9c93fe583bd1a14a8ee437c342f1b4739941e0237aac6ca5bc4eb5d0a
ed9a6a103df7dcb5a8d025a3721399d0b090eeb2efb204d58f4ec93eba5a6d41886dd6adba2b08a6
93f73106c588ec8072ca3817f4f3bec130ee08992a75638e0ffcc4108fb4eb063b>
ppp0 output:
ff0300214510003427bf4000400621a1a55b410380c28a3362880016f92af95637c
aaba680100ff8306200000101080ab189ec026f8aff66
panic: mtx_enter: locking against myself
Stopped at Debugger+0x7: leave
RUN AT LEAST 'trace' AND 'ps' AND INCLUDE OUTPUT WHEN REPORTING THIS PANIC!
DO NOT EVEN BOTHER REPORTING THIS WITHOUT INCLUDING THAT INFORMATION!
ddb> trace
Debugger(d09d172a,f2132b6c,d0202f50,f2132b6c,d03ca9c4) at Debugger+0x7
panic(d0202f50,f2132bcc,d03c9e9f,d0b8bd20,2) at panic+0x71
mtx_enter(d0b8bd20,2,f2132bb8,f2132bb0,d042d62a) at mtx_enter+0x60
pool_get(d0b8bd20,2,40,8862,d09d0720) at pool_get+0x2f
m_clget(f21b5100,2,0,800,d0bb10e8) at m_clget+0x41
pppgetm(d11b8000,f21b5f00,0,3,0) at pppgetm+0xae
pppinput(7e,d116a600,2f8,2,d112f054) at pppinput+0x5a9
comsoft(d112f000,d356de00,d1108ac0,d0b8bc40,f2132db0) at comsoft+0x13d
softintr_dispatch(2) at softintr_dispatch+0x5a
Xsofttty() at Xsofttty+0x12
--- interrupt ---
poison_check(d11bc008,7f8,f2132d80,f2132d7c,d0203025) at poison_check+0x3b
pool_do_get(d0b8bd20,2,f2132de0,d041a60d,d09d0720) at pool_do_get+0x1e7
pool_get(d0b8bd20,2,f2132e34,f2132e14,d0203025) at pool_get+0x96
m_clget(0,2,0,800,d041bc60) at m_clget+0x41
epmbuffill(d1123000,d0bb10dc,f2132e94,d042cb45,40) at epmbuffill+0x66
softclock(0,d0821a1e,d0bb10cc,d1108e00,20000000) at softclock+0x225
softintr_dispatch(0) at softintr_dispatch+0x5a
Xsoftclock() at Xsoftclock+0x12
--- interrupt ---
apm_cpu_idle(d03b20eb,d0b8785c,d0c42360,0,0) at apm_cpu_idle+0xa6
cpu_idle_cycle(d0c42360) at cpu_idle_cycle+0xc
Bad frame pointer: 0xd0d0ce58
ddb> ps
PID PPID PGRP UID S FLAGS WAIT COMMAND
32359 5417 32359 0 2 0x83 ssh
28103 1 28103 0 3 0x80 poll ntpd
17467 32317 17467 83 3 0x90 poll ntpd
32317 1 32317 83 3 0x90 poll ntpd
4376 15160 4376 1000 3 0x83 ttyin ksh
15160 12099 12099 1000 2 0x90 sshd
12099 1141 12099 0 3 0x82 poll sshd
12738 1 12738 0 3 0xb0 select pppd
5417 5655 5417 0 3 0x8b pause ksh
5655 31933 31933 1000 3 0x90 select sshd
31933 1141 31933 0 3 0x82 poll sshd
6665 1 6665 0 3 0x83 ttyin getty
26489 1 26489 0 3 0x83 ttyin getty
7662 1 7662 0 3 0x83 ttyin getty
17994 1 17994 0 3 0x83 ttyin getty
30355 1 30355 0 3 0x83 ttyin getty
4279 1 4279 0 3 0x83 ttyin getty
21042 1 21042 0 3 0x80 poll wsmoused
19838 1 19838 0 3 0x80 poll cron
27140 1 27140 99 3 0x90 poll sndiod
27564 14864 14864 95 3 0x90 kqread smtpd
27367 14864 14864 95 3 0x90 kqread smtpd
6435 14864 14864 95 3 0x90 kqread smtpd
7814 14864 14864 95 3 0x90 kqread smtpd
4845 14864 14864 95 3 0x90 kqread smtpd
9600 14864 14864 103 3 0x90 kqread smtpd
14864 1 14864 0 3 0x80 kqread smtpd
26814 1 26814 77 3 0x90 poll dhcpd
1141 1 1141 0 3 0x80 select sshd
11212 8748 8748 74 2 0x490 pflogd
8748 1 8748 0 3 0x80 netio pflogd
1081 580 580 73 2 0x90 syslogd
580 1 580 0 3 0x80 netio syslogd
8278 0 0 0 3 0x14200 pgzero zerothread
19813 0 0 0 3 0x14200 aiodoned aiodoned
1973 0 0 0 3 0x14200 syncer update
4350 0 0 0 3 0x14200 cleaner cleaner
1181 0 0 0 3 0x14200 reaper reaper
30902 0 0 0 3 0x14200 pgdaemon pagedaemon
23675 0 0 0 3 0x14200 bored crypto
24446 0 0 0 3 0x14200 pftm pfpurge
2910 0 0 0 3 0x14200 apmev apm0
4473 0 0 0 3 0x14200 bored systqmp
16840 0 0 0 3 0x14200 bored systq
*29867 0 0 0 7 0x40014200 idle0
7279 0 0 0 3 0x14200 kmalloc kmthread
1 0 1 0 3 0x82 wait init
0 -1 0 0 3 0x10200 scheduler swapper
ddb> show registers
ds 0x10
es 0x10
fs 0x20
gs 0
edi 0x100
esi 0xd0202f50 mtx_enter+0x60
ebp 0xf2132b20
ebx 0xf2132b6c
edx 0x1
ecx 0xd0b212cc kprintf_mutex
eax 0x1
eip 0xd055a3b7 Debugger+0x7
cs 0x50
eflags 0x200282
esp 0xf2132b10
ss 0x10
Debugger+0x7: leave
ddb>
---------- Forwarded message ----------
From: Philip Guenther <pguent...@proofpoint.com>
Date: Mon, Mar 30, 2015 at 12:24 AM
Subject: Re: OpenBSD 5.6 Kernel panic - panic: mtx_enter: locking against
myself
To: Walter Daugherity <wdaugher...@gmail.com>
Cc: bugs@openbsd.org
On Sun, 29 Mar 2015, Walter Daugherity wrote:
> No, 5.7-current snapshot still does not fix this bug. I have tried
> 2015-Mar-18 and 2015-Mar-26 snapshots, and both still crash under
> network logging load (e.g., with pppd kdebug and debug enabled, log on
> to a remote computer and run the "top" command and the system crashes).
Since you've updated across a significant change in the involved code,
please provide a trace from a panic with the updated build. (The trace
has certainly changed, as pool_do_put() doesn't exist anymore, so the
problem code path involved in the panic has changed.)
...
> The problem may be in syslogd or in the file system, <...>
No, it absolutely cannot be a bug in syslogd, and from the trace is not a
bug in the file system, but rather--as kettenis@ explained--the failure to
block interrupts as necessary in some critical section.
Philip Guenther
--
--
Walter C. Daugherity Dept. of Computer Science & Engineering
E-mail: daug...@neo.tamu.edu Texas A & M University
http://faculty.cs.tamu.edu/daugher College Station, TX 77843-3112
---Not an official document of Texas A&M---
