Long delay during boot
-
I had issues with the snapshot from 8th (built on Sat Nov 08 15:38:47 CST 2014) with packages and long reboot after config restore. When the box finally booted, it had menu items for packages, but no actual packages installed. Checking Packages -> Installed showed no packages installed.
Bootup also got stuck on "Configuring Firewall." for ~7 minutes. Initially when upgrading from ~27th Sep to 8th Nov I was patient enough to wait for about 5 minutes before I did a reinstall of a snapshot from 23th Sep that I had ready on a USB stick -> upgrade -> Restore and again it took ages to boot up.
Here's the system.log from my last boot.
Nov 9 17:17:01 pfsense syslogd: kernel boot file is /boot/kernel/kernel Nov 9 17:17:01 pfsense kernel: pflog0: promiscuous mode disabled Nov 9 17:17:01 pfsense kernel: Waiting (max 60 seconds) for system process `vnlru' to stop...done Nov 9 17:17:01 pfsense kernel: Waiting (max 60 seconds) for system process `bufdaemon' to stop...done Nov 9 17:17:01 pfsense kernel: Waiting (max 60 seconds) for system process `syncer' to stop... Nov 9 17:17:01 pfsense kernel: Syncing disks, vnodes remaining...0 0 done Nov 9 17:17:01 pfsense kernel: All buffers synced. Nov 9 17:17:01 pfsense kernel: Copyright (c) 1992-2014 The FreeBSD Project. Nov 9 17:17:01 pfsense kernel: Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994 Nov 9 17:17:01 pfsense kernel: The Regents of the University of California. All rights reserved. Nov 9 17:17:01 pfsense kernel: FreeBSD is a registered trademark of The FreeBSD Foundation. Nov 9 17:17:01 pfsense kernel: FreeBSD 10.1-RC4-p1 #0 a7c1e8b(releng/10.1)-dirty: Sat Nov 8 16:19:59 CST 2014 Nov 9 17:17:01 pfsense kernel: root@pfsense-22-amd64-builder:/usr/obj.amd64/usr/pfSensesrc/src/sys/pfSense_SMP.10 amd64 Nov 9 17:17:01 pfsense kernel: FreeBSD clang version 3.4.1 (tags/RELEASE_34/dot1-final 208032) 20140512 Nov 9 17:17:01 pfsense kernel: CPU: Intel(R) Pentium(R) CPU G630T @ 2.30GHz (2294.84-MHz K8-class CPU) Nov 9 17:17:01 pfsense kernel: Origin = "GenuineIntel" Id = 0x206a7 Family = 0x6 Model = 0x2a Stepping = 7 Nov 9 17:17:01 pfsense kernel: Features=0xbfebfbff <fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,htt,tm,pbe>Nov 9 17:17:01 pfsense kernel: Features2=0xd9ae3bf <sse3,pclmulqdq,dtes64,mon,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,pcid,sse4.1,sse4.2,popcnt,tscdlt,xsave,osxsave>Nov 9 17:17:01 pfsense kernel: AMD Features=0x28100800 <syscall,nx,rdtscp,lm>Nov 9 17:17:01 pfsense kernel: AMD Features2=0x1 <lahf>Nov 9 17:17:01 pfsense kernel: VT-x: PAT,HLT,MTF,PAUSE,EPT,UG,VPID Nov 9 17:17:01 pfsense kernel: TSC: P-state invariant, performance statistics Nov 9 17:17:01 pfsense kernel: real memory = 8589934592 (8192 MB) Nov 9 17:17:01 pfsense kernel: avail memory = 8185839616 (7806 MB) Nov 9 17:17:01 pfsense kernel: Event timer "LAPIC" quality 600 Nov 9 17:17:01 pfsense kernel: ACPI APIC Table: <intel s1200kp="">Nov 9 17:17:01 pfsense kernel: FreeBSD/SMP: Multiprocessor System Detected: 2 CPUs Nov 9 17:17:01 pfsense kernel: FreeBSD/SMP: 1 package(s) x 2 core(s) Nov 9 17:17:01 pfsense kernel: cpu0 (BSP): APIC ID: 0 Nov 9 17:17:01 pfsense kernel: cpu1 (AP): APIC ID: 2 Nov 9 17:17:01 pfsense kernel: ioapic0 <version 2.0="">irqs 0-23 on motherboard Nov 9 17:17:01 pfsense kernel: wlan: mac acl policy registered Nov 9 17:17:01 pfsense kernel: iwi_bss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi/. Nov 9 17:17:01 pfsense kernel: iwi_bss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Nov 9 17:17:01 pfsense kernel: module_register_init: MOD_LOAD (iwi_bss_fw, 0xffffffff8062dd90, 0) error 1 Nov 9 17:17:01 pfsense kernel: iwi_ibss: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi/. Nov 9 17:17:01 pfsense kernel: iwi_ibss: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Nov 9 17:17:01 pfsense kernel: module_register_init: MOD_LOAD (iwi_ibss_fw, 0xffffffff8062de40, 0) error 1 Nov 9 17:17:01 pfsense kernel: iwi_monitor: You need to read the LICENSE file in /usr/share/doc/legal/intel_iwi/. Nov 9 17:17:01 pfsense kernel: iwi_monitor: If you agree with the license, set legal.intel_iwi.license_ack=1 in /boot/loader.conf. Nov 9 17:17:01 pfsense kernel: module_register_init: MOD_LOAD (iwi_monitor_fw, 0xffffffff8062def0, 0) error 1 Nov 9 17:17:01 pfsense kernel: random: <software, yarrow="">initialized Nov 9 17:17:01 pfsense kernel: kbd1 at kbdmux0 Nov 9 17:17:01 pfsense kernel: cryptosoft0: <software crypto="">on motherboard Nov 9 17:17:01 pfsense kernel: padlock0: No ACE support. Nov 9 17:17:01 pfsense kernel: acpi0: <intel s1200kp="">on motherboard Nov 9 17:17:01 pfsense kernel: acpi0: Power Button (fixed) Nov 9 17:17:01 pfsense kernel: cpu0: <acpi cpu="">on acpi0 Nov 9 17:17:01 pfsense kernel: cpu1: <acpi cpu="">on acpi0 Nov 9 17:17:01 pfsense kernel: attimer0: <at timer="">port 0x40-0x43 irq 0 on acpi0 Nov 9 17:17:01 pfsense kernel: Timecounter "i8254" frequency 1193182 Hz quality 0 Nov 9 17:17:01 pfsense kernel: Event timer "i8254" frequency 1193182 Hz quality 100 Nov 9 17:17:01 pfsense kernel: atrtc0: <at realtime="" clock="">port 0x70-0x71 irq 8 on acpi0 Nov 9 17:17:01 pfsense kernel: Event timer "RTC" frequency 32768 Hz quality 0 Nov 9 17:17:01 pfsense kernel: hpet0: <high precision="" event="" timer="">iomem 0xfed00000-0xfed003ff on acpi0 Nov 9 17:17:01 pfsense kernel: Timecounter "HPET" frequency 14318180 Hz quality 950 Nov 9 17:17:01 pfsense kernel: Event timer "HPET" frequency 14318180 Hz quality 550 Nov 9 17:17:01 pfsense kernel: Event timer "HPET1" frequency 14318180 Hz quality 440 Nov 9 17:17:01 pfsense kernel: Event timer "HPET2" frequency 14318180 Hz quality 440 Nov 9 17:17:01 pfsense kernel: Event timer "HPET3" frequency 14318180 Hz quality 440 Nov 9 17:17:01 pfsense kernel: Event timer "HPET4" frequency 14318180 Hz quality 440 Nov 9 17:17:01 pfsense kernel: Event timer "HPET5" frequency 14318180 Hz quality 440 Nov 9 17:17:01 pfsense kernel: Event timer "HPET6" frequency 14318180 Hz quality 440 Nov 9 17:17:01 pfsense kernel: Timecounter "ACPI-fast" frequency 3579545 Hz quality 900 Nov 9 17:17:01 pfsense kernel: acpi_timer0: <24-bit timer at 3.579545MHz> port 0x408-0x40b on acpi0 Nov 9 17:17:01 pfsense kernel: pcib0: <acpi host-pci="" bridge="">port 0xcf8-0xcff on acpi0 Nov 9 17:17:01 pfsense kernel: pci0: <acpi pci="" bus="">on pcib0 Nov 9 17:17:01 pfsense kernel: vgapci0: <vga-compatible display="">port 0xf000-0xf03f mem 0xfe000000-0xfe3fffff,0xe0000000-0xefffffff irq 16 at device 2.0 on pci0 Nov 9 17:17:01 pfsense kernel: agp0: <sandybridge desktop="" gt1="" ig="">on vgapci0 Nov 9 17:17:01 pfsense kernel: agp0: aperture size is 256M, detected 65532k stolen memory Nov 9 17:17:01 pfsense kernel: vgapci0: Boot video device Nov 9 17:17:01 pfsense kernel: pci0: <simple comms="">at device 22.0 (no driver attached) Nov 9 17:17:01 pfsense kernel: em0: <intel(r) 1000="" pro="" network="" connection="" 7.4.2="">port 0xf080-0xf09f mem 0xfe500000-0xfe51ffff,0xfe524000-0xfe524fff irq 20 at device 25.0 on pci0 Nov 9 17:17:01 pfsense kernel: em0: Using an MSI interrupt Nov 9 17:17:01 pfsense kernel: ehci0: <ehci (generic)="" usb="" 2.0="" controller="">mem 0xfe523000-0xfe5233ff irq 16 at device 26.0 on pci0 Nov 9 17:17:01 pfsense kernel: usbus0: EHCI version 1.0 Nov 9 17:17:01 pfsense kernel: usbus0 on ehci0 Nov 9 17:17:01 pfsense kernel: pcib1: <acpi pci-pci="" bridge="">irq 17 at device 28.0 on pci0 Nov 9 17:17:01 pfsense kernel: pci1: <acpi pci="" bus="">on pcib1 Nov 9 17:17:01 pfsense kernel: pcib2: <acpi pci-pci="" bridge="">irq 16 at device 28.1 on pci0 Nov 9 17:17:01 pfsense kernel: pci2: <acpi pci="" bus="">on pcib2 Nov 9 17:17:01 pfsense kernel: em1: <intel(r) 1000="" pro="" network="" connection="" 7.4.2="">port 0xe000-0xe01f mem 0xfe400000-0xfe41ffff,0xfe420000-0xfe423fff irq 17 at device 0.0 on pci2 Nov 9 17:17:01 pfsense kernel: em1: Using MSIX interrupts with 3 vectors Nov 9 17:17:01 pfsense kernel: ehci1: <ehci (generic)="" usb="" 2.0="" controller="">mem 0xfe522000-0xfe5223ff irq 23 at device 29.0 on pci0 Nov 9 17:17:01 pfsense kernel: usbus1: EHCI version 1.0 Nov 9 17:17:01 pfsense kernel: usbus1 on ehci1 Nov 9 17:17:01 pfsense kernel: pcib3: <acpi pci-pci="" bridge="">at device 30.0 on pci0 Nov 9 17:17:01 pfsense kernel: pci3: <acpi pci="" bus="">on pcib3 Nov 9 17:17:01 pfsense kernel: isab0: <pci-isa bridge="">at device 31.0 on pci0 Nov 9 17:17:01 pfsense kernel: isa0: <isa bus="">on isab0 Nov 9 17:17:01 pfsense kernel: ahci0: <intel cougar="" point="" ahci="" sata="" controller="">port 0xf0d0-0xf0d7,0xf0c0-0xf0c3,0xf0b0-0xf0b7,0xf0a0-0xf0a3,0xf060-0xf07f mem 0xfe521000-0xfe5217ff irq 19 at device 31.2 on pci0 Nov 9 17:17:01 pfsense kernel: ahci0: AHCI v1.30 with 6 6Gbps ports, Port Multiplier not supported Nov 9 17:17:01 pfsense kernel: ahcich0: <ahci channel="">at channel 0 on ahci0 Nov 9 17:17:01 pfsense kernel: ahcich1: <ahci channel="">at channel 1 on ahci0 Nov 9 17:17:01 pfsense kernel: ahcich2: <ahci channel="">at channel 2 on ahci0 Nov 9 17:17:01 pfsense kernel: ahcich3: <ahci channel="">at channel 3 on ahci0 Nov 9 17:17:01 pfsense kernel: ahciem0: <ahci enclosure="" management="" bridge="">on ahci0 Nov 9 17:17:01 pfsense kernel: acpi_button0: <power button="">on acpi0 Nov 9 17:17:01 pfsense kernel: sc0: <system console="">at flags 0x100 on isa0 Nov 9 17:17:01 pfsense kernel: sc0: VGA <16 virtual consoles, flags=0x300> Nov 9 17:17:01 pfsense kernel: vga0: <generic isa="" vga="">at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0 Nov 9 17:17:01 pfsense kernel: atkbdc0: <keyboard controller="" (i8042)="">at port 0x60,0x64 on isa0 Nov 9 17:17:01 pfsense kernel: atkbd0: <at keyboard="">irq 1 on atkbdc0 Nov 9 17:17:01 pfsense kernel: kbd0 at atkbd0 Nov 9 17:17:01 pfsense kernel: atkbd0: [GIANT-LOCKED] Nov 9 17:17:01 pfsense kernel: ppc0: cannot reserve I/O port range Nov 9 17:17:01 pfsense kernel: est0: <enhanced speedstep="" frequency="" control="">on cpu0 Nov 9 17:17:01 pfsense kernel: est1: <enhanced speedstep="" frequency="" control="">on cpu1 Nov 9 17:17:01 pfsense kernel: Timecounters tick every 1.000 msec Nov 9 17:17:01 pfsense kernel: IPsec: Initialized Security Association Processing. Nov 9 17:17:01 pfsense kernel: random: unblocking device. Nov 9 17:17:01 pfsense kernel: usbus0: 480Mbps High Speed USB v2.0 Nov 9 17:17:01 pfsense kernel: usbus1: 480Mbps High Speed USB v2.0 Nov 9 17:17:01 pfsense kernel: ugen1.1: <intel>at usbus1 Nov 9 17:17:01 pfsense kernel: uhub0: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr="">on usbus1 Nov 9 17:17:01 pfsense kernel: ugen0.1: <intel>at usbus0 Nov 9 17:17:01 pfsense kernel: uhub1: <intel 1="" 9="" ehci="" root="" hub,="" class="" 0,="" rev="" 2.00="" 1.00,="" addr="">on usbus0 Nov 9 17:17:01 pfsense kernel: uhub0: 2 ports with 2 removable, self powered Nov 9 17:17:01 pfsense kernel: uhub1: 2 ports with 2 removable, self powered Nov 9 17:17:01 pfsense kernel: ugen1.2: <vendor 0x8087="">at usbus1 Nov 9 17:17:01 pfsense kernel: uhub2: <vendor 2="" 9="" 0x8087="" product="" 0x0024,="" class="" 0,="" rev="" 2.00="" 0.00,="" addr="">on usbus1 Nov 9 17:17:01 pfsense kernel: ugen0.2: <vendor 0x8087="">at usbus0 Nov 9 17:17:01 pfsense kernel: uhub3: <vendor 2="" 9="" 0x8087="" product="" 0x0024,="" class="" 0,="" rev="" 2.00="" 0.00,="" addr="">on usbus0 Nov 9 17:17:01 pfsense kernel: uhub3: 6 ports with 6 removable, self powered Nov 9 17:17:01 pfsense kernel: uhub2: 8 ports with 8 removable, self powered Nov 9 17:17:01 pfsense kernel: ugen1.3: <vendor 0x04d9="">at usbus1 Nov 9 17:17:01 pfsense kernel: ukbd0: <vendor 0="" 3="" 0x04d9="" usb="" keyboard,="" class="" 0,="" rev="" 1.10="" 3.10,="" addr="">on usbus1 Nov 9 17:17:01 pfsense kernel: kbd2 at ukbd0 Nov 9 17:17:01 pfsense kernel: uhid0: <vendor 0="" 3="" 0x04d9="" usb="" keyboard,="" class="" 0,="" rev="" 1.10="" 3.10,="" addr="">on usbus1 Nov 9 17:17:01 pfsense kernel: ses0 at ahciem0 bus 0 scbus4 target 0 lun 0 Nov 9 17:17:01 pfsense kernel: ses0: <ahci sgpio="" enclosure="" 1.00="" 0001="">SEMB S-E-S 2.00 device Nov 9 17:17:01 pfsense kernel: ses0: SEMB SES Device Nov 9 17:17:01 pfsense kernel: ada0 at ahcich0 bus 0 scbus0 target 0 lun 0 Nov 9 17:17:01 pfsense kernel: ada0: <kingston sv300s37a60g="" 505abbf0="">ATA-8 SATA 3.x device Nov 9 17:17:01 pfsense kernel: ada0: Serial Number 50026B72310717D4 Nov 9 17:17:01 pfsense kernel: ada0: 600.000MB/s transfers (SATA 3.x, UDMA6, PIO 8192bytes) Nov 9 17:17:01 pfsense kernel: ada0: Command Queueing enabled Nov 9 17:17:01 pfsense kernel: ada0: 57241MB (117231408 512 byte sectors: 16H 63S/T 16383C) Nov 9 17:17:01 pfsense kernel: ada0: Previously was known as ad4 Nov 9 17:17:01 pfsense kernel: SMP: AP CPU #1 Launched! Nov 9 17:17:01 pfsense kernel: Timecounter "TSC-low" frequency 1147421898 Hz quality 1000 Nov 9 17:17:01 pfsense kernel: Trying to mount root from ufs:/dev/ada0s1a [rw]... Nov 9 17:17:01 pfsense kernel: coretemp0: <cpu on-die="" thermal="" sensors="">on cpu0 Nov 9 17:17:01 pfsense kernel: coretemp1: <cpu on-die="" thermal="" sensors="">on cpu1 Nov 9 17:17:02 pfsense sshd[8870]: Server listening on :: port 22. Nov 9 17:17:02 pfsense sshd[8870]: Server listening on 0.0.0.0 port 22. Nov 9 17:17:02 pfsense sshlockout[9141]: sshlockout/webConfigurator v3.0 starting up Nov 9 17:17:03 pfsense kernel: Nov 9 17:17:03 pfsense kernel: em0: link state changed to UP Nov 9 17:17:03 pfsense devd: Executing '/usr/local/sbin/pfSctl -c 'interface linkup start em0'' Nov 9 17:17:03 pfsense check_reload_status: Linkup starting em0 Nov 9 17:17:08 pfsense check_reload_status: rc.newwanip starting em0 Nov 9 17:17:09 pfsense php: rc.bootup: Resyncing OpenVPN instances. Nov 9 17:17:09 pfsense kernel: done. Nov 9 17:17:09 pfsense dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory. Nov 9 17:17:09 pfsense kernel: Nov 9 17:17:09 pfsense kernel: tun1: changing name to 'ovpns1' Nov 9 17:17:09 pfsense kernel: tun2: changing name to 'ovpns2' Nov 9 17:17:09 pfsense kernel: ovpns1: link state changed to UP Nov 9 17:17:09 pfsense check_reload_status: rc.newwanip starting ovpns1 Nov 9 17:17:09 pfsense kernel: pflog0: promiscuous mode enabled Nov 9 17:17:09 pfsense kernel: ovpns2: link state changed to UP Nov 9 17:17:09 pfsense check_reload_status: rc.newwanip starting ovpns2 Nov 9 17:17:10 pfsense php-fpm[284]: /rc.newwanip: rc.newwanip: Info: starting on em0. Nov 9 17:17:10 pfsense php-fpm[284]: /rc.newwanip: rc.newwanip: on (IP address: 84.MY.WAN.IP) (interface: WAN[wan]) (real interface: em0). Nov 9 17:17:10 pfsense php-fpm[284]: /rc.newwanip: IP has changed, killing states on former IP 0.0.0.0. Nov 9 17:17:10 pfsense dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory. Nov 9 17:17:10 pfsense php-fpm[284]: /rc.newwanip: ROUTING: setting default route to 84.DDD.NN.1 Nov 9 17:17:10 pfsense php-fpm[284]: /rc.newwanip: RRD create failed exited with 1, the error is: ERROR: creating '/var/db/rrd/WAN_DHCP-quality.rrd': No such file or directory Nov 9 17:17:10 pfsense php-fpm[25534]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Nov 9 17:17:10 pfsense php-fpm[25534]: /rc.newwanip: rc.newwanip: on (IP address: 192.OPEN.VPN.IP2) (interface: []) (real interface: ovpns1). Nov 9 17:17:10 pfsense check_reload_status: Reloading filter Nov 9 17:17:10 pfsense php-fpm[25534]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.OPEN.VPN.IP2 - Restarting packages. Nov 9 17:17:10 pfsense check_reload_status: Starting packages Nov 9 17:17:10 pfsense php-fpm[25534]: /rc.newwanip: rc.newwanip: Info: starting on ovpns2. Nov 9 17:17:10 pfsense php-fpm[25534]: /rc.newwanip: rc.newwanip: on (IP address: 192.OPEN.VPN.IP1) (interface: []) (real interface: ovpns2). Nov 9 17:17:10 pfsense check_reload_status: Reloading filter Nov 9 17:17:10 pfsense php-fpm[25534]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.OPEN.VPN.IP1 - Restarting packages. Nov 9 17:17:10 pfsense check_reload_status: Starting packages Nov 9 17:17:12 pfsense php-fpm[284]: /rc.newwanip: phpDynDNS (my.dyn.dns.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Nov 9 17:17:13 pfsense php-fpm[29425]: /rc.start_packages: Restarting/Starting all packages. Nov 9 17:17:13 pfsense php-fpm[29425]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[29425]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[29425]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[29425]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[284]: /rc.newwanip: Resyncing OpenVPN instances for interface WAN. Nov 9 17:17:13 pfsense SnortStartup[34548]: Snort START for SnortLAN(330_em1)... Nov 9 17:17:13 pfsense kernel: ovpns1: link state changed to DOWN Nov 9 17:17:13 pfsense check_reload_status: Reloading filter Nov 9 17:17:13 pfsense snort[34589]: FATAL ERROR: OpenAlertFile() => fopen() alert file /var/log/snort/snort_em1330/alert: No such file or directory Nov 9 17:17:13 pfsense kernel: ovpns2: link state changed to DOWN Nov 9 17:17:13 pfsense kernel: ovpns1: link state changed to UP Nov 9 17:17:13 pfsense check_reload_status: rc.newwanip starting ovpns1 Nov 9 17:17:13 pfsense php-fpm[284]: /rc.newwanip: Creating rrd update script Nov 9 17:17:13 pfsense kernel: ovpns2: link state changed to UP Nov 9 17:17:13 pfsense check_reload_status: rc.newwanip starting ovpns2 Nov 9 17:17:13 pfsense php-fpm[55608]: /rc.start_packages: Restarting/Starting all packages. Nov 9 17:17:13 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:13 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:14 pfsense SnortStartup[59780]: Snort START for SnortLAN(330_em1)... Nov 9 17:17:14 pfsense snort[59812]: FATAL ERROR: OpenAlertFile() => fopen() alert file /var/log/snort/snort_em1330/alert: No such file or directory Nov 9 17:17:14 pfsense php-fpm[55608]: /rc.newwanip: rc.newwanip: Info: starting on ovpns1. Nov 9 17:17:14 pfsense php-fpm[55608]: /rc.newwanip: rc.newwanip: on (IP address: 192.OPEN.VPN.IP2) (interface: []) (real interface: ovpns1). Nov 9 17:17:14 pfsense php-fpm[55608]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.OPEN.VPN.IP2 - Restarting packages. Nov 9 17:17:14 pfsense check_reload_status: Starting packages Nov 9 17:17:14 pfsense php-fpm[55608]: /rc.newwanip: rc.newwanip: Info: starting on ovpns2. Nov 9 17:17:14 pfsense php-fpm[55608]: /rc.newwanip: rc.newwanip: on (IP address: 192.OPEN.VPN.IP1) (interface: []) (real interface: ovpns2). Nov 9 17:17:14 pfsense php-fpm[55608]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - -> 192.OPEN.VPN.IP1 - Restarting packages. Nov 9 17:17:14 pfsense check_reload_status: Starting packages Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: Restarting/Starting all packages. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense SnortStartup[82584]: Snort START for SnortLAN(330_em1)... Nov 9 17:17:15 pfsense snort[82877]: FATAL ERROR: OpenAlertFile() => fopen() alert file /var/log/snort/snort_em1330/alert: No such file or directory Nov 9 17:17:15 pfsense php-fpm[284]: /rc.newwanip: pfSense package system has detected an IP change or dynamic WAN reconnection - 0.0.0.0 -> 84.MY.WAN.IP - Restarting packages. Nov 9 17:17:15 pfsense check_reload_status: Starting packages Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: Restarting/Starting all packages. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense php-fpm[55608]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:17:15 pfsense SnortStartup[97882]: Snort START for SnortLAN(330_em1)... Nov 9 17:17:15 pfsense snort[98213]: FATAL ERROR: OpenAlertFile() => fopen() alert file /var/log/snort/snort_em1330/alert: No such file or directory Nov 9 17:17:16 pfsense kernel: em1: link state changed to UP Nov 9 17:17:16 pfsense devd: Executing '/usr/local/sbin/pfSctl -c 'interface linkup start em1'' Nov 9 17:17:16 pfsense check_reload_status: Linkup starting em1 Nov 9 17:24:09 pfsense kernel: ... Nov 9 17:24:09 pfsense kernel: .done. Nov 9 17:24:09 pfsense php: rc.bootup: The command '/usr/sbin/pw groupadd -g -M 2000 2>&1' returned exit code '65', the output was 'pw: group name required' Nov 9 17:24:09 pfsense kernel: done. Nov 9 17:24:10 pfsense php: rc.bootup: ROUTING: setting default route to 84.DDD.NN.1 Nov 9 17:24:10 pfsense kernel: done. Nov 9 17:24:10 pfsense dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory. Nov 9 17:24:10 pfsense kernel: done. Nov 9 17:24:10 pfsense dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory. Nov 9 17:24:10 pfsense dhcpleases: Could not deliver signal HUP to process because its pidfile does not exist, No such file or directory. Nov 9 17:24:10 pfsense dhcpleases: kqueue error: unkown Nov 9 17:24:10 pfsense kernel: done. Nov 9 17:24:10 pfsense check_reload_status: Updating all dyndns Nov 9 17:24:11 pfsense php-fpm[55608]: /rc.dyndns.update: phpDynDNS (my.dyn.dns.com): No change in my IP address and/or 25 days has not passed. Not updating dynamic DNS entry. Nov 9 17:24:13 pfsense kernel: .. Nov 9 17:24:14 pfsense kernel: .. Nov 9 17:24:14 pfsense kernel: .done. Nov 9 17:24:19 pfsense php: rc.bootup: Creating rrd update script Nov 9 17:24:19 pfsense php: rc.bootup: miniupnpd: Starting service on interface: lan Nov 9 17:24:19 pfsense kernel: done. Nov 9 17:24:19 pfsense kernel: done. Nov 9 17:24:19 pfsense php-fpm[71347]: /rc.start_packages: Restarting/Starting all packages. Nov 9 17:24:19 pfsense php-fpm[71347]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:24:19 pfsense php-fpm[71347]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:24:19 pfsense php-fpm[71347]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:24:19 pfsense php-fpm[71347]: /rc.start_packages: No pfBlocker action during boot process. Nov 9 17:24:19 pfsense SnortStartup[3452]: Snort START for SnortLAN(330_em1)... Nov 9 17:24:19 pfsense snort[4339]: FATAL ERROR: OpenAlertFile() => fopen() alert file /var/log/snort/snort_em1330/alert: No such file or directory Nov 9 17:24:20 pfsense login: login on ttyv0 as root Nov 9 17:24:20 pfsense sshlockout[21384]: sshlockout/webConfigurator v3.0 starting up Nov 9 17:24:32 pfsense php-fpm[71347]: /index.php: Successful login for user 'admin' from: 192.168.XX.YY Nov 9 17:24:32 pfsense php-fpm[71347]: /index.php: Successful login for user 'admin' from: 192.168.XX.YY Nov 9 17:25:51 pfsense sshd[45878]: Accepted keyboard-interactive/pam for root from 192.168.XX.YY port 63416 ssh2</cpu></cpu></kingston></ahci></vendor></vendor></vendor></vendor></vendor></vendor></vendor></intel></intel></intel></intel></enhanced></enhanced></at></keyboard></generic></system></power></ahci></ahci></ahci></ahci></ahci></intel></isa></pci-isa></acpi></acpi></ehci></intel(r)></acpi></acpi></acpi></acpi></ehci></intel(r)></simple></sandybridge></vga-compatible></acpi></acpi></high></at></at></acpi></acpi></intel></software></software,></version></intel ></lahf></syscall,nx,rdtscp,lm></sse3,pclmulqdq,dtes64,mon,ds_cpl,vmx,est,tm2,ssse3,cx16,xtpr,pdcm,pcid,sse4.1,sse4.2,popcnt,tscdlt,xsave,osxsave></fpu,vme,de,pse,tsc,msr,pae,mce,cx8,apic,sep,mtrr,pge,mca,cmov,pat,pse36,clflush,dts,acpi,mmx,fxsr,sse,sse2,ss,htt,tm,pbe> -
Split this off to its own thread since it has nothing to do with the thread you posted in, please don't hijack unrelated threads.
Are you using hostnames in aliases, IPsec, or anywhere else? DNS delays seem most suspect, but hard to say from that.
-
@cmb:
Are you using hostnames in aliases, IPsec, or anywhere else? DNS delays seem most suspect, but hard to say from that.
I'm only using IP/port aliases and pfBlocker. Other packages / features I have enabled are Snort and OpenVPN.
I just updated to the 10th Nov snapshot and it took about 7-9 minutes for the firewall to get online again.
I went through my config.xml and couldn't find anything odd about it. Is there any further information I can provide?
Edit: Another reboot with 10th Nov (built on Mon Nov 10 02:26:14 CST 2014) snapshot and no delay. Reboot time was less than 2 minutes.
-
I don't see anything obvious that'd cause a boot delay along those lines. Something took a long time in the linkup of the NIC, and it's not clear what from that.
Is it only reboots post-upgrade?
-
There was an issue with pfctl which I think Ermal pushed a fix for awhile back (see Bug # 3854 on Redmine.)
At that time, from the pfSense Terminal, it was stuck on "Loading Network" or something like that for about 3-5mins.
Its faster now, but I still notice that 2.2 (Bare Metal and VM) takes a bit longer to load than any of my 2.1.5 boxes.
-
@cmb:
I don't see anything obvious that'd cause a boot delay along those lines. Something took a long time in the linkup of the NIC, and it's not clear what from that.
Is it only reboots post-upgrade?
With the Sunday snapshot I was able to replicate the same delay multiple times with no changes made before reboot. It seems to be a lot better with the current snapshot with sub 2 minute reboot time for the last 2 times I've tested.
Copyright 2025 Rubicon Communications LLC (Netgate). All rights reserved.