[SOLVED] Frequent kernel panics

[Nacho]

Hi there,

After updating to 16.7.5 I've been experiencing frequent kernel panics, trying to run update from the WebUI will trigger is as well as running option 12 from the console.
when running Squid, trying to use the proxy from a machine behind the firewall will also trigger a kernel panic.

After a kernel panic the machine reboots.

The machine is a VM on ESX6.0 on a machine with hyperthreading enabled.

some information from the reporter:

System information

Code: [Select]

FreeBSD 10.3-RELEASE-p9 #0 8d514f5(stable/16.7): Mon Sep 26 03:46:17 CEST 2016     root@sensey64:/usr/obj/usr/src/sys/SMP
OPNsense 16.7.5-b3d01d5f7 [16.7.4-e7aaafea8] OpenSSL 1.0.2j  26 Sep 2016 (amd64)
UUID 564d5f75-234e-c19c-77a5-a6ce12b930d2
Time Wed, 09 Nov 2016 10:41:48 +0100
User Agent Mozilla/5.0 (Macintosh; Intel Mac OS X 10_11_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/54.0.2840.71 Safari/537.36

dmesg.boot

Code: [Select]

TSC: P-state invariant
Hypervisor: Origin = "VMwareVMware"
real memory  = 1073741824 (1024 MB)
avail memory = 1000103936 (953 MB)
Event timer "LAPIC" quality 600
ACPI APIC Table:
random:  initialized
MADT: Forcing active-low polarity and level trigger for SCI
ioapic0  irqs 0-23 on motherboard
wlan: mac acl policy registered
kbd1 at kbdmux0
netmap: loaded module
cryptosoft0:  on motherboard
acpi0:  on motherboard
acpi0: Power Button (fixed)
Timecounter "HPET" frequency 14318180 Hz quality 950
cpu0:  on acpi0
attimer0:  port 0x40-0x43 irq 0 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
atrtc0:  port 0x70-0x71 irq 8 on acpi0
Event timer "RTC" frequency 32768 Hz quality 0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
pcib0:  port 0xcf8-0xcff on acpi0
pci0:  on pcib0
pcib1:  at device 1.0 on pci0
pci1:  on pcib1
isab0:  at device 7.0 on pci0
isa0:  on isab0
atapci0:  port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x1060-0x106f at device 7.1 on pci0
ata0:  at channel 0 on atapci0
ata1:  at channel 1 on atapci0
pci0:  at device 7.3 (no driver attached)
vgapci0:  port 0x1070-0x107f mem 0xe8000000-0xefffffff,0xfe000000-0xfe7fffff irq 16 at device 15.0 on pci0
vgapci0: Boot video device
mpt0:  port 0x1400-0x14ff mem 0xfeba0000-0xfebbffff,0xfebc0000-0xfebdffff irq 17 at device 16.0 on pci0
mpt0: MPI Version=1.2.0.0
pcib2:  at device 17.0 on pci0
pci2:  on pcib2
em0:  port 0x2000-0x203f mem 0xfd5c0000-0xfd5dffff,0xfdff0000-0xfdffffff irq 18 at device 0.0 on pci2
em0: Ethernet address: 00:0c:29:b9:30:d2
em0: netmap queues/slots: TX 1/256, RX 1/256
em1:  port 0x2040-0x207f mem 0xfd5a0000-0xfd5bffff,0xfdfe0000-0xfdfeffff irq 19 at device 1.0 on pci2
em1: Ethernet address: 00:50:56:00:2e:af
em1: netmap queues/slots: TX 1/256, RX 1/256
pcib3:  at device 21.0 on pci0
pci3:  on pcib3
pcib4:  at device 21.1 on pci0
pci4:  on pcib4
pcib5:  at device 21.2 on pci0
pci5:  on pcib5
pcib6:  at device 21.3 on pci0
pci6:  on pcib6
pcib7:  at device 21.4 on pci0
pci7:  on pcib7
pcib8:  at device 21.5 on pci0
pci8:  on pcib8
pcib9:  at device 21.6 on pci0
pci9:  on pcib9
pcib10:  at device 21.7 on pci0
pci10:  on pcib10
pcib11:  at device 22.0 on pci0
pci11:  on pcib11
pcib12:  at device 22.1 on pci0
pci12:  on pcib12
pcib13:  at device 22.2 on pci0
pci13:  on pcib13
pcib14:  at device 22.3 on pci0
pci14:  on pcib14
pcib15:  at device 22.4 on pci0
pci15:  on pcib15
pcib16:  at device 22.5 on pci0
pci16:  on pcib16
pcib17:  at device 22.6 on pci0
pci17:  on pcib17
pcib18:  at device 22.7 on pci0
pci18:  on pcib18
pcib19:  at device 23.0 on pci0
pci19:  on pcib19
pcib20:  at device 23.1 on pci0
pci20:  on pcib20
pcib21:  at device 23.2 on pci0
pci21:  on pcib21
pcib22:  at device 23.3 on pci0
pci22:  on pcib22
pcib23:  at device 23.4 on pci0
pci23:  on pcib23
pcib24:  at device 23.5 on pci0
pci24:  on pcib24
pcib25:  at device 23.6 on pci0
pci25:  on pcib25
pcib26:  at device 23.7 on pci0
pci26:  on pcib26
pcib27:  at device 24.0 on pci0
pci27:  on pcib27
pcib28:  at device 24.1 on pci0
pci28:  on pcib28
pcib29:  at device 24.2 on pci0
pci29:  on pcib29
pcib30:  at device 24.3 on pci0
pci30:  on pcib30
pcib31:  at device 24.4 on pci0
pci31:  on pcib31
pcib32:  at device 24.5 on pci0
pci32:  on pcib32
pcib33:  at device 24.6 on pci0
pci33:  on pcib33
pcib34:  at device 24.7 on pci0
pci34:  on pcib34
acpi_acad0:  on acpi0
atkbdc0:  port 0x60,0x64 irq 1 on acpi0
atkbd0:  irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0:  irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model IntelliMouse, device ID 3
fdc0:  port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
orm0:  at iomem 0xc0000-0xc7fff,0xc8000-0xc9fff,0xca000-0xcafff,0xcb000-0xcbfff,0xdc000-0xdffff,0xe0000-0xe7fff on isa0
sc0:  at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0:  at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
ppc0: cannot reserve I/O port range
Timecounters tick every 1.000 msec
IPsec: Initialized Security Association Processing.
em0: link state changed to UP
em1: link state changed to UP
random: unblocking device.
da0 at mpt0 bus 0 scbus2 target 0 lun 0
da0:  Fixed Direct Access SCSI-2 device
da0: 320.000MB/s transfers (160.000MHz, offset 127, 16bit)
da0: Command Queueing enabled
da0: 40960MB (83886080 512 byte sectors)
da0: quirks=0x40
cd0 at ata1 bus 0 scbus1 target 0 lun 0
cd0:  Removable CD-ROM SCSI device
cd0: Serial Number 10000000000000000001
cd0: 33.300MB/s transfers (UDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present
cd0: quirks=0x40
Timecounter "TSC-low" frequency 1750012000 Hz quality 1000
Trying to mount root from ufs:/dev/da0s1a [rw]...
WARNING: /mnt was not properly dismounted
WARNING: attempt to domain_add(netgraph) after domainfinalize()
tun1: changing name to 'ovpns1'
ifa_add_loopback_route: insertion failed: 17
ovpns1: link state changed to UP
pflog0: promiscuous mode enabled


Fatal trap 12: page fault while in kernel mode
cpuid = 0; apic id = 00
fault virtual address = 0x0
fault code = supervisor read data, page not present
instruction pointer = 0x20:0xffffffff80c64c6c
stack pointer         = 0x28:0xfffffe003ccaf5c0
frame pointer         = 0x28:0xfffffe003ccaf7a0
code segment = base 0x0, limit 0xfffff, type 0x1b
= DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 0 (em1 taskq)
Copyright (c) 1992-2016 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
The Regents of the University of California. All rights reserved.
FreeBSD is a registered trademark of The FreeBSD Foundation.
FreeBSD 10.3-RELEASE-p9 #0 8d514f5(stable/16.7): Mon Sep 26 03:46:17 CEST 2016
    root@sensey64:/usr/obj/usr/src/sys/SMP amd64
FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512
[HBSD ASLR] status: opt-out
[HBSD ASLR] mmap: 30 bit
[HBSD ASLR] exec base: 30 bit
[HBSD ASLR] stack: 42 bit
[HBSD ASLR] vdso: 28 bit
[HBSD ASLR] map32bit: 18 bit
[HBSD ASLR] disallow MAP_32BIT mode mmap: opt-in
[HBSD ASLR (compat)] status: opt-out
[HBSD ASLR (compat)] mmap: 14 bit
[HBSD ASLR (compat)] exec base: 14 bit
[HBSD ASLR (compat)] stack: 14 bit
[HBSD ASLR (compat)] vdso: 8 bit
[HBSD LOG] logging to system: enabled
[HBSD LOG] logging to user: disabled
CPU: Intel(R) Xeon(R) CPU E3-1275 V2 @ 3.50GHz (3500.02-MHz K8-class CPU)
  Origin="GenuineIntel"  Id=0x306a9  Family=0x6  Model=0x3a  Stepping=9
  Features=0xfa3fbff
  Features2=0xffba2203
  AMD Features=0x28100800
  AMD Features2=0x1
  Structured Extended Features=0x202
  TSC: P-state invariant
Hypervisor: Origin = "VMwareVMware"
real memory  = 1073741824 (1024 MB)
avail memory = 1000103936 (953 MB)
Event timer "LAPIC" quality 600
ACPI APIC Table:
random:  initialized
MADT: Forcing active-low polarity and level trigger for SCI
ioapic0  irqs 0-23 on motherboard
wlan: mac acl policy registered
kbd1 at kbdmux0
netmap: loaded module
cryptosoft0:  on motherboard
acpi0:  on motherboard
acpi0: Power Button (fixed)
Timecounter "HPET" frequency 14318180 Hz quality 950
cpu0:  on acpi0
attimer0:  port 0x40-0x43 irq 0 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
atrtc0:  port 0x70-0x71 irq 8 on acpi0
Event timer "RTC" frequency 32768 Hz quality 0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 900
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x1008-0x100b on acpi0
pcib0:  port 0xcf8-0xcff on acpi0
pci0:  on pcib0
pcib1:  at device 1.0 on pci0
pci1:  on pcib1
isab0:  at device 7.0 on pci0
isa0:  on isab0
atapci0:  port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0x1060-0x106f at device 7.1 on pci0
ata0:  at channel 0 on atapci0
ata1:  at channel 1 on atapci0
pci0:  at device 7.3 (no driver attached)
vgapci0:  port 0x1070-0x107f mem 0xe8000000-0xefffffff,0xfe000000-0xfe7fffff irq 16 at device 15.0 on pci0
vgapci0: Boot video device
mpt0:  port 0x1400-0x14ff mem 0xfeba0000-0xfebbffff,0xfebc0000-0xfebdffff irq 17 at device 16.0 on pci0
mpt0: MPI Version=1.2.0.0
pcib2:  at device 17.0 on pci0
pci2:  on pcib2
em0:  port 0x2000-0x203f mem 0xfd5c0000-0xfd5dffff,0xfdff0000-0xfdffffff irq 18 at device 0.0 on pci2
em0: Ethernet address: 00:0c:29:b9:30:d2
em0: netmap queues/slots: TX 1/256, RX 1/256
em1:  port 0x2040-0x207f mem 0xfd5a0000-0xfd5bffff,0xfdfe0000-0xfdfeffff irq 19 at device 1.0 on pci2
em1: Ethernet address: 00:50:56:00:2e:af
em1: netmap queues/slots: TX 1/256, RX 1/256
pcib3:  at device 21.0 on pci0
pci3:  on pcib3
pcib4:  at device 21.1 on pci0
pci4:  on pcib4
pcib5:  at device 21.2 on pci0
pci5:  on pcib5
pcib6:  at device 21.3 on pci0
pci6:  on pcib6
pcib7:  at device 21.4 on pci0
pci7:  on pcib7
pcib8:  at device 21.5 on pci0
pci8:  on pcib8
pcib9:  at device 21.6 on pci0
pci9:  on pcib9
pcib10:  at device 21.7 on pci0
pci10:  on pcib10
pcib11:  at device 22.0 on pci0
pci11:  on pcib11
pcib12:  at device 22.1 on pci0
pci12:  on pcib12
pcib13:  at device 22.2 on pci0
pci13:  on pcib13
pcib14:  at device 22.3 on pci0
pci14:  on pcib14
pcib15:  at device 22.4 on pci0
pci15:  on pcib15
pcib16:  at device 22.5 on pci0
pci16:  on pcib16
pcib17:  at device 22.6 on pci0
pci17:  on pcib17
pcib18:  at device 22.7 on pci0
pci18:  on pcib18
pcib19:  at device 23.0 on pci0
pci19:  on pcib19
pcib20:  at device 23.1 on pci0
pci20:  on pcib20
pcib21:  at device 23.2 on pci0
pci21:  on pcib21
pcib22:  at device 23.3 on pci0
pci22:  on pcib22
pcib23:  at device 23.4 on pci0
pci23:  on pcib23
pcib24:  at device 23.5 on pci0
pci24:  on pcib24
pcib25:  at device 23.6 on pci0
pci25:  on pcib25
pcib26:  at device 23.7 on pci0
pci26:  on pcib26
pcib27:  at device 24.0 on pci0
pci27:  on pcib27
pcib28:  at device 24.1 on pci0
pci28:  on pcib28
pcib29:  at device 24.2 on pci0
pci29:  on pcib29
pcib30:  at device 24.3 on pci0
pci30:  on pcib30
pcib31:  at device 24.4 on pci0
pci31:  on pcib31
pcib32:  at device 24.5 on pci0
pci32:  on pcib32
pcib33:  at device 24.6 on pci0
pci33:  on pcib33
pcib34:  at device 24.7 on pci0
pci34:  on pcib34
acpi_acad0:  on acpi0
atkbdc0:  port 0x60,0x64 irq 1 on acpi0
atkbd0:  irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0:  irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model IntelliMouse, device ID 3
fdc0:  port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
orm0:  at iomem 0xc0000-0xc7fff,0xc8000-0xc9fff,0xca000-0xcafff,0xcb000-0xcbfff,0xdc000-0xdffff,0xe0000-0xe7fff on isa0
sc0:  at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0:  at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
ppc0: cannot reserve I/O port range
Timecounters tick every 1.000 msec
IPsec: Initialized Security Association Processing.
em0: link state changed to UP
em1: link state changed to UP
random: unblocking device.
da0 at mpt0 bus 0 scbus2 target 0 lun 0
da0:  Fixed Direct Access SCSI-2 device
da0: 320.000MB/s transfers (160.000MHz, offset 127, 16bit)
da0: Command Queueing enabled
da0: 40960MB (83886080 512 byte sectors)
da0: quirks=0x40
cd0 at ata1 bus 0 scbus1 target 0 lun 0
cd0:  Removable CD-ROM SCSI device
cd0: Serial Number 10000000000000000001
cd0: 33.300MB/s transfers (UDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present
cd0: quirks=0x40
Timecounter "TSC-low" frequency 1750012000 Hz quality 1000
Trying to mount root from ufs:/dev/da0s1a [rw]...
WARNING: /mnt was not properly dismounted
WARNING: /mnt: mount pending error: blocks 8 files 0
WARNING: /mnt: reload pending error: blocks 8 files 0
WARNING: attempt to domain_add(netgraph) after domainfinalize()
tun1: changing name to 'ovpns1'
ifa_add_loopback_route: insertion failed: 17
ovpns1: link state changed to UP
pflog0: promiscuous mode enabled

I'm happy to provide more information when needed.

I've sent reports using the reporter over the last couple of months but haven't had any response so far.
I'm kinda stuck now with a highly instable machine. Any help would be greatly appreciated.

[franco]

Hi there,

Can you let us know which email address you submitted these under? We get a lot of kernel dumps without emails and descriptions which we can't do much about them because we cannot contact the submitters.

You should try the following. From the console, reapply the kernel and reboot:

# opnsense-update -fk
# /usr/local/etc/rc.reboot

If that doesn't help, try installing the "os-intel-em" plugin and reboot.

Just to make sure we're not dealing with a faulty kernel on the disk or any known issues with the em(4) driver.


Thanks,
Franco

[Nacho]

Hi Franco,

Thanks for your answer. I'll give your suggestions a go.

The email address I used was taco _at_ scheltema _dot_ org

Cheers,
Taco

[Nacho]

Well... I tried to reapply the kernel which resulted in another crash and reboot.
I tried running opnsense-update which resulted in the same, I did see this before it crashed;

Code: [Select]

# opnsense-update
Updating OPNsense repository catalogue...
Repository OPNsense has a wrong packagesite, need to re-create database

[franco]

Thanks, I will check the archive.

Hmm, system is really unstable. There's no reason it should panic from that command per se. Can you submit this report, too?

Also, this updated the package database, but you need to run with options "-kf" as this triggers a forced kernel reinstall, otherwise the kernel is left as is.


Cheers,
Franco

[franco]

I found one

Fatal trap 12: page fault while in kernel mode
cpuid = 0; apic id = 00
fault virtual address   = 0x0
fault code      = supervisor read data, page not present
instruction pointer   = 0x20:0xffffffff80c64c6c
stack pointer           = 0x28:0xfffffe003ccaf5c0
frame pointer           = 0x28:0xfffffe003ccaf7a0
code segment      = base 0x0, limit 0xfffff, type 0x1b
         = DPL 0, pres 1, long 1, def32 0, gran 1
processor eflags   = interrupt enabled, resume, IOPL = 0
current process      = 0 (em1 taskq)

They all look the same here. Are you using the os-intel-em plugin?

Not much changed from 16.7.4 to 16.7.5. Shawn was a bit worried about his ASLR/PIE, but that was always in 16.7 or phased into 16.7.7, respectively.

We should attempt to get you on 16.7.7 or retry with install+restore to 16.7 just to see if it's still happening before we go into which features you use.

Edit: also looks like there is a file system inconsistency that can't be fixed anymore. Did the system ever power out unexpectedly?

[Nacho]

Not sure if it had an unexpected power cycle, but it's a machine at Hetzner and not the newest at that so anything is possible.

I don't know if I use the os-intel-em plugin, at the moment it won't show me any plugin, it just shows a mostly empty page.

I might try to do a clean install and import the config, seems like the cleanest option at the moment.

[franco]

Is it a root server? It could be the machine has a faulty NIC caused by larger traffic flow. All the errors point to only "em1" being unstable. If you have more ports available try avoiding "em1".

The reinstall seems like a clean option, but if the above is true, it's going to be the same, only then you're on 16.7 and can't upgrade. :/

[Nacho]

Hi Franco,

Thanks again for helping out!

It's a virtual machine on VMware ESXi which is on a machine at Hetzner. It is possible that it has some hardware issue but I haven't seen anything in the vmware logs.
I did some tests downloading large files from a machine behind the firewall which works fine. Until a couple of weeks ago I had the Squid server running with all internet traffic from the machines behind the firewall going through the proxy, this was working fine until I ran the last update on OPN. after the update the OPN would crash when trying to download anything through the proxy.

So I'm still leaning towards a reinstall. I just have to find the time to do it

Cheers,
Taco

[franco]

Ok, in a VM setting it doesn't make sense that "em1" is faulty, probably just the busy WAN link going down first and foremost. I agree.

Meanwhile, 16.7.7 superseded 16.7.5 in terms of base/kernel files installed. But in any case even a refresh of the 16.7.5 would work as they are signed and verified, it can only be wrong when the file system has glitches or RAM during reads or writes after verification.

Anyway, good luck and please check back.

[Nacho]

Well, I managed to install a second machine with:

OPNsense 16.7.7-amd64
FreeBSD 10.3-RELEASE-p11
OpenSSL 1.0.2j 26 Sep 2016

So far I haven't seen any issues. Unfortunately I can't do a straight restore on it due to the setup I have, I'll be configuring this server to take over all tasks from the crashing server manually. Once I'm done I'll have to request a routing change from Hetzner (at the moment I have a /28 subnet routed to the problematic server) once that is done I'll do some testing to see if the issue stays away. I'll post back here in a few days.

Cheers,
Taco

[Nacho]

Just checking back;

I've now made the new firewall (16.7.7) live with an almost identical config. I did set it up manually for the most part and only used the export/import for the ipsec config (the firewall has a site2site ipsec to another environment)
I've also enabled the proxy which I had disabled on the crashing server.
So far everything seems to work fine, I've had no crashes on this server and everything seems to work ok.
My gut feeling says something went wrong during the last update which caused the kernel to crash. The new install seems to update fine so I'd say this was a once-off and not a bug.

Thanks for your support!

[franco]

Hey Nacho,

Happy to hear and thanks for checking back. If something to the contrary pops up again, let us know.


Cheers,
Franco

[Nacho]

Ehmm... while I am switched over to the new firewall I had time to play with the old one a bit more; I noticed that for some reason my WAN interface was set to DHCP while I initially specifically configured this to be the static ip address that I got from Hetzner. When I reconfigured it to be the static address I tried updating and guess what.... it worked!?! running the updater is what kept crashing the server but now it updated fine, it's now on 16.7.7 as well.

So maybe during one of the updates (I suspect when I updated from 16.1.x to 16.7) the WAN interface switched to DHCP. not sure if that is even possible but changing it back to static definitely seems to have fixed the issue.

I might just keep this server around and test a bit more with it.

Anyway, status can stay [SOLVED], I'm just leaving this comment in case anyone else happens to run into this issue as well.

Cheers,
Taco

[franco]

Hi Taco,

Could it be the server picked up a bad IP on em1 (WAN?!) and the forced traffic caused a loop on the infrastructure attached causing the Intel driver to drop out under the pressure? It would explain why the server is fine now, only em1 crashed and only when you tried to operate from its IP directly.


Cheers,
Franco