2.3.1 - 100% CPU Usage - /usr/local/sbin/check_reload_status



  • Hey,

    We've been running some tests in version 2.3.1, HA Setup, and just noticed that the process /usr/local/sbin/check_reload_status is running at 100% CPU Usage on both firewalls:

    last pid: 29592;  load averages:  1.07,  1.13,  1.14  up 1+06:08:18    16:54:39
    217 processes: 10 running, 144 sleeping, 63 waiting
    
    Mem: 50M Active, 62M Inact, 543M Wired, 112K Cache, 413M Buf, 7206M Free
    Swap: 16G Total, 16G Free
    
      PID USERNAME PRI NICE   SIZE    RES STATE   C   TIME    WCPU COMMAND
       11 root     155 ki31     0K   128K CPU1    1  29.4H 100.00% [idle{idle: cpu1}]
       11 root     155 ki31     0K   128K CPU3    3  29.3H 100.00% [idle{idle: cpu3}]
      330 root     123   20 18888K  2664K CPU5    5  63:25 100.00% /usr/local/sbin/check_reload_status
       11 root     155 ki31     0K   128K CPU7    7  29.7H  98.88% [idle{idle: cpu7}]
       11 root     155 ki31     0K   128K CPU0    0  29.7H  98.88% [idle{idle: cpu0}]
       11 root     155 ki31     0K   128K CPU4    4  29.3H  86.28% [idle{idle: cpu4}]
       11 root     155 ki31     0K   128K RUN     5  29.0H  85.60% [idle{idle: cpu5}]
       11 root     155 ki31     0K   128K CPU6    6  28.7H  85.25% [idle{idle: cpu6}]
       11 root     155 ki31     0K   128K RUN     2  29.4H  49.76% [idle{idle: cpu2}]
    14659 root      35    0   262M 35612K piperd  0   0:00   1.95% php-fpm: pool nginx (php-fpm)
        0 root     -16    -     0K   688K swapin  4 233.0H   0.00% [kernel{swapper}]
       12 root     -92    -     0K  1008K WAIT    6  44:30   0.00% [intr{irq288: igb2:que}]
       12 root     -92    -     0K  1008K WAIT    5  19:15   0.00% [intr{irq287: igb2:que}]
       12 root     -92    -     0K  1008K WAIT    5  14:15   0.00% [intr{irq278: igb1:que}]
       12 root     -92    -     0K  1008K WAIT    4   9:56   0.00% [intr{irq277: igb1:que}]
       12 root     -92    -     0K  1008K WAIT    3   9:24   0.00% [intr{irq276: igb1:que}]
        0 root     -92    -     0K   688K -       0   8:34   0.00% [kernel{dummynet}]
       12 root     -92    -     0K  1008K WAIT    1   5:46   0.00% [intr{irq283: igb2:que}]
    
    

    Nothing on the logs show what can be happening. Any idea?

    Full ps uxawww output:

    [2.3.1-RELEASE][admin@fw1.event]/root: ps uxawww
    USER      PID  %CPU %MEM    VSZ   RSS TT  STAT STARTED        TIME COMMAND
    root       11 697.4  0.0      0   128  -  RL   Mon10AM 14075:54.80 [idle]
    root      330 100.0  0.0  18888  2664  -  RNs  Mon10AM    64:52.14 /usr/local/sbin/check_reload_status
    root    13480   1.2  0.4 268248 35332  -  S     4:56PM     0:00.14 php-fpm: pool nginx (php-fpm)
    root        0   0.0  0.0      0   688  -  DLs  Mon10AM     8:35.53 [kernel]
    root        1   0.0  0.0   9136   820  -  ILs  Mon10AM     0:00.01 /sbin/init --
    root        2   0.0  0.0      0    16  -  DL   Mon10AM     0:00.00 [crypto]
    root        3   0.0  0.0      0    16  -  DL   Mon10AM     0:00.00 [crypto returns]
    root        4   0.0  0.0      0    48  -  DL   Mon10AM     0:00.82 [cam]
    root        5   0.0  0.0      0    16  -  DL   Mon10AM     0:06.62 [pf purge]
    root        6   0.0  0.0      0    16  -  DL   Mon10AM     0:00.00 [sctp_iterator]
    root        7   0.0  0.0      0    16  -  DL   Mon10AM     0:00.02 [enc_daemon0]
    root        8   0.0  0.0      0    16  -  DL   Mon10AM     0:00.75 [g_mirror pfSenseMir]
    root        9   0.0  0.0      0    32  -  DL   Mon10AM     0:00.50 [pagedaemon]
    root       10   0.0  0.0      0    16  -  DL   Mon10AM     0:00.00 [audit]
    root       12   0.0  0.0      0  1008  -  WL   Mon10AM   131:32.64 [intr]
    root       13   0.0  0.0      0   128  -  DL   Mon10AM     0:00.00 [ng_queue]
    root       14   0.0  0.0      0    48  -  DL   Mon10AM     0:06.07 [geom]
    root       15   0.0  0.0      0    16  -  DL   Mon10AM     0:15.65 [rand_harvestq]
    root       16   0.0  0.0      0    80  -  DL   Mon10AM     0:01.51 [usb]
    root       17   0.0  0.0      0    16  -  DL   Mon10AM     0:00.00 [vmdaemon]
    root       18   0.0  0.0      0    16  -  DL   Mon10AM     0:00.00 [pagezero]
    root       19   0.0  0.0      0    16  -  DL   Mon10AM     0:00.04 [idlepoll]
    root       20   0.0  0.0      0    32  -  DL   Mon10AM     0:00.53 [bufdaemon]
    root       21   0.0  0.0      0    16  -  DL   Mon10AM     0:03.73 [syncer]
    root       22   0.0  0.0      0    16  -  DL   Mon10AM     0:00.12 [vnlru]
    root       61   0.0  0.0      0    16  -  DL   Mon10AM     0:00.10 [md0]
    root      332   0.0  0.0  18888  2396  -  IN   Mon10AM     0:00.00 check_reload_status: Monitoring daemon of check_reload_status
    root      343   0.0  0.1  13624  5204  -  Is   Mon10AM     0:00.02 /sbin/devd -q
    dhcpd    3138   0.0  0.2  32996 20264  -  Ss    3:53PM     0:00.55 /usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dhcpd -cf /etc/dhcpd.conf -pf /var/run/dhcpd.pid lagg0_vlan102 lagg0_vlan103 lagg0_vlan104 lagg0_vlan105 lagg0_vlan106 lagg0_vlan107 lagg0_vlan108
    root    11792   0.0  0.1  21624  5832  -  Ss    3:53PM     0:00.23 /usr/local/sbin/openvpn --config /var/etc/openvpn/client2.conf
    root    12745   0.0  0.1  21624  5832  -  Ss    3:53PM     0:00.22 /usr/local/sbin/openvpn --config /var/etc/openvpn/client1.conf
    root    22826   0.0  0.1  59068  8080  -  Is   Mon10AM     0:00.00 /usr/sbin/sshd
    root    23009   0.0  0.0  14612  2180  -  Is   Mon10AM     0:00.00 /usr/local/sbin/sshlockout_pf 15
    root    29559   0.0  0.0  16676  2284  -  Ss   Mon10AM     0:00.47 /usr/local/sbin/filterlog -i pflog0 -p /var/run/filterlog.pid
    root    30265   0.0  0.0  14516  2316  -  Ss   Mon10AM     0:17.61 /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /var/etc/syslog.conf -b 10.10.115.237
    root    30556   0.0  0.0  18896  2492  -  Is   Mon10AM     0:00.01 /usr/local/sbin/xinetd -syslog daemon -f /var/etc/xinetd.conf -pidfile /var/run/xinetd.pid
    root    31335   0.0  0.0  12268  1876  -  Is   Mon10AM     0:00.00 /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local/bin/ping_hosts.sh
    root    31836   0.0  0.0  12268  1888  -  I    Mon10AM     0:00.01 minicron: helper /usr/local/bin/ping_hosts.sh  (minicron)
    root    31911   0.0  0.0  12268  1876  -  Is   Mon10AM     0:00.00 /usr/local/bin/minicron 3600 /var/run/expire_accounts.pid /usr/local/sbin/fcgicli -f /etc/rc.expireaccounts
    root    32048   0.0  0.0  12268  1888  -  I    Mon10AM     0:00.00 minicron: helper /usr/local/sbin/fcgicli -f /etc/rc.expireaccounts  (minicron)
    root    32215   0.0  0.0  12268  1876  -  Is   Mon10AM     0:00.00 /usr/local/bin/minicron 86400 /var/run/update_alias_url_data.pid /usr/local/sbin/fcgicli -f /etc/rc.update_alias_url_data
    root    32516   0.0  0.0  12268  1888  -  I    Mon10AM     0:00.00 minicron: helper /usr/local/sbin/fcgicli -f /etc/rc.update_alias_url_data  (minicron)
    root    33195   0.0  0.0  12268  1876  -  Is   Mon10AM     0:00.00 /usr/local/bin/minicron 60 /var/run/gmirror_status_check.pid /usr/local/sbin/gmirror_status_check.php
    root    33463   0.0  0.0  12268  1884  -  S    Mon10AM     0:00.04 minicron: helper /usr/local/sbin/gmirror_status_check.php  (minicron)
    root    35912   0.0  0.0  15012  2292  -  Ss    3:53PM     0:00.12 /usr/local/bin/dpinger -S -r 0 -i WANGW -B 10.10.115.237 -p /var/run/dpinger_WANGW_10.10.115.237_4.2.2.2.pid -u /var/run/dpinger_WANGW_10.10.115.237_4.2.2.2.sock -C /etc/rc.gateway_alarm -d 0 -s 500 -l 2000 -t 60000 -A 1000 -D 500 -L 20 4.2.2.2
    root    36477   0.0  0.0  15012  2292  -  Ss    3:53PM     0:00.12 /usr/local/bin/dpinger -S -r 0 -i HETZNERVPN_01_VPNV4 -B 10.8.2.6 -p /var/run/dpinger_HETZNERVPN_01_VPNV4_10.8.2.6_208.67.222.222.pid -u /var/run/dpinger_HETZNERVPN_01_VPNV4_10.8.2.6_208.67.222.222.sock -C /etc/rc.gateway_alarm -d 0 -s 500 -l 2000 -t 60000 -A 1000 -D 500 -L 20 208.67.222.222
    root    36532   0.0  0.0  15012  2292  -  Ss    3:53PM     0:00.12 /usr/local/bin/dpinger -S -r 0 -i HETZNERVPN_02_VPNV4 -B 10.8.1.6 -p /var/run/dpinger_HETZNERVPN_02_VPNV4_10.8.1.6_208.67.220.220.pid -u /var/run/dpinger_HETZNERVPN_02_VPNV4_10.8.1.6_208.67.220.220.sock -C /etc/rc.gateway_alarm -d 0 -s 500 -l 2000 -t 60000 -A 1000 -D 500 -L 20 208.67.220.220
    root    36835   0.0  0.3 268248 27776  -  Ss    4:51PM     0:00.02 php-fpm: master process (/usr/local/lib/php-fpm.conf) (php-fpm)
    root    37130   0.0  0.0  15012  2292  -  Ss    3:53PM     0:00.12 /usr/local/bin/dpinger -S -r 0 -i 667_WAN2GW -B 10.30.115.2 -p /var/run/dpinger_667_WAN2GW_10.30.115.2_4.2.2.3.pid -u /var/run/dpinger_667_WAN2GW_10.30.115.2_4.2.2.3.sock -C /etc/rc.gateway_alarm -d 0 -s 500 -l 2000 -t 60000 -A 1000 -D 500 -L 20 4.2.2.3
    root    38758   0.0  0.1  38848  6348  -  Is    4:51PM     0:00.00 nginx: master process /usr/local/sbin/nginx -c /var/etc/nginx-webConfigurator.conf (nginx)
    root    38826   0.0  0.1  38848  7384  -  S     4:51PM     0:00.20 nginx: worker process (nginx)
    root    39053   0.0  0.1  38848  7036  -  S     4:51PM     0:00.04 nginx: worker process (nginx)
    root    42461   0.0  0.0  16532  2292  -  Ss   Mon10AM     0:00.03 /usr/sbin/cron -s
    root    54758   0.0  0.2  30140 17968  -  Ss   Mon10AM     0:03.01 /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
    unbound 57867   0.0  0.4 186988 34180  -  Is    3:53PM     0:00.08 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
    root    93416   0.0  0.1  82268  8412  -  Ss    4:51PM     0:00.07 sshd: admin@pts/0 (sshd)
    root    94833   0.0  0.0  14612  2180  -  Is   Mon10AM     0:00.00 /usr/local/sbin/sshlockout_pf 15
    root    69163   0.0  0.0  14428  1992 v0  Is+  Mon10AM     0:00.00 /usr/libexec/getty Pc ttyv0
    root    25702   0.0  0.0   8168  1828  0  IN    4:55PM     0:00.00 sleep 60
    root    26894   0.0  0.0  18676  2252  0  R+    4:56PM     0:00.00 ps uxawww
    root    39512   0.0  0.0  17000  2604  0  IN    4:51PM     0:00.03 /bin/sh /var/db/rrd/updaterrd.sh
    root    97617   0.0  0.0  17000  2544  0  Ss    4:51PM     0:00.00 /bin/sh /etc/rc.initial
    root    98345   0.0  0.0  17340  3388  0  S     4:55PM     0:00.00 /bin/tcsh
    


  • Same in 2.3.2_1 …

    Anyone?

    ps uxawww output:

    
    USER      PID  %CPU %MEM    VSZ   RSS TT  STAT STARTED       TIME COMMAND
    root       11 580.3  0.0      0   128  -  RL    7:05AM 1309:40.05 [idle]
    root       12 104.6  0.0      0   464  -  WL    7:05AM   50:40.06 [intr]
    root      630 100.0  0.0  18888  2692  -  RNs   7:06AM  109:36.82 /usr/local/sbin/check_reload_status
    root        0  20.8  0.0      0   224  -  DLs   7:05AM   15:14.91 [kernel]
    root     6224   2.7  0.3 280688 51464  -  S    10:13AM    0:00.35 php-fpm: pool nginx (php-fpm)
    root        1   0.0  0.0   9136   820  -  ILs   7:05AM    0:00.02 /sbin/init --
    root        2   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [crypto]
    root        3   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [crypto returns]
    root        4   0.0  0.0      0    48  -  DL    7:05AM    0:01.81 [cam]
    root        5   0.0  0.0      0    16  -  DL    7:05AM    0:03.67 [pf purge]
    root        6   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [sctp_iterator]
    root        7   0.0  0.0      0    16  -  DL    7:05AM    0:00.22 [g_mirror pfSenseMir]
    root        8   0.0  0.0      0    32  -  DL    7:05AM    0:00.11 [pagedaemon]
    root        9   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [vmdaemon]
    root       10   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [audit]
    root       13   0.0  0.0      0   128  -  DL    7:05AM    0:00.00 [ng_queue]
    root       14   0.0  0.0      0    48  -  DL    7:05AM    0:01.57 [geom]
    root       15   0.0  0.0      0    16  -  DL    7:05AM    0:15.81 [rand_harvestq]
    root       16   0.0  0.0      0   240  -  DL    7:05AM    0:00.36 [usb]
    root       17   0.0  0.0      0    16  -  DL    7:05AM    0:00.03 [acpi_thermal]
    root       18   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [acpi_cooling0]
    root       19   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [idlepoll]
    root       20   0.0  0.0      0    16  -  DL    7:05AM    0:00.00 [pagezero]
    root       21   0.0  0.0      0    32  -  DL    7:05AM    0:00.15 [bufdaemon]
    root       22   0.0  0.0      0    16  -  DL    7:05AM    0:00.02 [vnlru]
    root       23   0.0  0.0      0    16  -  DL    7:05AM    0:00.73 [syncer]
    root       62   0.0  0.0      0    16  -  DL    7:05AM    0:00.17 [md0]
    root      632   0.0  0.0  18888  2396  -  IN    7:06AM    0:00.00 check_reload_status: Monitoring daemon of check_reload_status
    root      643   0.0  0.0  13624  5204  -  Is    7:06AM    0:00.03 /sbin/devd -q
    unbound  2209   0.0  0.3 113268 42840  -  Ss    8:43AM    0:54.99 /usr/local/sbin/unbound -c /var/unbound/unbound.conf
    root     4849   0.0  0.1  30140 17968  -  Ss    8:29AM    0:00.46 /usr/local/sbin/ntpd -g -c /var/etc/ntpd.conf -p /var/run/ntpd.pid
    root     5443   0.0  0.0  14564  2280  -  Is    8:25AM    0:00.00 dhclient: lagg1_vlan10 [priv] (dhclient)
    root     6861   0.0  0.0  16532  2336  -  Is    7:06AM    0:00.01 /usr/sbin/cron -s
    dhcpd    8264   0.0  0.1  28912 17432  -  Ss    8:26AM    0:02.65 /usr/local/sbin/dhcpd -user dhcpd -group _dhcp -chroot /var/dhcpd -cf /etc/dhcpd.conf -pf /var/run/dhcpd.pid lagg0_vlan3 lagg0_vlan4 lagg0_vlan5 lagg0_vlan30 lagg0_vlan90 lagg0_vlan60
    _dhcp    8502   0.0  0.0  14564  2396  -  Is    8:25AM    0:00.03 dhclient: lagg1_vlan10 (dhclient)
    root     9935   0.0  0.0  14512  2316  -  Ss    7:06AM    0:04.25 /usr/sbin/syslogd -s -c -c -l /var/dhcpd/var/run/log -P /var/run/syslog.pid -f /var/etc/syslog.conf
    root    10600   0.0  0.0  12268  1876  -  Is    7:06AM    0:00.00 /usr/local/bin/minicron 240 /var/run/ping_hosts.pid /usr/local/bin/ping_hosts.sh
    root    10960   0.0  0.0  12268  1888  -  I     7:06AM    0:00.00 minicron: helper /usr/local/bin/ping_hosts.sh  (minicron)
    root    11174   0.0  0.0  12268  1876  -  Is    7:06AM    0:00.00 /usr/local/bin/minicron 3600 /var/run/expire_accounts.pid /usr/local/sbin/fcgicli -f /etc/rc.expireaccounts
    root    11488   0.0  0.0  12268  1888  -  I     7:06AM    0:00.00 minicron: helper /usr/local/sbin/fcgicli -f /etc/rc.expireaccounts  (minicron)
    root    11655   0.0  0.0  12268  1876  -  Is    7:06AM    0:00.00 /usr/local/bin/minicron 86400 /var/run/update_alias_url_data.pid /usr/local/sbin/fcgicli -f /etc/rc.update_alias_url_data
    root    12090   0.0  0.0  12268  1888  -  I     7:06AM    0:00.00 minicron: helper /usr/local/sbin/fcgicli -f /etc/rc.update_alias_url_data  (minicron)
    root    12765   0.0  0.0  12268  1876  -  Is    7:06AM    0:00.00 /usr/local/bin/minicron 60 /var/run/gmirror_status_check.pid /usr/local/sbin/gmirror_status_check.php
    root    12855   0.0  0.0  63736  8208  -  Is   10:12AM    0:00.02 sshd: anw [priv] (sshd)
    root    13222   0.0  0.0  12268  1884  -  S     7:06AM    0:00.01 minicron: helper /usr/local/sbin/gmirror_status_check.php  (minicron)
    anw     13600   0.0  0.0  63736  8216  -  S    10:12AM    0:00.01 sshd: anw@pts/1 (sshd)
    root    15591   0.0  0.0  59068  8088  -  Is    7:06AM    0:00.00 /usr/sbin/sshd
    root    15863   0.0  0.0  14612  2180  -  Is    7:06AM    0:00.00 /usr/local/sbin/sshlockout_pf 15
    root    22410   0.0  0.0  30388  3524  -  Is    7:06AM    0:00.02 /usr/local/libexec/ipsec/starter --daemon charon
    root    22447   0.0  0.1 259216 20672  -  Is    7:06AM    0:06.54 /usr/local/libexec/ipsec/charon --use-syslog
    root    44009   0.0  0.0  21624  5780  -  Ss    8:25AM    0:00.80 /usr/local/sbin/openvpn --config /var/etc/openvpn/client1.conf
    root    44575   0.0  0.0  17000  2620  -  IN    8:26AM    0:01.31 /bin/sh /var/db/rrd/updaterrd.sh
    root    44946   0.0  0.0  21624  5780  -  Ss    8:25AM    0:00.82 /usr/local/sbin/openvpn --config /var/etc/openvpn/client2.conf
    root    47847   0.0  0.0  21624  5868  -  Ss    8:25AM    0:03.27 /usr/local/sbin/openvpn --config /var/etc/openvpn/client3.conf
    root    48212   0.0  0.0  21036  4728  -  Is    7:06AM    0:00.99 /usr/local/sbin/miniupnpd -f /var/etc/miniupnpd.conf -P /var/run/miniupnpd.pid
    root    56323   0.0  0.0  23092  2660  -  Is    7:07AM    0:00.01 /usr/local/sbin/filterdns -p /var/run/filterdns.pid -i 300 -c /var/etc/filterdns.conf -d 1
    root    62229   0.0  0.2 268400 30060  -  Ss    8:23AM    0:00.26 php-fpm: master process (/usr/local/lib/php-fpm.conf) (php-fpm)
    root    62369   0.0  0.0   8168  1828  -  IN   10:13AM    0:00.00 sleep 60
    root    64034   0.0  0.0  39136  6552  -  Is    8:23AM    0:00.00 nginx: master process /usr/local/sbin/nginx -c /var/etc/nginx-webConfigurator.conf (nginx)
    root    64223   0.0  0.0  39136  8004  -  S     8:23AM    0:00.58 nginx: worker process (nginx)
    root    64457   0.0  0.0  39136  7392  -  S     8:23AM    0:00.18 nginx: worker process (nginx)
    root    64743   0.0  0.0  39136  7672  -  S     8:23AM    0:00.43 nginx: worker process (nginx)
    root    64810   0.0  0.0  39136  7624  -  S     8:23AM    0:00.32 nginx: worker process (nginx)
    root    65583   0.0  0.0  63736  8268  -  Ss   10:12AM    0:00.10 sshd: admin@pts/0 (sshd)
    root    67249   0.0  0.0  16676  2556  -  Ss    7:06AM    0:05.82 /usr/local/sbin/filterlog -i pflog0 -p /var/run/filterlog.pid
    root    67656   0.0  0.0  18896  2492  -  Is    7:06AM    0:00.01 /usr/local/sbin/xinetd -syslog daemon -f /var/etc/xinetd.conf -pidfile /var/run/xinetd.pid
    root    89299   0.0  0.0  21624  5868  -  Ss    8:26AM    0:10.76 /usr/local/sbin/openvpn --config /var/etc/openvpn/client4.conf
    root    98779   0.0  0.0  14612  2180  -  Is    7:07AM    0:00.00 /usr/local/sbin/sshlockout_pf 15
    root    52902   0.0  0.0  14428  1992 v0  Is+   7:06AM    0:00.00 /usr/libexec/getty Pc ttyv0
    root    11136   0.0  0.0  17000  2540  0  Is   10:12AM    0:00.00 /bin/sh /etc/rc.initial
    root    11882   0.0  0.0  17340  3380  0  S    10:12AM    0:00.00 /bin/tcsh
    root    28464   0.0  0.0  18676  2276  0  R+   10:13AM    0:00.00 ps uxawww
    anw     13617   0.0  0.0  17340  3416  1  Is   10:12AM    0:00.00 -tcsh (tcsh)
    anw     33868   0.0  0.0  21856  3012  1  S+   10:12AM    0:00.02 top
    
    

  • Rebel Alliance Developer Netgate

    check_reload_status is a command dispatching daemon. If it's using CPU, it's because it's being given a lot of commands. In other words, it's not causing the problem, you're looking at a symptom. You need to locate the actual cause. Look in all of your logs for any repeating events or other processes that are stopping/starting, for example.


Log in to reply