Is this the type of issue fixed by bug fix #4445 ?

rnmixon

Hi,

I just read through the release notes on 2.2.1 and noticed a resolution for bug #4445

https://redmine.pfsense.org/issues/4445

I have posted twice back in December when running 2.2 on Hyper-V:

Am I correct in deducing that the problems I reported are pretty similar to that reported in bug #4445?

It's strange 2.2 has been working fine on one Hyper-v server (1U SuperMicro with Intel Atom C2778). But on another (a Xeon E5-2630L v2) we had the above problem.

Thanks for any comments/insight.

Richard

cmb

The symptoms you described there are exactly how bug #4445 exhibits itself. I'm not sure why it's so hit and miss between hosts, most Hyper-V hosts don't seem to hit it, but some repeatedly do. It's definitely fixed in 2.2.1 though.

rnmixon

Well, I upgraded to 2.2.1 on the 1u SuperMicro this evening and it seems to have also been bit now.

I can ssh into the firewall - from there I can access the internet or the LAN, but no connectivity from LAN to the outside.

I restored back to my pre-upgrade config, but still cannot connect.

Headed into do a physical restore on the VM now.

rnmixon

Here's a bit more info:

Once I got onsite I could restore a backup of the VM from the night before. Tested and all was working fine.
Since I was up and onsite at 2am I decided to go on and try the 2.2.1 update again. The exact same thing happened.
Before I restored again I used sftp to grab as many of the log, config and other files I could think of so we might have a better chance of understanding why this is happening.

I'm including the dmesg.boot file below - the end of which shows the disk I/O error and it appears to be unable to mount, no real surprises here.

What other info might be of use? I've also got the rules.debug files which was mentioned in bug #4445 as the file that get's corrupted by this problem. I don't think I want to publicly upload the whole file to the forum - but could do excerpts if that might help.

It would also be great to know if there's a good way to patch the rules.debug file as it should be when this happens. That is not ideal, but much better than restoring the VM and losing a days' log files and history.

Thank you much - Richard

/var/log/dmesg.boot:

Copyright (c) 1992-2014 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.1-RELEASE-p6 #0 b69ba8f(releng/10.1)-dirty: Fri Mar 13 08:37:46 CDT 2015
    root@pfs22-amd64-builder:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10 amd64
FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512
CPU: Intel(R) Atom(TM) CPU  C2758  @ 2.40GHz (2400.85-MHz K8-class CPU)
  Origin = "GenuineIntel"  Id = 0x406d8  Family = 0x6  Model = 0x4d  Stepping = 8
  Features=0x1f83fbff <fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,mmx,fxsr,sse,sse2,ss,htt>Features2=0xc2d82203 <sse3,pclmulqdq,ssse3,cx16,sse4.1,sse4.2,movbe,popcnt,aesni,rdrand,hv>AMD Features=0x20100800 <syscall,nx,lm>AMD Features2=0x101 <lahf,prefetch>Structured Extended Features=0x2200 <erms>real memory  = 2147483648 (2048 MB)
avail memory = 2041348096 (1946 MB)
Event timer "LAPIC" quality 400
ACPI APIC Table: <vrtual microsft="">FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs
FreeBSD/SMP: 1 package(s) x 2 core(s)
 cpu0 (BSP): APIC ID:  0
 cpu1 (AP): APIC ID:  1
ioapic0: Changing APIC ID to 0
ioapic0 <version 1.1="">irqs 0-23 on motherboard
wlan: mac acl policy registered
random: <software, yarrow="">initialized
kbd1 at kbdmux0
vmbus0: <vmbus devices="">on motherboard
cryptosoft0: <software crypto="">on motherboard
padlock0: No ACE support.
acpi0: <vrtual microsft="">on motherboard
acpi0: Power Button (fixed)
acpi0: reservation of 0, a0000 (3) failed
acpi0: reservation of 100000, f7f00000 (3) failed
cpu0: <acpi cpu="">on acpi0
cpu1: <acpi cpu="">on acpi0
attimer0: <at timer="">port 0x40-0x43 irq 0 on acpi0
Timecounter "i8254" frequency 1193182 Hz quality 0
Event timer "i8254" frequency 1193182 Hz quality 100
atrtc0: <at realtime="" clock="">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: <32-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0
pcib0: <acpi host-pci="" bridge="">port 0xcf8-0xcff on acpi0
pci0: <acpi pci="" bus="">on pcib0
isab0: <pci-isa bridge="">at device 7.0 on pci0
isa0: <isa bus="">on isab0
atapci0: <intel piix4="" udma33="" controller="">port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xffa0-0xffaf at device 7.1 on pci0
ata0: <ata channel="">at channel 0 on atapci0
ata1: <ata channel="">at channel 1 on atapci0
pci0: <bridge>at device 7.3 (no driver attached)
vgapci0: <vga-compatible display="">mem 0xf8000000-0xfbffffff irq 11 at device 8.0 on pci0
vgapci0: Boot video device
atkbdc0: <keyboard controller="" (i8042)="">port 0x60,0x64 irq 1 on acpi0
atkbd0: <at keyboard="">irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <ps 2="" mouse="">irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model IntelliMouse Explorer, device ID 4
uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
uart0: console (115200,n,8,1)
uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
fdc0: <floppy drive="" controller="" (fde)="">port 0x3f0-0x3f5,0x3f7 irq 6 drq 2 on acpi0
fd0: <1440-KB 3.5" drive> on fdc0 drive 0
orm0: <isa option="" rom="">at iomem 0xc0000-0xcbfff on isa0
sc0: <system console="">at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <generic isa="" vga="">at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
ppc0: cannot reserve I/O port range
Timecounter "Hyper-V" frequency 10000000 Hz quality 10000000
Timecounters tick every 10.000 msec
IPsec: Initialized Security Association Processing.
storvsc0 on vmbus0
storvsc1 on vmbus0
hyperv-utils0 on vmbus0
hyperv-utils0: Hyper-V Service attaching: Hyper-V Heartbeat Service

hyperv-utils1 on vmbus0
hyperv-utils1: Hyper-V Service attaching: Hyper-V KVP Service

hyperv-utils2 on vmbus0
hyperv-utils2: Hyper-V Service attaching: Hyper-V Shutdown Service

hyperv-utils3 on vmbus0
hyperv-utils3: Hyper-V Service attaching: Hyper-V Time Synch Service

hn0: <synthetic network="" interface="">on vmbus0
random: unblocking device.
hn1: <synthetic network="" interface="">on vmbus0
ada0 at ata0 bus 0 scbus0 target 0 lun 0
ada0: <virtual hd="" 1.1.0="">ATA-8 device
ada0: 16.700MB/s transfers (WDMA2, PIO 65536bytes)
ada0: 8192MB (16777216 512 byte sectors: 16H 63S/T 16383C)
ada0: Previously was known as ad0
(ada0:ata0:0:0:0): SETFEATURES ENABLE WCACHE. ACB: ef 02 00 00 00 40 00 00 00 00 00 00
(ada0:ata0:0:0:0): CAM status: ATA Status Error
(ada0:ata0:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 00 ()
(ada0:ata0:0:0:0): RES: 51 00 00 00 00 00 00 00 00 00 00
(ada0:ata0:0:0:0): Retrying command
cd0 at ata0 bus 0 scbus0 target 1 lun 0
cd0: <msft virtual="" cd="" rom="" 1.0="">Removable CD-ROM SCSI-5 device
SMP: AP CPU #1 Launched!
cd0: 16.700MB/s transfers (WDMA2, ATAPI 12bytes, PIO 65534bytes)
cd0: Attempt to query device size failed: NOT READY, Medium not present
(ada0:ata0:0:0:0): SETFEATURES ENABLE WCACHE. ACB: ef 02 00 00 00 40 00 00 00 00 00 00
(ada0:ata0:0:0:0): CAM status: ATA Status Error
(ada0:ata0:0:0:0): ATA status: 51 (DRDY SERV ERR), error: 00 ()
(ada0:ata0:0:0:0): RES: 51 00 00 00 00 00 00 00 00 00 00
(ada0:ata0:0:0:0): Error 5, Retries exhausted
da0 at blkvsc0 bus 0 scbus2 target 0 lun 0
da0: <msft virtual="" disk="" 1.0="">Fixed Direct Access SCSI-4 device
da0: 300.000MB/s transfers
da0: Command Queueing enabled
da0: 8192MB (16777216 512 byte sectors: 255H 63S/T 1044C)
Trying to mount root from ufs:/dev/ada0s1a [rw]...</msft></msft></virtual></synthetic></synthetic></generic></system></isa></floppy></ps></at></keyboard></vga-compatible></bridge></ata></ata></intel></isa></pci-isa></acpi></acpi></at></at></acpi></acpi></vrtual></software></vmbus></software,></version></vrtual></erms></lahf,prefetch></syscall,nx,lm></sse3,pclmulqdq,ssse3,cx16,sse4.1,sse4.2,movbe,popcnt,aesni,rdrand,hv></fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,mmx,fxsr,sse,sse2,ss,htt>

rnmixon

Am I seeing this problem because #4445 was not completely fixed in 2.2.1? Or is it because the bug manifests while I am still on 2.2, but in the process of upgrading to 2.2.1?

Anything I can do to better figure out this? Or as or recover from it at all?

I read the bug description that says "results in a rules.debug omitting all config-dependent nat and rdr lines from rules.debug", but I'm not savvy enough to try and fix that on the fly (or not even sure I should try to).

Thank you - Richard

cmb

If you're still seeing "Dec 5 08:39:49 pfSense kernel: (ada0:ata1:0:1:0): Error 5, Retries exhausted", you're having a different issue of some sort. Any issue you're having on 2.2.1 at this point is completely different from #4445, that's definitely completely fixed in 2.2.1. Those disk error logs could potentially cause similar symptoms if they're still occurring.