Hello list,
Recently, I decided to update my pfSense install from 2.0 to the
2.1 nightlies. After the update, everything is fine except that all
the pfSense services seem to go down then come up repeatedly. For
example, this is what the ntpd log shows:
--------------------------------8<--------------Snip--------------8<--------------------------------
Oct 23 19:33:57 ntpd[26267]: ntpd [email protected] Tue Aug 7 01:42:52
UTC 2012 (1)
Oct 23 19:33:57 ntpdate[24339]: adjust time server x.x.x.x offset 0.004919 sec
Oct 23 19:33:52 ntpd[60639]: ntpd exiting on signal 15
Oct 23 19:32:41 ntpd[60639]: Listening on routing socket on fd #29 for
interface updates
Oct 23 19:32:41 ntpd[60639]: peers refreshed
Oct 23 19:32:41 ntpd[60639]: Listen normally on 6 lo0 ::1 UDP 123
Oct 23 19:32:41 ntpd[60639]: Listen normally on 5 lo0 127.0.0.1 UDP 123
Oct 23 19:32:41 ntpd[60639]: Listen normally on 4 igb1 xxxx::1 UDP 123
Oct 23 19:32:41 ntpd[60639]: Listen normally on 3 igb1 xxxx::1:3700 UDP 123
Oct 23 19:32:41 ntpd[60639]: Listen normally on 2 igb1 x.x.x.x UDP 123
Oct 23 19:32:41 ntpd[60639]: Listen and drop on 1 v6wildcard :: UDP 123
Oct 23 19:32:41 ntpd[60639]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Oct 23 19:32:41 ntpd[60639]: ntp_io: estimated max descriptors: 11095,
initial socket boundary: 20
Oct 23 19:32:41 ntpd[60639]: proto: precision = 2.304 usec
Oct 23 19:32:41 ntpd[60485]: ntpd [email protected] Tue Aug 7 01:42:52
UTC 2012 (1)
Oct 23 19:29:00 ntpd[38578]: ntpd [email protected] Tue Aug 7 01:42:52
UTC 2012 (1)
Oct 23 19:29:00 ntpdate[36138]: adjust time server x.x.x.x offset -0.004914 sec
Oct 23 19:28:53 ntpd[1708]: ntpd exiting on signal 15
Oct 23 19:24:18 ntpd[1708]: Listening on routing socket on fd #31 for
interface updates
Oct 23 19:24:18 ntpd[1708]: peers refreshed
Oct 23 19:24:18 ntpd[1708]: Listen normally on 6 lo0 ::1 UDP 123
Oct 23 19:24:18 ntpd[1708]: Listen normally on 5 lo0 127.0.0.1 UDP 123
Oct 23 19:24:18 ntpd[1708]: Listen normally on 4 igb1 xxxx::1 UDP 123
Oct 23 19:24:18 ntpd[1708]: Listen normally on 3 igb1 xxxx::1:3700 UDP 123
Oct 23 19:24:18 ntpd[1708]: Listen normally on 2 igb1 x.x.x.x UDP 123
Oct 23 19:24:18 ntpd[1708]: Listen and drop on 1 v6wildcard :: UDP 123
Oct 23 19:24:18 ntpd[1708]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Oct 23 19:24:18 ntpd[1708]: ntp_io: estimated max descriptors: 11095,
initial socket boundary: 20
Oct 23 19:24:18 ntpd[1708]: proto: precision = 2.304 usec
Oct 23 19:24:18 ntpd[1451]: ntpd [email protected] Tue Aug 7 01:42:52
UTC 2012 (1)
Oct 23 19:24:18 ntpdate[63232]: adjust time server x.x.x.x offset 0.006295 sec
Oct 23 19:24:11 ntpd[684]: ntpd exiting on signal 15
Oct 23 19:19:04 ntpd[684]: Listening on routing socket on fd #29 for
interface updates
Oct 23 19:19:04 ntpd[684]: peers refreshed
Oct 23 19:19:04 ntpd[684]: Listen normally on 6 lo0 ::1 UDP 123
Oct 23 19:19:04 ntpd[684]: Listen normally on 5 lo0 127.0.0.1 UDP 123
Oct 23 19:19:04 ntpd[684]: Listen normally on 4 igb1 xxxx::1 UDP 123
Oct 23 19:19:04 ntpd[684]: Listen normally on 3 igb1 xxxx::1:3700 UDP 123
Oct 23 19:19:04 ntpd[684]: Listen normally on 2 igb1 x.x.x.x UDP 123
Oct 23 19:19:04 ntpd[684]: Listen and drop on 1 v6wildcard :: UDP 123
Oct 23 19:19:04 ntpd[684]: Listen and drop on 0 v4wildcard 0.0.0.0 UDP 123
Oct 23 19:19:04 ntpd[684]: ntp_io: estimated max descriptors: 11095,
initial socket boundary: 20
Oct 23 19:19:04 ntpd[684]: proto: precision = 2.368 usec
Oct 23 19:19:04 ntpd[62414]: ntpd [email protected] Tue Aug 7 01:42:52
UTC 2012 (1)
Oct 23 19:19:04 ntpdate[36419]: adjust time server x.x.x.x offset -0.007397 sec
Oct 23 19:18:59 ntpd[44271]: ntpd exiting on signal 15
--------------------------------8<--------------Snip--------------8<--------------------------------
Upon further investigation, I found that check_reload_status is
the cause. Force killing the process with 'killall -9
check_reload_status' stops this from happening. The process starts
during pfSense boot up but never terminates, consuming a lot of CPU
cycles. It also starts whenever I change any configuration in the web
configurator, which I guess is its purpose, but it never terminates
and causes the weird services behaviour.
Here is how 'ps axuwww' looks like when check_reload_status is
running (from boot up):
--------------------------------8<--------------Snip--------------8<--------------------------------
%ps axuwww
USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND
root 11 98.0 0.0 0 16 ?? RL 7:09PM 26:51.97 [idle]
root 0 0.0 0.0 0 144 ?? DLs 7:09PM 0:01.49 [kernel]
root 1 0.0 0.0 3204 472 ?? SLs 7:09PM 0:00.02 /sbin/init --
root 2 0.0 0.0 0 16 ?? DL 7:09PM 0:00.02 [g_event]
root 3 0.0 0.0 0 16 ?? DL 7:09PM 0:12.14 [g_up]
root 4 0.0 0.0 0 16 ?? DL 7:09PM 0:20.20 [g_down]
root 5 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [crypto]
root 6 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [crypto returns]
root 7 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [sctp_iterator]
root 8 0.0 0.0 0 16 ?? DL 7:09PM 0:00.06 [pfpurge]
root 9 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [xpt_thrd]
root 10 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [audit]
root 12 0.0 0.0 0 288 ?? WL 7:09PM 0:41.05 [intr]
root 13 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [ng_queue]
root 14 0.0 0.0 0 16 ?? DL 7:09PM 0:01.11 [yarrow]
root 15 0.0 0.0 0 16 ?? DL 7:09PM 0:00.03 [pagedaemon]
root 16 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [vmdaemon]
root 17 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [pagezero]
root 18 0.0 0.0 0 16 ?? DL 7:09PM 0:00.00 [idlepoll]
root 19 0.0 0.0 0 16 ?? DL 7:09PM 0:00.06 [bufdaemon]
root 20 0.0 0.0 0 16 ?? DL 7:09PM 0:00.19 [syncer]
root 21 0.0 0.0 0 16 ?? DL 7:09PM 0:00.01 [vnlru]
root 22 0.0 0.0 0 16 ?? DL 7:09PM 0:00.01 [softdepflush]
root 38 0.0 0.0 0 16 ?? DL 7:09PM 0:00.08 [md0]
root 257 0.0 0.1 6988 1292 ?? SNs 7:10PM 9:01.36
/usr/local/sbin/check_reload_status
root 259 0.0 0.1 6988 1124 ?? SN 7:10PM 0:00.00
check_reload_status: Monitoring daemon of check_reload_status
root 269 0.0 0.3 5248 2976 ?? Is 7:10PM 0:00.01 /sbin/devd
_dhcp 4590 0.0 0.2 6952 1784 ?? Is 7:48PM 0:00.00
dhclient: igb0 (dhclient)
root 6481 0.0 0.2 6952 1596 ?? Ss 7:11PM 0:03.35 /sbin/routed
root 8115 0.0 0.3 15344 3332 ?? Is 7:10PM 0:00.00 /usr/sbin/sshd
root 10466 0.0 0.1 6924 1504 ?? Ss 7:11PM 0:00.14
/usr/local/sbin/miniupnpd -f /var/etc/miniupnpd.conf -P
/var/run/miniupnpd.pid
root 13806 0.0 0.6 25948 5828 ?? S 7:10PM 0:00.93
/usr/local/sbin/lighttpd -f /var/etc/lighty-webConfigurator.conf
root 14412 0.0 2.3 120172 23516 ?? I 7:10PM 0:00.17
/usr/local/bin/php
root 15452 0.0 2.6 120172 26344 ?? S 7:10PM 0:00.75
/usr/local/bin/php
root 15787 0.0 3.1 120172 31988 ?? S 7:10PM 0:01.15
/usr/local/bin/php
root 18940 0.0 0.4 26244 3896 ?? Ss 7:11PM 0:00.10 sshd:
admin@pts/0 (sshd)
root 20763 0.0 0.1 7116 1368 ?? Is 7:11PM 0:00.00
/usr/local/sbin/sshlockout_pf 15
root 21374 0.0 3.6 120172 36292 ?? S 7:10PM 0:03.83
/usr/local/bin/php
root 23822 0.0 0.1 5864 1232 ?? Is 7:27PM 0:00.00
/usr/local/bin/minicron 240 /var/run/ping_hosts.pid
/usr/local/bin/ping_hosts.sh
root 24005 0.0 0.1 5864 1280 ?? I 7:27PM 0:00.00
minicron: helper /usr/local/bin/ping_hosts.sh (minicron)
root 24296 0.0 10.4 189432 105532 ?? SNs 7:49PM 0:00.30
/usr/pbi/ntop-amd64/bin/ntop -i igb0,igb1,gif0,ovpns1,lo0 -u root -d
-4 -M -x 8102 -X 8192
root 24453 0.0 0.1 5864 1232 ?? Is 7:27PM 0:00.00
/usr/local/bin/minicron 3600 /var/run/expire_accounts.pid
/etc/rc.expireaccounts
root 24831 0.0 0.1 5864 1280 ?? I 7:27PM 0:00.00
minicron: helper /etc/rc.expireaccounts (minicron)
root 24929 0.0 0.1 5864 1232 ?? Is 7:27PM 0:00.00
/usr/local/bin/minicron 86400 /var/run/update_alias_url_data.pid
/etc/rc.update_alias_url_data
root 25119 0.0 0.1 5864 1280 ?? I 7:27PM 0:00.00
minicron: helper /etc/rc.update_alias_url_data (minicron)
root 27428 0.0 0.2 8008 1684 ?? SNs 7:49PM 0:00.00 /usr/sbin/cron -s
havp 30883 0.0 0.7 26428 7620 ?? SNs 7:45PM 0:00.01
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
havp 31208 0.0 0.7 26428 7620 ?? IN 7:45PM 0:00.00
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
havp 31285 0.0 0.7 26428 7620 ?? IN 7:45PM 0:00.00
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
havp 31456 0.0 0.7 26428 7620 ?? IN 7:45PM 0:00.00
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
havp 31866 0.0 0.7 26428 7620 ?? IN 7:45PM 0:00.00
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
havp 32256 0.0 0.7 26428 7620 ?? IN 7:45PM 0:00.00
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
root 32288 0.0 0.2 5860 1572 ?? SNs 7:48PM 0:00.02
/usr/local/sbin/apinger -c /var/etc/apinger.conf
havp 32409 0.0 0.7 26428 7620 ?? IN 7:45PM 0:00.00
/usr/pbi/havp-amd64/sbin/havp -c /usr/local/etc/havp/havp.config
root 32577 0.0 0.2 14436 2288 ?? SN 7:48PM 0:00.00 rrdtool -
root 34318 0.0 0.0 0 16 ?? DL 7:26PM 0:00.00 [md10]
dhcpd 37262 0.0 0.7 13084 7584 ?? Ss 7:10PM 0:00.05
/usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dhcpd -cf
/etc/dhcpd.conf -pf /var/run/dhcpd.pid igb1
root 38258 0.0 0.2 9064 1632 ?? Ss 7:10PM 0:00.15
/usr/sbin/inetd -wW -R 0 -a 127.0.0.1 /var/etc/inetd.conf
dhcpd 38561 0.0 0.5 11164 5356 ?? Ss 7:10PM 0:00.05
/usr/local/sbin/dhcpd -6 -user dhcpd -group _dhcp -chroot /var/dhcpd
-cf /etc/dhcpdv6.conf -pf /var/run/dhcpdv6.pid igb1
root 39084 0.0 0.1 2804 1012 ?? Is 7:10PM 0:00.00
/usr/local/sbin/dhcpleases6 -c /usr/local/bin/php -f
/usr/local/sbin/prefixes.php|/bin/sh -l
/var/dhcpd/var/db/dhcpd6.leases
root 39634 0.0 0.1 5864 1420 ?? Is 7:10PM 0:00.02
/usr/local/sbin/radvd -C /var/etc/radvd.conf -m syslog
root 40016 0.0 0.1 5864 1264 ?? Is 7:10PM 0:00.01
/usr/local/sbin/dhcpleases -l /var/dhcpd/var/db/dhcpd.leases -d
example.com -p /var/run/dnsmasq.pid -h /var/etc/hosts
nobody 42267 0.0 0.3 10184 2820 ?? S 7:10PM 0:01.33
/usr/local/sbin/dnsmasq --local-ttl 1 --all-servers
--rebind-localhost-ok --stop-dns-rebind --dns-forward-max=5000
--cache-size=10000 --dhcp-hostsfile=/var/etc/hosts
root 44218 0.0 0.1 7116 1460 ?? Is 7:23PM 0:00.00
/usr/local/sbin/sshlockout_pf 15
root 46145 0.0 21.8 249464 221648 ?? INs 7:13PM 0:00.01
/usr/local/sbin/clamd -c /usr/local/etc/clamd.conf
root 50654 0.0 0.1 2796 1000 ?? SN 7:49PM 0:00.00 sleep 60
root 52296 0.0 0.4 11056 4052 ?? SNs 7:48PM 0:00.01
/usr/local/sbin/openvpn --config /var/etc/openvpn/server1.conf
root 54131 0.0 0.4 11056 4060 ?? SNs 7:48PM 0:00.00
/usr/local/sbin/openvpn --config /var/etc/openvpn/server2.conf
root 56843 0.0 4.3 132460 43900 ?? SN 7:49PM 0:00.21
/usr/local/bin/php -f /etc/rc.start_packages
root 57732 0.0 0.7 14020 6940 ?? SNs 7:49PM 0:00.01
/usr/local/bin/ntpd -g -c /var/etc/ntpd.conf
root 61026 0.0 0.2 6952 1632 ?? Is 7:48PM 0:00.00
dhclient: igb0 [priv] (dhclient)
root 63489 0.0 0.3 14868 2808 ?? Ss 7:22PM 0:17.26
/usr/sbin/syslogd -c -c -l /var/dhcpd/var/run/log -f
/var/etc/syslog.conf
root 33592 0.0 0.1 6948 1376 v0 Is+ 7:27PM 0:00.00
/usr/libexec/getty Pc ttyv0
root 33938 0.0 0.3 11824 2684 v0- S 7:10PM 0:03.88
/usr/sbin/tcpdump -s 256 -v -l -n -e -ttt -i pflog0
root 34013 0.0 0.1 5860 1016 v0- S 7:10PM 0:12.47 logger
-t pf -p local0.info
root 59439 0.0 0.2 8376 1656 v0- SN 7:11PM 0:00.15 /bin/sh
/var/db/rrd/updaterrd.sh
root 20974 0.0 0.2 8376 1576 0 Is 7:11PM 0:00.00 /bin/sh
/etc/rc.initial
root 24448 0.0 0.2 8348 2444 0 S 7:11PM 0:00.02 /bin/tcsh
root 54070 0.0 0.2 8072 1560 0 R+ 7:50PM 0:00.00 ps axuwww
--------------------------------8<--------------Snip--------------8<--------------------------------
Can anyone shed some light as to what's happening?
Thanks!
_______________________________________________
List mailing list
[email protected]
http://lists.pfsense.org/mailman/listinfo/list
