Optimizing rc.bootup

ssheikh · Sep 4, 2013, 7:57 AM

Forking off this thread: http://forum.pfsense.org/index.php/topic,66103.0.html

My initial thoughts on this are:

pfSense has such a wide variety of hardware being used to run it that a common rc.bootup may not work for every scenario unless we build a lot if intelligence into it. May not be doable without a lot of tedious work and feedback from the users.
I think rc.bootup should just start up the interfaces and setup the core firewall but none of the packages or services. It should stage a delayed starting for all the packages and services. Possibly through cron/at.
Give the enduser some flexibility in defining service startup sequences and delays. Also give them the ability to define service inter-dependencies. Maybe add tab under System: Advanced called "Startup Sequence" or something similar.
A bit OT, but having a service watchdog that periodically checks on the status of services, alerts and restarts any if it finds them dead.

Thanks,

Shahid

phil.davis · Sep 4, 2013, 9:26 AM

1,2,3: This repo has the code we are working on at present - https://github.com/individual-it/pfsense
It lets the user specify a startup delay (seconds). On low memory systems that experience issues (e.g. if you have a few OpenVPN instances and…) then you can choose a delay time. (e.g. 10, 15, 20 seconds seem useful values in our trials)
It also lets you choose a "memory stabilise time (seconds)" - it monitors the number of free memory pages, if that stays within a 2% tolerance for this many seconds, then the boot proceeds (rather than waiting the whole delay time). In testing we have found that typically a process is kicked off, memory fluctuates for a few seconds, then it stabilses, a reasonable indication that the new process has done its initialisation and settled down.
For the OpenVPN case, the delay routine is called after the start of each server and client instance. For other things (dnsmasq, dhcp server, ntp...) it is called after each one is kicked off.
So far this seems to be a practical way to have a tunable slowdown of the boot process.

The functional guts of this code works. We are just in the process of fixing up GUI/message typos/formatting... Hope to have a pull request with A1 code for tomorrow.

4: JimP created the Service Watchdog package last week. Try it, it is working for me.

eri-- · Sep 4, 2013, 9:37 AM

Those are all kludges and i would be reluctant to merge that even.

There is a plan hopefully to be ready fro 2.2 to make this a non-issue.

The main issue is not the daemons started but the php process(es) which are memory hungry and create overhead.
For 2.1 i think its too late to have this for 2.2 a proper solution would be to move to php-fpm and create a messaging mechanism to avoid spawning that many php processes but just use one and be done with it.
This will lower the memory requirements and provide flexibility on how things are handled.

You have to realise that not only rc.bootup is the issue here!

phil.davis · Sep 4, 2013, 9:51 AM

It would be good to have some review discussion about a practical (=kludge?) solution to the current issues. We sometimes have trouble at bootup that leaves the firewall with no webGUI, missing DNS, DHCP or whatever. Now that there is Service Watchdog, things improve because that can kick off failed things after the bootup finishes. But Service Watchdog takes no action until it sees that the boot is finished. Sometimes the boot process itself gets killed and the "bootup" file does not get removed, so Service Watchdog forever thinks the system is still booting, and thus does not restart the missing services.
We even had 1 example a week ago where system routing configure died somewhere and the system would not route at all and/or the pf process was gone - those things are not restarted by Service Watchdog!

Under some scenarios, someone has to SSH in to the box locally and restart the webGUI, then use the webGUI to restart services… until they get useful internet back and then remote support can get in over OpenVPN, TeamViewer or whatever to check things out. Minimising the need for this would be good:)

What is reasonable to do in 2.1 to help this?

eri-- · Sep 4, 2013, 10:48 AM

Add more RAM!
It is too late for anything for 2.1 of such big impacts.

All the small changes like disabling APC etc were merged but i think anything else is a bit late.
Maybe 2.1.1? is a better target.

phil.davis · Sep 4, 2013, 11:17 AM

Add more RAM!

I wish I could, but it is soldered onto the Alix board! We are planning to buy the new systems from NetGate with 2GB RAM, 4 x 1GB ethernet 12V DC to use in our main offices. People can bring them out from the USA in late November. We can't get anything like that here locally, and getting them freighted out is a nightmare of paperwork at this end. The small offices do not have multiple WAN/VLAN, less VPN links… so they run fine on the Alix. At the end of November I hope to have solved our issues with hardware changes.

But there are 1,000's of Alix installs out there. There must be other people who are finding them tight on memory, and it would be useful to provide "optimal" solutions for them to be able to run new FreeBSD/pfSense versions for as long as feasible.

Anyway, given the flurry of activity in Redmine and Github the last 2 days, it looks like a 2.1 release is getting close to reality. So, as you suggest, it might be best to work something for a subsequent pfSense version.

kejianshi · Sep 4, 2013, 11:26 AM

Sounds like you are living life on the edge with ram.

Any chance you could get anything else very low power with more ram other than alix?

phil.davis · Sep 4, 2013, 11:37 AM

Any chance you could get anything else very low power with more ram other than alix?

Yep, I was referring to http://store.netgate.com/Netgate-FW-525B-P1919C83.aspx - more memory, more ethernet and faster, still 12V DC connector.
If I could find them in a local shop I would be very happy. These (or any similar thing that I can find) can come in late November. Some time next year the "new Alix" may be available for real, and that will be another possibility, but its production schedule is too slow for me right now.

Just for interest, we live over-the-edge here. In one remote town the hydro-power system has gone down. It will be off-line for 1 month. No town power at all. Nepal Telecom does not have enough solar and battery there to run telecommunications 24/7. So they have switched off the internet service for a month, and the mobile phone tower is turned on in the afternoon/evening when the solar batteries have charged a bit, then turned off again when night has really come. For this month I don't care if the Alix up there boots or not :)

So the ability to connect pfSense hardware direct to a battery is very useful.

kejianshi · Sep 4, 2013, 12:06 PM

I know your solar issues. I also have built several full solar installs. Currently here at home I use all monocrystalline panels with exide deep cycle lead-acid batteries for storage and PWM chargers. If these batteries ever give up, I'll switch to LIFEPO4, but they show no signs of wear.
I realize that PSU = Power conversion = Power loss also.
Anyway. WATTs add up quick. I'll give it some thought.

eri-- · Sep 4, 2013, 12:42 PM

For anyone that wants to test here is a diff to check_reload_status that should make things better for lowmem systems.

You need to recompile check_reload_status yourself and put it on the pfSense box.


diff --git a/pfPorts/check_reload_status/files/check_reload_status.c b/pfPorts/check_reload_status/files/check_reload_status.c
index 494a776..c2905d9 100644
--- a/pfPorts/check_reload_status/files/check_reload_status.c
+++ b/pfPorts/check_reload_status/files/check_reload_status.c
@@ -225,6 +225,8 @@ run_command_detailed(int fd, short event, void *arg) {
                return;
        }

+       system(cmd->command);
+#if 0
        switch (vfork()) {
        case -1:
                syslog(LOG_ERR, "Could not vfork() error %d - %s!!!", errno, strerror(errno));
@@ -237,6 +239,7 @@ run_command_detailed(int fd, short event, void *arg) {
                _exit(127); /* Protect in case execl errors out */
                break;
        default:
+#endif
                if (cmd->aggregate > 0) {
                        cmd->dontexec = 1;
                        timeout_add(&cmd->ev, &tv);
@@ -246,8 +249,10 @@ run_command_detailed(int fd, short event, void *arg) {
                        pthread_mutex_unlock(&mtx);
                        free(cmd);
                }
+#if 0
                break;
        }
+#endif
 }

 static void

ssheikh · Sep 4, 2013, 4:00 PM

@phil.davis:

4: JimP created the Service Watchdog package last week. Try it, it is working for me.

Thx. Will give that a try.

ssheikh · Sep 4, 2013, 5:48 PM

@ermal:

Add more RAM!
It is too late for anything for 2.1 of such big impacts.

All the small changes like disabling APC etc were merged but i think anything else is a bit late.
Maybe 2.1.1? is a better target.

In my case I am having the most bootup related problems on x2 Quad core system with 8 GB of RAM.

I think the problem is more than just check_reload_status. Here is the System Log:

Sep 1 23:03:49	kernel: cpu6 (AP): APIC ID: 20
Sep 1 23:03:49	kernel: cpu7 (AP): APIC ID: 22
Sep 1 23:03:49	kernel: ioapic0: Changing APIC ID to 1
Sep 1 23:03:49	kernel: ioapic1: Changing APIC ID to 3
Sep 1 23:03:49	kernel: ioapic0 <version 2.0=""> irqs 0-23 on motherboard
Sep 1 23:03:49	kernel: ioapic1 <version 2.0=""> irqs 24-47 on motherboard
Sep 1 23:03:49	kernel: wlan: mac acl policy registered
Sep 1 23:03:49	kernel: ipw_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
Sep 1 23:03:49	kernel: ipw_bss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Sep 1 23:03:49	kernel: module_register_init: MOD_LOAD (ipw_bss_fw, 0xffffffff804a5da0, 0) error 1
Sep 1 23:03:49	kernel: ipw_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
Sep 1 23:03:49	kernel: ipw_ibss: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Sep 1 23:03:49	kernel: module_register_init: MOD_LOAD (ipw_ibss_fw, 0xffffffff804a5e40, 0) error 1
Sep 1 23:03:49	kernel: ipw_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_ipw/.
Sep 1 23:03:49	kernel: ipw_monitor: If you agree with the license, set legal.intel_ipw.license_ack=1 in /boot/loader.conf.
Sep 1 23:03:49	kernel: module_register_init: MOD_LOAD (ipw_monitor_fw, 0xffffffff804a5ee0, 0) error 1
Sep 1 23:03:49	kernel: kbd1 at kbdmux0
Sep 1 23:03:49	kernel: cryptosoft0: <software crypto=""> on motherboard
Sep 1 23:03:49	kernel: padlock0: No ACE support.
Sep 1 23:03:49	kernel: acpi0: <081612 XSDT1045> on motherboard
Sep 1 23:03:49	kernel: acpi0: [ITHREAD]
Sep 1 23:03:49	kernel: acpi0: Power Button (fixed)
Sep 1 23:03:49	kernel: unknown: I/O range not supported
Sep 1 23:03:49	kernel: acpi0: reservation of 0, a0000 (3) failed
Sep 1 23:03:49	kernel: acpi0: reservation of 100000, bff00000 (3) failed
Sep 1 23:03:49	kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
Sep 1 23:03:49	kernel: acpi_timer0: <24-bit timer at 3.579545MHz> port 0x808-0x80b on acpi0
Sep 1 23:03:49	kernel: cpu0: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: ACPI Warning: Incorrect checksum in table [OEMB] - 0x2E, should be 0x2B (20101013/tbutils-354)
Sep 1 23:03:49	kernel: cpu1: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: cpu2: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: cpu3: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: cpu4: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: cpu5: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: cpu6: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: cpu7: <acpi cpu=""> on acpi0
Sep 1 23:03:49	kernel: pcib0: <acpi host-pci="" bridge=""> port 0xcf8-0xcff on acpi0
Sep 1 23:03:49	kernel: pci0: <acpi pci="" bus=""> on pcib0
Sep 1 23:03:49	kernel: pcib1: <acpi pci-pci="" bridge=""> at device 1.0 on pci0
Sep 1 23:03:49	kernel: pci1: <acpi pci="" bus=""> on pcib1
Sep 1 23:03:49	kernel: pcib2: <acpi pci-pci="" bridge=""> at device 2.0 on pci0
Sep 1 23:03:49	kernel: pci2: <acpi pci="" bus=""> on pcib2
Sep 1 23:03:49	kernel: pcib3: <acpi pci-pci="" bridge=""> at device 3.0 on pci0
Sep 1 23:03:49	kernel: pci3: <acpi pci="" bus=""> on pcib3
Sep 1 23:03:49	kernel: pcib4: <acpi pci-pci="" bridge=""> at device 7.0 on pci0
Sep 1 23:03:49	kernel: pci4: <acpi pci="" bus=""> on pcib4
Sep 1 23:03:49	kernel: pcib5: <acpi pci-pci="" bridge=""> at device 9.0 on pci0
Sep 1 23:03:49	kernel: pci5: <acpi pci="" bus=""> on pcib5
Sep 1 23:03:49	kernel: em0: <intel(r) 1000="" pro="" network="" connection="" 7.3.2=""> port 0xcc00-0xcc1f mem 0xdf5e0000-0xdf5fffff,0xdf5c0000-0xdf5dffff irq 32 at device 0.0 on pci5
Sep 1 23:03:49	kernel: em0: Using an MSI interrupt
Sep 1 23:03:49	kernel: em0: [FILTER]
Sep 1 23:03:49	kernel: em1: <intel(r) 1000="" pro="" network="" connection="" 7.3.2=""> port 0xc880-0xc89f mem 0xdf5a0000-0xdf5bffff,0xdf580000-0xdf59ffff irq 42 at device 0.1 on pci5
Sep 1 23:03:49	kernel: em1: Using an MSI interrupt
Sep 1 23:03:49	kernel: em1: [FILTER]
Sep 1 23:03:49	kernel: pci0: <base peripheral,="" interrupt="" controller=""> at device 20.0 (no driver attached)
Sep 1 23:03:49	kernel: pci0: <base peripheral,="" interrupt="" controller=""> at device 20.1 (no driver attached)
Sep 1 23:03:49	kernel: pci0: <base peripheral,="" interrupt="" controller=""> at device 20.2 (no driver attached)
Sep 1 23:03:49	kernel: pci0: <base peripheral,="" interrupt="" controller=""> at device 20.3 (no driver attached)
Sep 1 23:03:49	kernel: uhci0: <intel 82801ji="" (ich10)="" usb="" controller="" usb-d=""> port 0xbc00-0xbc1f irq 23 at device 26.0 on pci0
Sep 1 23:03:49	kernel: uhci0: [ITHREAD]
Sep 1 23:03:49	kernel: uhci0: LegSup = 0x2400
Sep 1 23:03:49	kernel: usbus0: <intel 82801ji="" (ich10)="" usb="" controller="" usb-d=""> on uhci0
Sep 1 23:03:49	kernel: uhci1: <intel 82801ji="" (ich10)="" usb="" controller="" usb-e=""> port 0xb880-0xb89f irq 22 at device 26.1 on pci0
Sep 1 23:03:49	kernel: uhci1: [ITHREAD]
Sep 1 23:03:49	kernel: uhci1: LegSup = 0x2400
Sep 1 23:03:49	kernel: usbus1: <intel 82801ji="" (ich10)="" usb="" controller="" usb-e=""> on uhci1
Sep 1 23:03:49	kernel: uhci2: <intel 82801ji="" (ich10)="" usb="" controller="" usb-f=""> port 0xb800-0xb81f irq 21 at device 26.2 on pci0
Sep 1 23:03:49	kernel: uhci2: [ITHREAD]
Sep 1 23:03:49	kernel: uhci2: LegSup = 0x2400
Sep 1 23:03:49	kernel: usbus2: <intel 82801ji="" (ich10)="" usb="" controller="" usb-f=""> on uhci2
Sep 1 23:03:49	kernel: ehci0: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-b=""> mem 0xdf4de000-0xdf4de3ff irq 20 at device 26.7 on pci0
Sep 1 23:03:49	kernel: ehci0: [ITHREAD]
Sep 1 23:03:49	kernel: usbus3: EHCI version 1.0
Sep 1 23:03:49	kernel: usbus3: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-b=""> on ehci0
Sep 1 23:03:49	kernel: pcib6: <acpi pci-pci="" bridge=""> irq 17 at device 28.0 on pci0
Sep 1 23:03:49	kernel: pci6: <acpi pci="" bus=""> on pcib6
Sep 1 23:03:49	kernel: igb0: <intel(r) 1000="" pro="" network="" connection="" version="" -="" 2.3.1=""> port 0xdc00-0xdc1f mem 0xdf6e0000-0xdf6fffff,0xdf6c0000-0xdf6dffff,0xdf69c000-0xdf69ffff irq 16 at device 0.0 on pci6
Sep 1 23:03:49	kernel: igb0: Using MSIX interrupts with 9 vectors
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 0 to cpu 0
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 1 to cpu 1
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 2 to cpu 2
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 3 to cpu 3
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 4 to cpu 4
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 5 to cpu 5
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 6 to cpu 6
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb0: Bound queue 7 to cpu 7
Sep 1 23:03:49	kernel: igb0: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: <intel(r) 1000="" pro="" network="" connection="" version="" -="" 2.3.1=""> port 0xd880-0xd89f mem 0xdf660000-0xdf67ffff,0xdf640000-0xdf65ffff,0xdf61c000-0xdf61ffff irq 17 at device 0.1 on pci6
Sep 1 23:03:49	kernel: igb1: Using MSIX interrupts with 9 vectors
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 0 to cpu 0
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 1 to cpu 1
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 2 to cpu 2
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 3 to cpu 3
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 4 to cpu 4
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 5 to cpu 5
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 6 to cpu 6
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: igb1: Bound queue 7 to cpu 7
Sep 1 23:03:49	kernel: igb1: [ITHREAD]
Sep 1 23:03:49	kernel: uhci3: <intel 82801ji="" (ich10)="" usb="" controller="" usb-a=""> port 0xb480-0xb49f irq 23 at device 29.0 on pci0
Sep 1 23:03:49	kernel: uhci3: [ITHREAD]
Sep 1 23:03:49	kernel: uhci3: LegSup = 0x2400
Sep 1 23:03:49	kernel: usbus4: <intel 82801ji="" (ich10)="" usb="" controller="" usb-a=""> on uhci3
Sep 1 23:03:49	kernel: uhci4: <intel 82801ji="" (ich10)="" usb="" controller="" usb-b=""> port 0xb400-0xb41f irq 22 at device 29.1 on pci0
Sep 1 23:03:49	kernel: uhci4: [ITHREAD]
Sep 1 23:03:49	kernel: uhci4: LegSup = 0x2400
Sep 1 23:03:49	kernel: usbus5: <intel 82801ji="" (ich10)="" usb="" controller="" usb-b=""> on uhci4
Sep 1 23:03:49	kernel: uhci5: <intel 82801ji="" (ich10)="" usb="" controller="" usb-c=""> port 0xac00-0xac1f irq 21 at device 29.2 on pci0
Sep 1 23:03:49	kernel: uhci5: [ITHREAD]
Sep 1 23:03:49	kernel: uhci5: LegSup = 0x2400
Sep 1 23:03:49	kernel: usbus6: <intel 82801ji="" (ich10)="" usb="" controller="" usb-c=""> on uhci5
Sep 1 23:03:49	kernel: ehci1: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-a=""> mem 0xdf4dc000-0xdf4dc3ff irq 23 at device 29.7 on pci0
Sep 1 23:03:49	kernel: ehci1: [ITHREAD]
Sep 1 23:03:49	kernel: usbus7: EHCI version 1.0
Sep 1 23:03:49	kernel: usbus7: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-a=""> on ehci1
Sep 1 23:03:49	kernel: pcib7: <acpi pci-pci="" bridge=""> at device 30.0 on pci0
Sep 1 23:03:49	kernel: pci7: <acpi pci="" bus=""> on pcib7
Sep 1 23:03:49	kernel: vgapci0: <vga-compatible display=""> port 0xec00-0xec7f mem 0xdf800000-0xdfffffff,0xdf7e0000-0xdf7fffff irq 16 at device 11.0 on pci7
Sep 1 23:03:49	kernel: isab0: <pci-isa bridge=""> at device 31.0 on pci0
Sep 1 23:03:49	kernel: isa0: <isa bus=""> on isab0
Sep 1 23:03:49	kernel: atapci0: <intel ich10="" sata300="" controller=""> port 0xa080-0xa087,0xa880-0xa883,0xa800-0xa807,0xa480-0xa483,0xa400-0xa41f mem 0xdf4da000-0xdf4da7ff irq 18 at device 31.2 on pci0
Sep 1 23:03:49	kernel: atapci0: [ITHREAD]
Sep 1 23:03:49	kernel: atapci0: AHCI called from vendor specific driver
Sep 1 23:03:49	kernel: atapci0: AHCI v1.20 controller with 6 3Gbps ports, PM not supported
Sep 1 23:03:49	kernel: ata2: <ata channel=""> at channel 0 on atapci0
Sep 1 23:03:49	kernel: ata2: [ITHREAD]
Sep 1 23:03:49	kernel: ata3: <ata channel=""> at channel 1 on atapci0
Sep 1 23:03:49	kernel: ata3: [ITHREAD]
Sep 1 23:03:49	kernel: ata4: <ata channel=""> at channel 2 on atapci0
Sep 1 23:03:49	kernel: ata4: [ITHREAD]
Sep 1 23:03:49	kernel: ata5: <ata channel=""> at channel 3 on atapci0
Sep 1 23:03:49	kernel: ata5: [ITHREAD]
Sep 1 23:03:49	kernel: ata6: <ata channel=""> at channel 4 on atapci0
Sep 1 23:03:49	kernel: ata6: [ITHREAD]
Sep 1 23:03:49	kernel: ata7: <ata channel=""> at channel 5 on atapci0
Sep 1 23:03:49	kernel: ata7: [ITHREAD]
Sep 1 23:03:49	kernel: pci0: <serial bus,="" smbus=""> at device 31.3 (no driver attached)
Sep 1 23:03:49	kernel: acpi_button0: <power button=""> on acpi0
Sep 1 23:03:49	kernel: atrtc0: <at realtime="" clock=""> port 0x70-0x71 irq 8 on acpi0
Sep 1 23:03:49	kernel: uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
Sep 1 23:03:49	kernel: uart0: [FILTER]
Sep 1 23:03:49	kernel: uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
Sep 1 23:03:49	kernel: uart1: [FILTER]
Sep 1 23:03:49	kernel: acpi_hpet0: <high precision="" event="" timer=""> iomem 0xfed00000-0xfed003ff on acpi0
Sep 1 23:03:49	kernel: Timecounter "HPET" frequency 14318180 Hz quality 900
Sep 1 23:03:49	kernel: qpi0: <qpi system="" bus=""> on motherboard
Sep 1 23:03:49	kernel: pcib8: <qpi host-pci="" bridge=""> pcibus 255 on qpi0
Sep 1 23:03:49	kernel: pci255: <pci bus=""> on pcib8
Sep 1 23:03:49	kernel: pcib9: <qpi host-pci="" bridge=""> pcibus 254 on qpi0
Sep 1 23:03:49	kernel: pci254: <pci bus=""> on pcib9
Sep 1 23:03:49	kernel: orm0: <isa option="" rom=""> at iomem 0xc0000-0xc7fff on isa0
Sep 1 23:03:49	kernel: sc0: <system console=""> at flags 0x100 on isa0
Sep 1 23:03:49	kernel: sc0: CGA <16 virtual consoles, flags=0x300>
Sep 1 23:03:49	kernel: vga0: <generic isa="" vga=""> at port 0x3d0-0x3db iomem 0xb8000-0xbffff on isa0
Sep 1 23:03:49	kernel: atkbdc0: <keyboard controller="" (i8042)=""> at port 0x60,0x64 on isa0
Sep 1 23:03:49	kernel: atkbd0: <at keyboard=""> irq 1 on atkbdc0
Sep 1 23:03:49	kernel: kbd0 at atkbd0
Sep 1 23:03:49	kernel: atkbd0: [GIANT-LOCKED]
Sep 1 23:03:49	kernel: atkbd0: [ITHREAD]
Sep 1 23:03:49	kernel: psm0: <ps 2="" mouse=""> irq 12 on atkbdc0
Sep 1 23:03:49	kernel: psm0: [GIANT-LOCKED]
Sep 1 23:03:49	kernel: psm0: [ITHREAD]
Sep 1 23:03:49	kernel: psm0: model GlidePoint, device ID 0
Sep 1 23:03:49	kernel: ppc0: cannot reserve I/O port range
Sep 1 23:03:49	kernel: est0: <enhanced speedstep="" frequency="" control=""> on cpu0
Sep 1 23:03:49	kernel: p4tcc0: <cpu frequency="" thermal="" control=""> on cpu0
Sep 1 23:03:49	kernel: est1: <enhanced speedstep="" frequency="" control=""> on cpu1
Sep 1 23:03:49	kernel: p4tcc1: <cpu frequency="" thermal="" control=""> on cpu1
Sep 1 23:03:49	kernel: est2: <enhanced speedstep="" frequency="" control=""> on cpu2
Sep 1 23:03:49	kernel: p4tcc2: <cpu frequency="" thermal="" control=""> on cpu2
Sep 1 23:03:49	kernel: est3: <enhanced speedstep="" frequency="" control=""> on cpu3
Sep 1 23:03:49	kernel: p4tcc3: <cpu frequency="" thermal="" control=""> on cpu3
Sep 1 23:03:49	kernel: est4: <enhanced speedstep="" frequency="" control=""> on cpu4
Sep 1 23:03:49	kernel: p4tcc4: <cpu frequency="" thermal="" control=""> on cpu4
Sep 1 23:03:49	kernel: est5: <enhanced speedstep="" frequency="" control=""> on cpu5
Sep 1 23:03:49	kernel: p4tcc5: <cpu frequency="" thermal="" control=""> on cpu5
Sep 1 23:03:49	kernel: est6: <enhanced speedstep="" frequency="" control=""> on cpu6
Sep 1 23:03:49	kernel: p4tcc6: <cpu frequency="" thermal="" control=""> on cpu6
Sep 1 23:03:49	kernel: est7: <enhanced speedstep="" frequency="" control=""> on cpu7
Sep 1 23:03:49	kernel: p4tcc7: <cpu frequency="" thermal="" control=""> on cpu7
Sep 1 23:03:49	kernel: Timecounters tick every 1.000 msec
Sep 1 23:03:49	kernel: IPsec: Initialized Security Association Processing.
Sep 1 23:03:49	kernel: usbus0: 12Mbps Full Speed USB v1.0
Sep 1 23:03:49	kernel: usbus1: 12Mbps Full Speed USB v1.0
Sep 1 23:03:49	kernel: usbus2: 12Mbps Full Speed USB v1.0
Sep 1 23:03:49	kernel: usbus3: 480Mbps High Speed USB v2.0
Sep 1 23:03:49	kernel: usbus4: 12Mbps Full Speed USB v1.0
Sep 1 23:03:49	kernel: usbus5: 12Mbps Full Speed USB v1.0
Sep 1 23:03:49	kernel: usbus6: 12Mbps Full Speed USB v1.0
Sep 1 23:03:49	kernel: usbus7: 480Mbps High Speed USB v2.0
Sep 1 23:03:49	kernel: ad4: 239429MB <wdc wd2502abys-02b7a0="" 02.03b03=""> at ata2-master UDMA100 SATA 3Gb/s
Sep 1 23:03:49	kernel: ugen0.1: <intel> at usbus0
Sep 1 23:03:49	kernel: uhub0: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus0
Sep 1 23:03:49	kernel: ugen1.1: <intel> at usbus1
Sep 1 23:03:49	kernel: uhub1: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus1
Sep 1 23:03:49	kernel: ugen2.1: <intel> at usbus2
Sep 1 23:03:49	kernel: uhub2: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus2
Sep 1 23:03:49	kernel: ugen3.1: <intel> at usbus3
Sep 1 23:03:49	kernel: uhub3: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr=""> on usbus3
Sep 1 23:03:49	kernel: ugen4.1: <intel> at usbus4
Sep 1 23:03:49	kernel: uhub4: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus4
Sep 1 23:03:49	kernel: ugen5.1: <intel> at usbus5
Sep 1 23:03:49	kernel: uhub5: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus5
Sep 1 23:03:49	kernel: ugen6.1: <intel> at usbus6
Sep 1 23:03:49	kernel: uhub6: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus6
Sep 1 23:03:49	kernel: ugen7.1: <intel> at usbus7
Sep 1 23:03:49	kernel: uhub7: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr=""> on usbus7
Sep 1 23:03:49	kernel: ad6: 238418MB <wdc wd2502abys-18b7a0="" 02.03b04=""> at ata3-master UDMA100 SATA 3Gb/s
Sep 1 23:03:49	kernel: GEOM_MIRROR: Device mirror/pfSenseMirror launched (2/2).
Sep 1 23:03:49	kernel: ar0: WARNING - mirror protection lost. RAID1 array in DEGRADED mode
Sep 1 23:03:49	kernel: ar0: 238416MB <intel matrixraid="" raid1=""> status: DEGRADED
Sep 1 23:03:49	kernel: ar0: disk0 DOWN no device found for this subdisk
Sep 1 23:03:49	kernel: ar0: disk1 READY (mirror) using ad4 at ata2-master
Sep 1 23:03:49	kernel: SMP: AP CPU #3 Launched!
Sep 1 23:03:49	kernel: SMP: AP CPU #4 Launched!
Sep 1 23:03:49	kernel: SMP: AP CPU #2 Launched!
Sep 1 23:03:49	kernel: SMP: AP CPU #6 Launched!
Sep 1 23:03:49	kernel: SMP: AP CPU #1 Launched!
Sep 1 23:03:49	kernel: SMP: AP CPU #5 Launched!
Sep 1 23:03:49	kernel: SMP: AP CPU #7 Launched!
Sep 1 23:03:49	kernel: GEOM_PART: integrity check failed (ar0, MBR)
Sep 1 23:03:49	kernel: Root mount waiting for: usbus7 usbus6 usbus5 usbus4 usbus3 usbus2 usbus1 usbus0
Sep 1 23:03:49	kernel: uhub0: 2 ports with 2 removable, self powered
Sep 1 23:03:49	kernel: uhub1: 2 ports with 2 removable, self powered
Sep 1 23:03:49	kernel: uhub2: 2 ports with 2 removable, self powered
Sep 1 23:03:49	kernel: uhub4: 2 ports with 2 removable, self powered
Sep 1 23:03:49	kernel: uhub5: 2 ports with 2 removable, self powered
Sep 1 23:03:49	kernel: uhub6: 2 ports with 2 removable, self powered
Sep 1 23:03:49	kernel: Root mount waiting for: usbus7 usbus3
Sep 1 23:03:49	kernel: Root mount waiting for: usbus7 usbus3
Sep 1 23:03:49	kernel: uhub3: 6 ports with 6 removable, self powered
Sep 1 23:03:49	kernel: uhub7: 6 ports with 6 removable, self powered
Sep 1 23:03:49	kernel: Root mount waiting for: usbus3
Sep 1 23:03:49	kernel: ugen3.2: <avocent> at usbus3
Sep 1 23:03:49	kernel: ukbd0: <keyboard> on usbus3
Sep 1 23:03:49	kernel: kbd2 at ukbd0
Sep 1 23:03:49	kernel: ums0: <mouse> on usbus3
Sep 1 23:03:49	kernel: ums0: 3 buttons and [Z] coordinates ID=0
Sep 1 23:03:49	kernel: ums1: <mouse rel=""> on usbus3
Sep 1 23:03:49	kernel: ums1: 3 buttons and [XYZ] coordinates ID=0
Sep 1 23:03:49	kernel: Trying to mount root from ufs:/dev/mirror/pfSenseMirrors1a
Sep 1 23:03:49	kernel: ZFS NOTICE: Prefetch is disabled by default if less than 4GB of RAM is present;
Sep 1 23:03:49	kernel: to enable, add "vfs.zfs.prefetch_disable=0" to /boot/loader.conf.
Sep 1 23:03:49	kernel: ZFS WARNING: Recommended minimum kmem_size is 512MB; expect unstable behavior.
Sep 1 23:03:49	kernel: Consider tuning vm.kmem_size and vm.kmem_size_max
Sep 1 23:03:49	kernel: in /boot/loader.conf.
Sep 1 23:03:49	kernel: ZFS filesystem version 5
Sep 1 23:03:49	kernel: ZFS storage pool version 28
Sep 1 23:03:49	kernel: coretemp0: <cpu on-die="" thermal="" sensors=""> on cpu0
Sep 1 23:03:49	kernel: coretemp1: <cpu on-die="" thermal="" sensors=""> on cpu1
Sep 1 23:03:49	kernel: coretemp2: <cpu on-die="" thermal="" sensors=""> on cpu2
Sep 1 23:03:49	kernel: coretemp3: <cpu on-die="" thermal="" sensors=""> on cpu3
Sep 1 23:03:49	kernel: coretemp4: <cpu on-die="" thermal="" sensors=""> on cpu4
Sep 1 23:03:49	kernel: coretemp5: <cpu on-die="" thermal="" sensors=""> on cpu5
Sep 1 23:03:49	kernel: coretemp6: <cpu on-die="" thermal="" sensors=""> on cpu6
Sep 1 23:03:49	kernel: coretemp7: <cpu on-die="" thermal="" sensors=""> on cpu7
Sep 1 23:03:49	kernel: vlan0: changing name to 'em1_vlan3'
Sep 1 23:03:50	kernel: vlan1: changing name to 'em1_vlan5'
Sep 1 23:03:50	kernel: vlan2: changing name to 'em1_vlan51'
Sep 1 23:03:50	kernel: vlan3: changing name to 'em1_vlan33'
Sep 1 23:03:50	sshd[8616]: Server listening on :: port 22.
Sep 1 23:03:50	sshd[8616]: Server listening on 0.0.0.0 port 22.
Sep 1 23:03:50	sshlockout[8708]: sshlockout/webConfigurator v3.0 starting up
Sep 1 23:03:50	kernel: igb0: link state changed to UP
Sep 1 23:03:50	check_reload_status: Linkup starting igb0
Sep 1 23:03:50	kernel: igb0: link state changed to DOWN
Sep 1 23:03:50	check_reload_status: Linkup starting igb0
Sep 1 23:03:51	kernel: carp0: changing name to 'lan_vip2'
Sep 1 23:03:51	kernel: igb0: promiscuous mode enabled
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp1: changing name to 'opt3_vip3'
Sep 1 23:03:51	kernel: em1: promiscuous mode enabled
Sep 1 23:03:51	kernel: em1_vlan33: promiscuous mode enabled
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp2: changing name to 'opt2_vip51'
Sep 1 23:03:51	kernel: em1_vlan51: promiscuous mode enabled
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp3: changing name to 'wan_vip53'
Sep 1 23:03:51	kernel: igb1: promiscuous mode enabled
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp4: changing name to 'wan_vip100'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp5: changing name to 'opt2_vip200'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp6: changing name to 'opt2_vip217'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp7: changing name to 'opt5_vip1'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp8: changing name to 'wan_vip254'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp9: changing name to 'wan_vip101'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:51	kernel: carp10: changing name to 'opt2_vip201'
Sep 1 23:03:51	kernel: ifa_del_loopback_route: deletion failed
Sep 1 23:03:51	kernel: ifa_add_loopback_route: insertion failed
Sep 1 23:03:52	php: rc.bootup: waiting for pfsync...
Sep 1 23:03:52	php: rc.bootup: pfsync done in 0 seconds.
Sep 1 23:03:52	php: rc.bootup: Configuring CARP settings finalize...
Sep 1 23:03:52	php: rc.bootup: Resyncing OpenVPN instances.
Sep 1 23:03:52	php: rc.bootup: The command '/sbin/route -q delete 192.168.240.38' returned exit code '1', the output was 'route: writing to routing socket: No such process'
Sep 1 23:03:52	kernel: tun2: changing name to 'ovpnc2'
Sep 1 23:03:52	kernel: pflog0: promiscuous mode enabled
Sep 1 23:03:53	check_reload_status: Linkup starting igb1
Sep 1 23:03:53	kernel: wan_vip53: INIT -> BACKUP
Sep 1 23:03:53	kernel: wan_vip100: INIT -> BACKUP
Sep 1 23:03:53	kernel: wan_vip101: INIT -> BACKUP
Sep 1 23:03:53	kernel: wan_vip254: INIT -> BACKUP
Sep 1 23:03:53	kernel: igb1: link state changed to UP
Sep 1 23:03:53	kernel: wan_vip53: link state changed to DOWN
Sep 1 23:03:53	kernel: wan_vip100: link state changed to DOWN
Sep 1 23:03:53	kernel: wan_vip101: link state changed to DOWN
Sep 1 23:03:53	kernel: wan_vip254: link state changed to DOWN
Sep 1 23:03:53	kernel: em0: link state changed to UP
Sep 1 23:03:53	kernel: lan_vip2: INIT -> BACKUP
Sep 1 23:03:53	kernel: igb0: link state changed to UP
Sep 1 23:03:53	kernel: lan_vip2: link state changed to DOWN
Sep 1 23:03:53	kernel: opt5_vip1: INIT -> BACKUP
Sep 1 23:03:53	kernel: em1: link state changed to UP
Sep 1 23:03:53	kernel: opt2_vip51: INIT -> BACKUP
Sep 1 23:03:53	kernel: opt2_vip200: INIT -> BACKUP
Sep 1 23:03:53	kernel: opt2_vip201: INIT -> BACKUP
Sep 1 23:03:53	kernel: opt2_vip217: INIT -> BACKUP
Sep 1 23:03:53	kernel: em1_vlan51: link state changed to UP
Sep 1 23:03:53	kernel: opt3_vip3: INIT -> BACKUP
Sep 1 23:03:53	kernel: em1_vlan33: link state changed to UP
Sep 1 23:03:53	kernel: em1_vlan3: link state changed to UP
Sep 1 23:03:53	kernel: em1_vlan5: link state changed to UP
Sep 1 23:03:53	kernel: opt5_vip1: link state changed to DOWN
Sep 1 23:03:53	kernel: opt2_vip51: link state changed to DOWN
Sep 1 23:03:53	kernel: opt2_vip200: link state changed to DOWN
Sep 1 23:03:53	kernel: opt2_vip201: link state changed to DOWN
Sep 1 23:03:53	kernel: opt2_vip217: link state changed to DOWN
Sep 1 23:03:53	kernel: opt3_vip3: link state changed to DOWN
Sep 1 23:03:53	check_reload_status: Linkup starting em0
Sep 1 23:03:53	check_reload_status: Linkup starting igb0
Sep 1 23:03:53	check_reload_status: Linkup starting em1
Sep 1 23:03:53	check_reload_status: Linkup starting em1_vlan51
Sep 1 23:03:53	check_reload_status: Linkup starting em1_vlan33
Sep 1 23:03:53	check_reload_status: Linkup starting em1_vlan3
Sep 1 23:03:53	check_reload_status: Linkup starting em1_vlan5
Sep 1 23:03:56	kernel: wan_vip53: link state changed to UP
Sep 1 23:03:56	kernel: wan_vip100: link state changed to UP
Sep 1 23:03:56	kernel: wan_vip101: link state changed to UP
Sep 1 23:03:56	kernel: wan_vip254: link state changed to UP
Sep 1 23:03:56	php: rc.bootup: ROUTING: setting default route to 4.34.101.161
Sep 1 23:03:56	kernel: lan_vip2: link state changed to UP
Sep 1 23:03:56	kernel: opt5_vip1: link state changed to UP
Sep 1 23:03:56	kernel: opt2_vip51: link state changed to UP
Sep 1 23:03:56	kernel: opt2_vip200: link state changed to UP
Sep 1 23:03:56	kernel: opt2_vip201: link state changed to UP
Sep 1 23:03:56	kernel: opt2_vip217: link state changed to UP
Sep 1 23:03:56	kernel: opt3_vip3: link state changed to UP
Sep 1 23:03:57	check_reload_status: Updating all dyndns
Sep 1 23:04:01	php: rc.bootup: Creating rrd update script
Sep 1 23:04:01	syslogd: exiting on signal 15
Sep 1 23:04:01	syslogd: kernel boot file is /boot/kernel/kernel
Sep 1 23:04:01	php: rc.start_packages: Restarting/Starting all packages.
Sep 1 23:04:05	login: login on ttyv0 as root
Sep 1 23:04:05	sshlockout[1517]: sshlockout/webConfigurator v3.0 starting up
Sep 1 23:04:09	check_reload_status: updating dyndns GW_53
Sep 1 23:04:09	check_reload_status: Restarting ipsec tunnels
Sep 1 23:04:09	check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep 1 23:04:09	check_reload_status: Reloading filter
Sep 1 23:04:12	php: rc.dyndns.update: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_53.
Sep 1 23:04:12	php: rc.filter_configure_sync: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.openvpn: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: OpenVPN: Resync server1 VA Server <-> CA Client
Sep 1 23:04:12	php: rc.openvpn: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: OpenVPN: Resync client2 VA Client <-> TX Server
Sep 1 23:04:12	php: rc.openvpn: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: Default gateway down setting GW_51 as default!
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:12	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:12	php: rc.openvpn: The command '/sbin/route -q delete 192.168.240.38' returned exit code '1', the output was 'route: writing to routing socket: No such process'
Sep 1 23:04:17	php: rc.filter_configure_sync: Default gateway down setting GW_51 as default!
Sep 1 23:04:17	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 1 23:04:17	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 1 23:04:17	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 1 23:04:33	kernel: ovpnc2: link state changed to UP
Sep 1 23:04:33	check_reload_status: rc.newwanip starting ovpnc2
Sep 1 23:04:34	check_reload_status: updating dyndns GW_53
Sep 1 23:04:34	check_reload_status: Restarting ipsec tunnels
Sep 1 23:04:34	check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep 1 23:04:34	check_reload_status: Reloading filter
Sep 1 23:04:35	php: rc.newwanip: rc.newwanip: Informational is starting ovpnc2.
Sep 1 23:04:35	php: rc.newwanip: rc.newwanip: on (IP address: 192.168.240.38) (interface: ) (real interface: ovpnc2).
Sep 1 23:04:35	php: rc.newwanip: pfSense package system has detected an ip change -> 192.168.240.38 ... Restarting packages.
Sep 1 23:04:35	check_reload_status: Starting packages
Sep 1 23:04:36	php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_53.
Sep 1 23:04:36	php: rc.openvpn: OpenVPN: Resync server1 VA Server <-> CA Client
Sep 1 23:04:36	php: rc.openvpn: OpenVPN: Resync client2 VA Client <-> TX Server
Sep 1 23:04:37	php: rc.start_packages: Restarting/Starting all packages.
Sep 1 23:04:37	php: /index.php: Successful login for user 'cjenkins' from: 10.100.7.100
Sep 1 23:04:37	php: /index.php: Successful login for user 'cjenkins' from: 10.100.7.100
Sep 1 23:04:41	kernel: pid 68970 (ntpd), uid 0: exited on signal 11 (core dumped)
Sep 1 23:05:00	php: watchdog_ntpd: NTPD was found dead.
Sep 1 23:05:00	php: watchdog_ntpd: NTPD is starting up.
Sep 1 23:05:00	kernel: pid 20626 (ntpd), uid 0: exited on signal 11 (core dumped)
Sep 1 23:05:07	kernel: ovpnc2: link state changed to DOWN
Sep 1 23:05:07	check_reload_status: Reloading filter
Sep 1 23:05:08	kernel: ovpnc2: link state changed to UP
Sep 1 23:05:08	check_reload_status: rc.newwanip starting ovpnc2
Sep 1 23:05:10	php: rc.newwanip: rc.newwanip: Informational is starting ovpnc2.
Sep 1 23:05:10	php: rc.newwanip: rc.newwanip: on (IP address: 192.168.240.38) (interface: ) (real interface: ovpnc2).
Sep 1 23:05:10	php: rc.newwanip: pfSense package system has detected an ip change -> 192.168.240.38 ... Restarting packages.
Sep 1 23:05:10	check_reload_status: Starting packages
Sep 1 23:05:13	php: rc.start_packages: Restarting/Starting all packages.
Sep 1 23:05:39	kernel: ovpnc2: link state changed to DOWN
Sep 1 23:05:39	check_reload_status: Reloading filter
Sep 1 23:05:40	kernel: ovpnc2: link state changed to UP
Sep 1 23:05:40	check_reload_status: rc.newwanip starting ovpnc2
Sep 1 23:05:42	sshd[99439]: Accepted keyboard-interactive/pam for root from 10.100.7.100 port 53708 ssh2
Sep 1 23:05:42	php: rc.newwanip: rc.newwanip: Informational is starting ovpnc2.
Sep 1 23:05:42	php: rc.newwanip: rc.newwanip: on (IP address: 192.168.240.38) (interface: ) (real interface: ovpnc2).
Sep 1 23:05:42	php: rc.newwanip: pfSense package system has detected an ip change -> 192.168.240.38 ... Restarting packages.
Sep 1 23:05:42	check_reload_status: Starting packages
Sep 1 23:05:44	php: rc.start_packages: Restarting/Starting all packages.
Sep 1 23:06:44	kernel: ovpnc2: link state changed to DOWN
Sep 1 23:06:44	check_reload_status: Reloading filter
Sep 1 23:06:45	kernel: ovpnc2: link state changed to UP
Sep 1 23:06:45	check_reload_status: rc.newwanip starting ovpnc2
Sep 1 23:06:47	php: rc.newwanip: rc.newwanip: Informational is starting ovpnc2.
Sep 1 23:06:47	php: rc.newwanip: rc.newwanip: on (IP address: 192.168.240.38) (interface: ) (real interface: ovpnc2).
Sep 1 23:06:47	php: rc.newwanip: pfSense package system has detected an ip change -> 192.168.240.38 ... Restarting packages.
Sep 1 23:06:47	check_reload_status: Starting packages
Sep 1 23:06:49	php: rc.start_packages: Restarting/Starting all packages.</cpu></cpu></cpu></cpu></cpu></cpu></cpu></cpu></mouse></mouse></keyboard></avocent></intel></wdc></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></wdc></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></ps></at></keyboard></generic></system></isa></pci></qpi></pci></qpi></qpi></high></at></power></serial></ata></ata></ata></ata></ata></ata></intel></isa></pci-isa></vga-compatible></acpi></acpi></intel></intel></intel></intel></intel></intel></intel></intel></intel(r)></intel(r)></acpi></acpi></intel></intel></intel></intel></intel></intel></intel></intel></intel(r)></intel(r)></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></acpi></software></version></version>

ssheikh · Sep 5, 2013, 1:58 AM

Look at all this chatter at bootup about gateways going down when in reality both gateways were up and running just fine with their monitor IP reachable.

I have completely commented out OpenVPN in rc.bootup. Yet it still starts both of the p2p client and server instances. All of this on a backup node of the HA cluster which should not even spawn the OpenVPNs because they are up and running just fine from the CARP master.

Like I said in the first post that perhaps rc.bootup should do nothing more than bring up the interfaces and setup routes and filtering.

Log is sorted with the newest on top.

Sep 4 21:24:09	php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_51.
Sep 4 21:24:08	php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_53.
Sep 4 21:24:07	check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep 4 21:24:07	check_reload_status: updating dyndns GW_51
Sep 4 21:24:06	check_reload_status: Reloading filter
Sep 4 21:24:06	check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep 4 21:24:06	check_reload_status: Restarting ipsec tunnels
Sep 4 21:24:06	check_reload_status: updating dyndns GW_53
Sep 4 21:23:57	kernel: lan_vip2: link state changed to DOWN
Sep 4 21:23:57	kernel: lan_vip2: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: opt3_vip3: link state changed to DOWN
Sep 4 21:23:57	kernel: opt3_vip3: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: opt2_vip238: link state changed to DOWN
Sep 4 21:23:57	kernel: opt2_vip238: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: opt2_vip201: link state changed to DOWN
Sep 4 21:23:57	kernel: opt2_vip201: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: opt2_vip200: link state changed to DOWN
Sep 4 21:23:57	kernel: opt2_vip200: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: opt2_vip51: link state changed to DOWN
Sep 4 21:23:57	kernel: opt2_vip51: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: opt5_vip1: link state changed to DOWN
Sep 4 21:23:57	kernel: opt5_vip1: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: wan_vip237: link state changed to DOWN
Sep 4 21:23:57	kernel: wan_vip237: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: wan_vip101: link state changed to DOWN
Sep 4 21:23:57	kernel: wan_vip101: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: wan_vip100: link state changed to DOWN
Sep 4 21:23:57	kernel: wan_vip100: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:57	kernel: wan_vip53: link state changed to DOWN
Sep 4 21:23:57	kernel: wan_vip53: MASTER -> BACKUP (more frequent advertisement received)
Sep 4 21:23:50	php: rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:50	php: rc.filter_configure_sync: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:50	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:50	php: rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:50	php: rc.filter_configure_sync: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:50	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:50	php: rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:50	php: rc.filter_configure_sync: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:50	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:50	php: rc.start_packages: Restarting/Starting all packages.
Sep 4 21:23:49	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:49	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:49	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:49	php: rc.dyndns.update: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:49	php: rc.dyndns.update: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:49	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:49	php: rc.dyndns.update: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:49	php: rc.dyndns.update: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:49	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:49	php: rc.dyndns.update: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:49	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:49	php: rc.dyndns.update: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:49	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:49	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:49	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:49	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:49	php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_51.
Sep 4 21:23:47	check_reload_status: Starting packages
Sep 4 21:23:47	php: rc.newwanip: pfSense package system has detected an ip change -> 192.168.240.41 ... Restarting packages.
Sep 4 21:23:47	php: rc.newwanip: rc.newwanip: on (IP address: 192.168.240.41) (interface: ) (real interface: ovpns1).
Sep 4 21:23:47	php: rc.newwanip: rc.newwanip: Informational is starting ovpns1.
Sep 4 21:23:47	check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep 4 21:23:47	check_reload_status: updating dyndns GW_51
Sep 4 21:23:45	php: rc.openvpn: The command '/sbin/route -q delete 192.168.240.34' returned exit code '1', the output was 'route: writing to routing socket: No such process'
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	check_reload_status: rc.newwanip starting ovpns1
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	kernel: ovpns1: link state changed to UP
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	kernel: tun2: changing name to 'ovpnc2'
Sep 4 21:23:45	php: rc.openvpn: OpenVPN: Resync client2 CA Client <-> VA Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: The command '/sbin/route -q delete 192.168.240.41' returned exit code '1', the output was 'route: writing to routing socket: No such process'
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	kernel: tun1: changing name to 'ovpns1'
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.openvpn: OpenVPN: Resync server1 CA Sevrer <-> TX Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.filter_configure_sync: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.filter_configure_sync: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.openvpn: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.filter_configure_sync: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.filter_configure_sync: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.dyndns.update: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Client)
Sep 4 21:23:45	php: rc.dyndns.update: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Client
Sep 4 21:23:45	php: rc.dyndns.update: Gateways status could not be determined, considering all as up/active. (Group: GWG_OpenVPN_Server)
Sep 4 21:23:45	php: rc.filter_configure_sync: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.dyndns.update: MONITOR: GW_51 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OpenVPN_Server
Sep 4 21:23:45	php: rc.dyndns.update: Gateways status could not be determined, considering all as up/active. (Group: GWG_OutboundNAT)
Sep 4 21:23:45	php: rc.openvpn: OpenVPN: One or more OpenVPN tunnel endpoints may have changed its IP. Reloading endpoints that may use GW_53.
Sep 4 21:23:45	php: rc.dyndns.update: MONITOR: GW_51 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:45	php: rc.dyndns.update: MONITOR: GW_53 is down, removing from routing group GWG_OutboundNAT
Sep 4 21:23:43	check_reload_status: Reloading filter
Sep 4 21:23:43	check_reload_status: Restarting OpenVPN tunnels/interfaces
Sep 4 21:23:43	check_reload_status: Restarting ipsec tunnels
Sep 4 21:23:43	check_reload_status: updating dyndns GW_53
Sep 4 21:23:38	sshlockout[92776]: sshlockout/webConfigurator v3.0 starting up
Sep 4 21:23:38	login: login on ttyv0 as root
Sep 4 21:23:34	php: rc.start_packages: Restarting/Starting all packages.
Sep 4 21:23:34	syslogd: kernel boot file is /boot/kernel/kernel
Sep 4 21:23:34	syslogd: exiting on signal 15
Sep 4 21:23:34	php: rc.bootup: Creating rrd update script
Sep 4 21:23:30	kernel: lan_vip2: link state changed to UP
Sep 4 21:23:30	check_reload_status: Updating all dyndns
Sep 4 21:23:29	kernel: opt3_vip3: link state changed to UP
Sep 4 21:23:29	kernel: opt2_vip238: link state changed to UP
Sep 4 21:23:29	kernel: opt2_vip201: link state changed to UP
Sep 4 21:23:29	kernel: opt2_vip200: link state changed to UP
Sep 4 21:23:29	kernel: opt2_vip51: link state changed to UP
Sep 4 21:23:29	kernel: opt5_vip1: link state changed to UP
Sep 4 21:23:29	kernel: wan_vip237: link state changed to UP
Sep 4 21:23:29	kernel: wan_vip101: link state changed to UP
Sep 4 21:23:29	kernel: wan_vip100: link state changed to UP
Sep 4 21:23:29	kernel: wan_vip53: link state changed to UP
Sep 4 21:23:29	php: rc.bootup: ROUTING: setting default route to 4.59.48.1
Sep 4 21:23:27	check_reload_status: Linkup starting igb0
Sep 4 21:23:27	check_reload_status: Linkup starting em1_vlan5
Sep 4 21:23:27	check_reload_status: Linkup starting em1_vlan33
Sep 4 21:23:27	check_reload_status: Linkup starting em1_vlan51
Sep 4 21:23:27	check_reload_status: Linkup starting em1
Sep 4 21:23:27	check_reload_status: Linkup starting em0
Sep 4 21:23:26	kernel: lan_vip2: link state changed to DOWN
Sep 4 21:23:26	kernel: igb0: link state changed to UP
Sep 4 21:23:26	kernel: lan_vip2: INIT -> BACKUP
Sep 4 21:23:26	kernel: opt3_vip3: link state changed to DOWN
Sep 4 21:23:26	kernel: opt2_vip238: link state changed to DOWN
Sep 4 21:23:26	kernel: opt2_vip201: link state changed to DOWN
Sep 4 21:23:26	kernel: opt2_vip200: link state changed to DOWN
Sep 4 21:23:26	kernel: opt2_vip51: link state changed to DOWN
Sep 4 21:23:26	kernel: opt5_vip1: link state changed to DOWN
Sep 4 21:23:26	kernel: em1_vlan5: link state changed to UP
Sep 4 21:23:26	kernel: em1_vlan33: link state changed to UP
Sep 4 21:23:26	kernel: opt3_vip3: INIT -> BACKUP
Sep 4 21:23:26	kernel: em1_vlan51: link state changed to UP
Sep 4 21:23:26	kernel: opt2_vip238: INIT -> BACKUP
Sep 4 21:23:26	kernel: opt2_vip201: INIT -> BACKUP
Sep 4 21:23:26	kernel: opt2_vip200: INIT -> BACKUP
Sep 4 21:23:26	kernel: opt2_vip51: INIT -> BACKUP
Sep 4 21:23:26	kernel: em1: link state changed to UP
Sep 4 21:23:26	kernel: opt5_vip1: INIT -> BACKUP
Sep 4 21:23:26	kernel: em0: link state changed to UP
Sep 4 21:23:26	kernel: wan_vip237: link state changed to DOWN
Sep 4 21:23:26	kernel: wan_vip101: link state changed to DOWN
Sep 4 21:23:26	kernel: wan_vip100: link state changed to DOWN
Sep 4 21:23:26	kernel: wan_vip53: link state changed to DOWN
Sep 4 21:23:26	kernel: igb1: link state changed to UP
Sep 4 21:23:26	kernel: wan_vip237: INIT -> BACKUP
Sep 4 21:23:26	kernel: wan_vip101: INIT -> BACKUP
Sep 4 21:23:26	kernel: wan_vip100: INIT -> BACKUP
Sep 4 21:23:26	kernel: wan_vip53: INIT -> BACKUP
Sep 4 21:23:26	check_reload_status: Linkup starting igb1
Sep 4 21:23:25	php: rc.bootup: Removing static route for monitor 4.2.2.1 and adding a new route through 66.214.150.65
Sep 4 21:23:25	php: rc.bootup: Removing static route for monitor 8.8.4.4 and adding a new route through 4.59.48.1
Sep 4 21:23:25	kernel: pflog0: promiscuous mode enabled
Sep 4 21:23:25	php: rc.bootup: Configuring CARP settings finalize...
Sep 4 21:23:25	php: rc.bootup: pfsync done in 0 seconds.
Sep 4 21:23:25	php: rc.bootup: waiting for pfsync...
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp10: changing name to 'opt2_vip201'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp9: changing name to 'wan_vip101'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp8: changing name to 'opt5_vip1'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp7: changing name to 'opt2_vip238'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp6: changing name to 'wan_vip237'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp5: changing name to 'opt2_vip200'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: carp4: changing name to 'wan_vip100'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: igb1: promiscuous mode enabled
Sep 4 21:23:24	kernel: carp3: changing name to 'wan_vip53'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: em1_vlan51: promiscuous mode enabled
Sep 4 21:23:24	kernel: carp2: changing name to 'opt2_vip51'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: em1_vlan33: promiscuous mode enabled
Sep 4 21:23:24	kernel: em1: promiscuous mode enabled
Sep 4 21:23:24	kernel: carp1: changing name to 'opt3_vip3'
Sep 4 21:23:24	kernel: ifa_add_loopback_route: insertion failed
Sep 4 21:23:24	kernel: ifa_del_loopback_route: deletion failed
Sep 4 21:23:24	kernel: igb0: promiscuous mode enabled
Sep 4 21:23:24	kernel: carp0: changing name to 'lan_vip2'
Sep 4 21:23:23	sshlockout[9893]: sshlockout/webConfigurator v3.0 starting up
Sep 4 21:23:23	sshd[9552]: Server listening on 0.0.0.0 port 22.
Sep 4 21:23:23	sshd[9552]: Server listening on :: port 22.
Sep 4 21:23:23	kernel: vlan2: changing name to 'em1_vlan51'
Sep 4 21:23:23	kernel: vlan1: changing name to 'em1_vlan5'
Sep 4 21:23:23	kernel: vlan0: changing name to 'em1_vlan33'
Sep 4 21:23:23	kernel: coretemp7: <cpu on-die="" thermal="" sensors=""> on cpu7
Sep 4 21:23:23	kernel: coretemp6: <cpu on-die="" thermal="" sensors=""> on cpu6
Sep 4 21:23:23	kernel: coretemp5: <cpu on-die="" thermal="" sensors=""> on cpu5
Sep 4 21:23:23	kernel: coretemp4: <cpu on-die="" thermal="" sensors=""> on cpu4
Sep 4 21:23:23	kernel: coretemp3: <cpu on-die="" thermal="" sensors=""> on cpu3
Sep 4 21:23:23	kernel: coretemp2: <cpu on-die="" thermal="" sensors=""> on cpu2
Sep 4 21:23:23	kernel: coretemp1: <cpu on-die="" thermal="" sensors=""> on cpu1
Sep 4 21:23:23	kernel: coretemp0: <cpu on-die="" thermal="" sensors=""> on cpu0
Sep 4 21:23:23	kernel: ZFS storage pool version 28
Sep 4 21:23:23	kernel: ZFS filesystem version 5
Sep 4 21:23:23	kernel: in /boot/loader.conf.
Sep 4 21:23:23	kernel: Consider tuning vm.kmem_size and vm.kmem_size_max
Sep 4 21:23:23	kernel: ZFS WARNING: Recommended minimum kmem_size is 512MB; expect unstable behavior.
Sep 4 21:23:23	kernel: Trying to mount root from ufs:/dev/mirror/pfSenseMirrors1a
Sep 4 21:23:23	kernel: ums1: 3 buttons and [XYZ] coordinates ID=0
Sep 4 21:23:23	kernel: ums1: <mouse rel=""> on usbus3
Sep 4 21:23:23	kernel: ums0: 3 buttons and [Z] coordinates ID=0
Sep 4 21:23:23	kernel: ums0: <mouse> on usbus3
Sep 4 21:23:23	kernel: kbd2 at ukbd0
Sep 4 21:23:23	kernel: ukbd0: <keyboard> on usbus3
Sep 4 21:23:23	kernel: ugen3.2: <avocent> at usbus3
Sep 4 21:23:23	kernel: uhub7: 6 ports with 6 removable, self powered
Sep 4 21:23:23	kernel: uhub3: 6 ports with 6 removable, self powered
Sep 4 21:23:23	kernel: Root mount waiting for: usbus7 usbus3
Sep 4 21:23:23	kernel: Root mount waiting for: usbus7 usbus3
Sep 4 21:23:23	kernel: uhub6: 2 ports with 2 removable, self powered
Sep 4 21:23:23	kernel: uhub5: 2 ports with 2 removable, self powered
Sep 4 21:23:23	kernel: uhub4: 2 ports with 2 removable, self powered
Sep 4 21:23:23	kernel: uhub2: 2 ports with 2 removable, self powered
Sep 4 21:23:23	kernel: uhub1: 2 ports with 2 removable, self powered
Sep 4 21:23:23	kernel: uhub0: 2 ports with 2 removable, self powered
Sep 4 21:23:23	kernel: Root mount waiting for: usbus7 usbus6 usbus5 usbus4 usbus3 usbus2 usbus1 usbus0
Sep 4 21:23:23	kernel: SMP: AP CPU #7 Launched!
Sep 4 21:23:23	kernel: SMP: AP CPU #4 Launched!
Sep 4 21:23:23	kernel: SMP: AP CPU #1 Launched!
Sep 4 21:23:23	kernel: SMP: AP CPU #6 Launched!
Sep 4 21:23:23	kernel: SMP: AP CPU #2 Launched!
Sep 4 21:23:23	kernel: SMP: AP CPU #5 Launched!
Sep 4 21:23:23	kernel: SMP: AP CPU #3 Launched!
Sep 4 21:23:23	kernel: GEOM_MIRROR: Device mirror/pfSenseMirror launched (2/2).
Sep 4 21:23:23	kernel: ad6: 239372MB <wdc wd2500ys-01shb1="" 20.06c06=""> at ata3-master UDMA100 SATA 1.5Gb/s
Sep 4 21:23:23	kernel: uhub7: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr=""> on usbus7
Sep 4 21:23:23	kernel: ugen7.1: <intel> at usbus7
Sep 4 21:23:23	kernel: uhub6: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus6
Sep 4 21:23:23	kernel: ugen6.1: <intel> at usbus6
Sep 4 21:23:23	kernel: uhub5: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus5
Sep 4 21:23:23	kernel: ugen5.1: <intel> at usbus5
Sep 4 21:23:23	kernel: uhub4: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus4
Sep 4 21:23:23	kernel: ugen4.1: <intel> at usbus4
Sep 4 21:23:23	kernel: uhub3: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr=""> on usbus3
Sep 4 21:23:23	kernel: ugen3.1: <intel> at usbus3
Sep 4 21:23:23	kernel: uhub2: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus2
Sep 4 21:23:23	kernel: ugen2.1: <intel> at usbus2
Sep 4 21:23:23	kernel: uhub1: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus1
Sep 4 21:23:23	kernel: ugen1.1: <intel> at usbus1
Sep 4 21:23:23	kernel: uhub0: <intel 1="" 9="" uhci="" root="" hub,="" class="" 0,="" rev="" 1.00="" 1.00,="" addr=""> on usbus0
Sep 4 21:23:23	kernel: ugen0.1: <intel> at usbus0
Sep 4 21:23:23	kernel: ad4: 239372MB <wdc wd2500ys-01shb1="" 20.06c06=""> at ata2-master UDMA100 SATA 1.5Gb/s
Sep 4 21:23:23	kernel: usbus7: 480Mbps High Speed USB v2.0
Sep 4 21:23:23	kernel: usbus6: 12Mbps Full Speed USB v1.0
Sep 4 21:23:23	kernel: usbus5: 12Mbps Full Speed USB v1.0
Sep 4 21:23:23	kernel: usbus4: 12Mbps Full Speed USB v1.0
Sep 4 21:23:23	kernel: usbus3: 480Mbps High Speed USB v2.0
Sep 4 21:23:23	kernel: usbus2: 12Mbps Full Speed USB v1.0
Sep 4 21:23:23	kernel: usbus1: 12Mbps Full Speed USB v1.0
Sep 4 21:23:23	kernel: usbus0: 12Mbps Full Speed USB v1.0
Sep 4 21:23:23	kernel: IPsec: Initialized Security Association Processing.
Sep 4 21:23:23	kernel: Timecounters tick every 1.000 msec
Sep 4 21:23:23	kernel: p4tcc7: <cpu frequency="" thermal="" control=""> on cpu7
Sep 4 21:23:23	kernel: est7: <enhanced speedstep="" frequency="" control=""> on cpu7
Sep 4 21:23:23	kernel: p4tcc6: <cpu frequency="" thermal="" control=""> on cpu6
Sep 4 21:23:23	kernel: est6: <enhanced speedstep="" frequency="" control=""> on cpu6
Sep 4 21:23:23	kernel: p4tcc5: <cpu frequency="" thermal="" control=""> on cpu5
Sep 4 21:23:23	kernel: est5: <enhanced speedstep="" frequency="" control=""> on cpu5
Sep 4 21:23:23	kernel: p4tcc4: <cpu frequency="" thermal="" control=""> on cpu4
Sep 4 21:23:23	kernel: est4: <enhanced speedstep="" frequency="" control=""> on cpu4
Sep 4 21:23:23	kernel: p4tcc3: <cpu frequency="" thermal="" control=""> on cpu3
Sep 4 21:23:23	kernel: est3: <enhanced speedstep="" frequency="" control=""> on cpu3
Sep 4 21:23:23	kernel: p4tcc2: <cpu frequency="" thermal="" control=""> on cpu2
Sep 4 21:23:23	kernel: est2: <enhanced speedstep="" frequency="" control=""> on cpu2
Sep 4 21:23:23	kernel: p4tcc1: <cpu frequency="" thermal="" control=""> on cpu1
Sep 4 21:23:23	kernel: est1: <enhanced speedstep="" frequency="" control=""> on cpu1
Sep 4 21:23:23	kernel: p4tcc0: <cpu frequency="" thermal="" control=""> on cpu0
Sep 4 21:23:23	kernel: est0: <enhanced speedstep="" frequency="" control=""> on cpu0
Sep 4 21:23:23	kernel: ppc0: cannot reserve I/O port range
Sep 4 21:23:23	kernel: atkbd0: [ITHREAD]
Sep 4 21:23:23	kernel: atkbd0: [GIANT-LOCKED]
Sep 4 21:23:23	kernel: kbd0 at atkbd0
Sep 4 21:23:23	kernel: atkbd0: <at keyboard=""> irq 1 on atkbdc0
Sep 4 21:23:23	kernel: atkbdc0: <keyboard controller="" (i8042)=""> at port 0x60,0x64 on isa0
Sep 4 21:23:23	kernel: vga0: <generic isa="" vga=""> at port 0x3d0-0x3db iomem 0xb8000-0xbffff on isa0
Sep 4 21:23:23	kernel: sc0: CGA <16 virtual consoles, flags=0x300>
Sep 4 21:23:23	kernel: sc0: <system console=""> at flags 0x100 on isa0
Sep 4 21:23:23	kernel: orm0: <isa option="" roms=""> at iomem 0xc0000-0xc7fff,0xc8000-0xc8fff,0xc9000-0xc9fff on isa0
Sep 4 21:23:23	kernel: pci254: <pci bus=""> on pcib8
Sep 4 21:23:23	kernel: pcib8: <qpi host-pci="" bridge=""> pcibus 254 on qpi0
Sep 4 21:23:23	kernel: pci255: <pci bus=""> on pcib7
Sep 4 21:23:23	kernel: pcib7: <qpi host-pci="" bridge=""> pcibus 255 on qpi0
Sep 4 21:23:23	kernel: qpi0: <qpi system="" bus=""> on motherboard
Sep 4 21:23:23	kernel: Timecounter "HPET" frequency 14318180 Hz quality 900
Sep 4 21:23:23	kernel: acpi_hpet0: <high precision="" event="" timer=""> iomem 0xfed00000-0xfed003ff on acpi0
Sep 4 21:23:23	kernel: uart1: [FILTER]
Sep 4 21:23:23	kernel: uart1: <16550 or compatible> port 0x2f8-0x2ff irq 3 on acpi0
Sep 4 21:23:23	kernel: uart0: [FILTER]
Sep 4 21:23:23	kernel: uart0: <16550 or compatible> port 0x3f8-0x3ff irq 4 flags 0x10 on acpi0
Sep 4 21:23:23	kernel: atrtc0: <at realtime="" clock=""> port 0x70-0x71 irq 8 on acpi0
Sep 4 21:23:23	kernel: acpi_button0: <power button=""> on acpi0
Sep 4 21:23:23	kernel: pci0: <serial bus,="" smbus=""> at device 31.3 (no driver attached)
Sep 4 21:23:23	kernel: ata7: [ITHREAD]
Sep 4 21:23:23	kernel: ata7: <ata channel=""> at channel 5 on atapci0
Sep 4 21:23:23	kernel: ata6: [ITHREAD]
Sep 4 21:23:23	kernel: ata6: <ata channel=""> at channel 4 on atapci0
Sep 4 21:23:23	kernel: ata5: [ITHREAD]
Sep 4 21:23:23	kernel: ata5: <ata channel=""> at channel 3 on atapci0
Sep 4 21:23:23	kernel: ata4: [ITHREAD]
Sep 4 21:23:23	kernel: ata4: <ata channel=""> at channel 2 on atapci0
Sep 4 21:23:23	kernel: ata3: [ITHREAD]
Sep 4 21:23:23	kernel: ata3: <ata channel=""> at channel 1 on atapci0
Sep 4 21:23:23	kernel: ata2: [ITHREAD]
Sep 4 21:23:23	kernel: ata2: <ata channel=""> at channel 0 on atapci0
Sep 4 21:23:23	kernel: atapci0: AHCI v1.20 controller with 6 3Gbps ports, PM not supported
Sep 4 21:23:23	kernel: atapci0: AHCI called from vendor specific driver
Sep 4 21:23:23	kernel: atapci0: [ITHREAD]
Sep 4 21:23:23	kernel: atapci0: <intel ich10="" sata300="" controller=""> port 0xa880-0xa887,0xa800-0xa803,0xa480-0xa487,0xa400-0xa403,0xa080-0xa09f mem 0xdf4da000-0xdf4da7ff irq 18 at device 31.2 on pci0
Sep 4 21:23:23	kernel: isa0: <isa bus=""> on isab0
Sep 4 21:23:23	kernel: isab0: <pci-isa bridge=""> at device 31.0 on pci0
Sep 4 21:23:23	kernel: vgapci0: <vga-compatible display=""> port 0xec00-0xec7f mem 0xdf800000-0xdfffffff,0xdf7e0000-0xdf7fffff irq 16 at device 11.0 on pci6
Sep 4 21:23:23	kernel: pci6: <acpi pci="" bus=""> on pcib6
Sep 4 21:23:23	kernel: pcib6: <acpi pci-pci="" bridge=""> at device 30.0 on pci0
Sep 4 21:23:23	kernel: usbus7: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-a=""> on ehci1
Sep 4 21:23:23	kernel: usbus7: EHCI version 1.0
Sep 4 21:23:23	kernel: ehci1: [ITHREAD]
Sep 4 21:23:23	kernel: ehci1: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-a=""> mem 0xdf4dc000-0xdf4dc3ff irq 23 at device 29.7 on pci0
Sep 4 21:23:23	kernel: usbus6: <intel 82801ji="" (ich10)="" usb="" controller="" usb-c=""> on uhci5
Sep 4 21:23:23	kernel: uhci5: LegSup = 0x2f00
Sep 4 21:23:23	kernel: uhci5: [ITHREAD]
Sep 4 21:23:23	kernel: uhci5: <intel 82801ji="" (ich10)="" usb="" controller="" usb-c=""> port 0xac00-0xac1f irq 21 at device 29.2 on pci0
Sep 4 21:23:23	kernel: usbus5: <intel 82801ji="" (ich10)="" usb="" controller="" usb-b=""> on uhci4
Sep 4 21:23:23	kernel: uhci4: LegSup = 0x2f00
Sep 4 21:23:23	kernel: uhci4: [ITHREAD]
Sep 4 21:23:23	kernel: uhci4: <intel 82801ji="" (ich10)="" usb="" controller="" usb-b=""> port 0xb400-0xb41f irq 22 at device 29.1 on pci0
Sep 4 21:23:23	kernel: usbus4: <intel 82801ji="" (ich10)="" usb="" controller="" usb-a=""> on uhci3
Sep 4 21:23:23	kernel: uhci3: LegSup = 0x2f00
Sep 4 21:23:23	kernel: uhci3: [ITHREAD]
Sep 4 21:23:23	kernel: uhci3: <intel 82801ji="" (ich10)="" usb="" controller="" usb-a=""> port 0xb480-0xb49f irq 23 at device 29.0 on pci0
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 7 to cpu 7
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 6 to cpu 6
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 5 to cpu 5
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 4 to cpu 4
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 3 to cpu 3
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 2 to cpu 2
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 1 to cpu 1
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Bound queue 0 to cpu 0
Sep 4 21:23:23	kernel: igb1: [ITHREAD]
Sep 4 21:23:23	kernel: igb1: Using MSIX interrupts with 9 vectors
Sep 4 21:23:23	kernel: igb1: <intel(r) 1000="" pro="" network="" connection="" version="" -="" 2.3.1=""> port 0xd880-0xd89f mem 0xdf660000-0xdf67ffff,0xdf640000-0xdf65ffff,0xdf63c000-0xdf63ffff irq 17 at device 0.1 on pci5
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 7 to cpu 7
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 6 to cpu 6
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 5 to cpu 5
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 4 to cpu 4
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 3 to cpu 3
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 2 to cpu 2
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 1 to cpu 1
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Bound queue 0 to cpu 0
Sep 4 21:23:23	kernel: igb0: [ITHREAD]
Sep 4 21:23:23	kernel: igb0: Using MSIX interrupts with 9 vectors
Sep 4 21:23:23	kernel: igb0: <intel(r) 1000="" pro="" network="" connection="" version="" -="" 2.3.1=""> port 0xdc00-0xdc1f mem 0xdf6e0000-0xdf6fffff,0xdf6c0000-0xdf6dffff,0xdf6bc000-0xdf6bffff irq 16 at device 0.0 on pci5
Sep 4 21:23:23	kernel: pci5: <acpi pci="" bus=""> on pcib5
Sep 4 21:23:23	kernel: pcib5: <acpi pci-pci="" bridge=""> irq 17 at device 28.0 on pci0
Sep 4 21:23:23	kernel: usbus3: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-b=""> on ehci0
Sep 4 21:23:23	kernel: usbus3: EHCI version 1.0
Sep 4 21:23:23	kernel: ehci0: [ITHREAD]
Sep 4 21:23:23	kernel: ehci0: <intel 82801ji="" (ich10)="" usb="" 2.0="" controller="" usb-b=""> mem 0xdf4de000-0xdf4de3ff irq 20 at device 26.7 on pci0
Sep 4 21:23:23	kernel: usbus2: <intel 82801ji="" (ich10)="" usb="" controller="" usb-f=""> on uhci2
Sep 4 21:23:23	kernel: uhci2: LegSup = 0x2f00
Sep 4 21:23:23	kernel: uhci2: [ITHREAD]
Sep 4 21:23:23	kernel: uhci2: <intel 82801ji="" (ich10)="" usb="" controller="" usb-f=""> port 0xb800-0xb81f irq 21 at device 26.2 on pci0
Sep 4 21:23:23	kernel: usbus1: <intel 82801ji="" (ich10)="" usb="" controller="" usb-e=""> on uhci1
Sep 4 21:23:23	kernel: uhci1: LegSup = 0x2f00
Sep 4 21:23:23	kernel: uhci1: [ITHREAD]
Sep 4 21:23:23	kernel: uhci1: <intel 82801ji="" (ich10)="" usb="" controller="" usb-e=""> port 0xb880-0xb89f irq 22 at device 26.1 on pci0
Sep 4 21:23:23	kernel: usbus0: <intel 82801ji="" (ich10)="" usb="" controller="" usb-d=""> on uhci0</intel></intel></intel></intel></intel></intel></intel></acpi></acpi></intel(r)></intel(r)></intel></intel></intel></intel></intel></intel></intel></intel></acpi></acpi></vga-compatible></pci-isa></isa></intel></ata></ata></ata></ata></ata></ata></serial></power></at></high></qpi></qpi></pci></qpi></pci></isa></system></generic></keyboard></at></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></enhanced></cpu></wdc></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></intel></wdc></avocent></keyboard></mouse></mouse></cpu></cpu></cpu></cpu></cpu></cpu></cpu></cpu>

phil.davis · Sep 5, 2013, 2:14 AM

I guess this is true of all use cases - every OpenVPN server or client is bound to 1 or more real interfaces (usually a WAN, can be a LAN, could be using a VLAN, can be a selection of an interface from a gateway group…). When the real interface comes up rc.linkup, rc.newwanip... get called anyway, and they give a kick to the OpenVPN instances that use the real interface.
Thus all OpenVPN should come up without being directly called in rc.bootup
Is this analysis correct?
If so, should we remove OpenVPN startup from rc.bootup?

(Side note: I don't use CARP, have enough trouble getting power for 1 box at each site. Issues with OpenVPN starting on CARP backup need to be fixed also - I guess there are more points in the code that need to check for CARP master/backup status)

eri-- · Sep 5, 2013, 6:53 AM

If you have your openvpn assigned will be started on the boot.

For 2.1 this should suffice but looking at ssheikh system log i think you have issues with the static routes or similar due to some kernel setup routines failing.

ssheikh · Sep 6, 2013, 1:10 AM

The only two static routes in there are a result of two of DNS servers configured to use non-default gateway.

There seem to be too many things stepping over each other in the bootup process for it happen cleanly specially in a CARP HA cluster environment.

I had one bootup instance in which check_reload_status didn't start in /etc/rc (because I commented it out there) so while rc.bootup was running, it wound up firing off 3 instances check_reload_status because (I guess) the send_event functions in util.inc attempt to start check_reload_status. And it attempts to start it 3 times without ever waiting long enough in each iteration to actually allow check_reload_status to really start executing.

At this point I am changing my configuration around to make sure that I am not using gateway groups for anything other than switching the default route and making sure that services are bound to actual interfaces and not to CARP VIPs.

As for my full mesh OpenVPN tunnels, I am now planning on the primary at each site to connect to primary at all the other sites and the backup at each site to connect to backup at all the other sites and see if I can make my routing decisions through OSPF. For the client to reestablish a connection to the server when the server DefGW switches I plan on using an extra remote statement in the client. On the server side I will have two servers for each remote site, one each bound to each of the WAN interfaces.

The moment I try to bind OpenVPN to a CARP VIP or a GW group, unpredictable things start happening during the bootup process. So I am trying to keep all local services off of VIPs and GWGs in the hope to get this setup to be a bit more stable.

individual-it · Sep 6, 2013, 4:44 AM

After we added VLANs into our system last week we could not bring it up correctly. After the boot there were no GUI, but we easily could restart that by SSH, so then it looked like everything worked but the routing didn't. Outside it got darker and darker and we got pretty hungry while we tried to find the mistake in our configuration. And after a long time we found out that it wasn't a mistake in the configuration but the firewall and the routing processes didn't start. They crashed during boot.
The only quick and dirty solution that came up into our tired minds was to put sleep() loops in the rc.bootup so we would have a running system the next morning.

So the changes phil was talking about is an improvement of this solution. It makes it more general and configurable.
I'm just made a pull request out of the changes: https://github.com/pfsense/pfsense/pull/798

I understand that this solution might not be the most nicest and sure enough you can call it a kludge. But I would also argue its a bug fix as 2.1 is supposed to run on a 256MB system, but does not in every case.

We cannot start our Alix boards without this changes. So please consider to take it into 2.1.
If you don't want to have this hack in the master branch I'm happy to rewrite and resubmit it to 2.1. But I suspect you just could merge the changes automatically into 2.1 as every change is tested on 2.1 systems

php_fpm should help.
And the other thing I've noticed that we have set PHP memory_limit to 128M. Do we need so much, or can we reduce that?

eri-- · Sep 6, 2013, 7:35 AM

@individual-it:

After we added VLANs into our system last week we could not bring it up correctly. After the boot there were no GUI, but we easily could restart that by SSH, so then it looked like everything worked but the routing didn't. Outside it got darker and darker and we got pretty hungry while we tried to find the mistake in our configuration. And after a long time we found out that it wasn't a mistake in the configuration but the firewall and the routing processes didn't start. They crashed during boot.
The only quick and dirty solution that came up into our tired minds was to put sleep() loops in the rc.bootup so we would have a running system the next morning.

So the changes phil was talking about is an improvement of this solution. It makes it more general and configurable.
I'm just made a pull request out of the changes: https://github.com/pfsense/pfsense/pull/798

I understand that this solution might not be the most nicest and sure enough you can call it a kludge. But I would also argue its a bug fix as 2.1 is supposed to run on a 256MB system, but does not in every case.

We cannot start our Alix boards without this changes. So please consider to take it into 2.1.
If you don't want to have this hack in the master branch I'm happy to rewrite and resubmit it to 2.1. But I suspect you just could merge the changes automatically into 2.1 as every change is tested on 2.1 systems

php_fpm should help.
And the other thing I've noticed that we have set PHP memory_limit to 128M. Do we need so much, or can we reduce that?

Usually as it is for 2.1 you probably are doing too much on one system(just a guess).
If you want this to be put as priority on the fix list i would rather push through commercial support to fix the low memory platforms.
The only way to fix this is controlling php forking and i know cause i have a lot of lowmem system myself.

Any other solution like yours with sleep is not sustainable since the behavior is unpredictable.

individual-it · Sep 9, 2013, 4:16 AM

Hi ermal,
thanks for your quick answer.

Yes we are doing quite much on the system, but as we are sitting in Nepal we have no chance at the moment to get an other one with more RAM. We striped down to the minimum of services we need but still have problems. And i doubt our charity can pay for commercial support.

Could you explain why you think this fix is unpredictable? By default it does not do anything, just if the administrator enters values in the "Maximum delay time" field it will be active.

I agree with you that the problem is PHP and not the services them self. But even more that is an argument for me to use the sleeping solution as an temporary fix. We basically wait till the one php process is finished before we start a new one.

Controlling the PHP forking would be of course a much better way of solving this problem. But as you told your self it's to late to have that change in 2.1. That would mean there would be no solution till 2.2 comes.

What about having a workaround in 2.1 and going for a proper solution in 2.2?