Guest User!

You are not Sophos Staff.

[8.920][BUG] Huge CPU increase because of httpd process

Hi All

The CPU went up suddenly because of httpd and since then it stayed there (55%). Before the increase the cpu was around 15% 

attached is the diagram as well

wwwrun   31676 99.2  0.1  18656  4724 ?        R    Mar30 1452:42  \_ /bin/httpd -f /etc/httpd/httpd.conf



(not sure if related to https://community.sophos.com/products/unified-threat-management/astaroorg/f/75/t/63913 as I don't have SSL scanning enabled-Mantis #20610 )

The issues started 30.3.2012 11.00 AM

Only error I can see is on middleware log (the times are not the same as the high CPU)

2012:03:30-00:10:16 ***** middleware[3523]: >=========================================================================
2012:03:30-00:10:16 ***** middleware[3523]: E Failed: /usr/sbin/tc qdisc del dev eth1.10 parent 1:5 handle 2:
2012:03:30-00:10:16 ***** middleware[3523]: 
2012:03:30-00:10:16 ***** middleware[3523]:  1. utils::IPRoute::tc_cmd:949() /utils/IPRoute.pm
2012:03:30-00:10:16 ***** middleware[3523]:  2. utils::IPRoute::tc_qdisc_cmd:919() /utils/IPRoute.pm
2012:03:30-00:10:16 ***** middleware[3523]:  3. utils::IPRoute::tc_qdisc_del:911() /utils/IPRoute.pm
2012:03:30-00:10:16 ***** middleware[3523]:  4. modules::qos::cleanSystem:257() /modules/qos.pm
2012:03:30-00:10:16 ***** middleware[3523]:  5. modules::qos::setAll:157() /modules/qos.pm
2012:03:30-00:10:16 ***** middleware[3523]:  6. core::Config::load:278() /core/Config.pm
2012:03:30-00:10:16 ***** middleware[3523]:  7. main::top-level:221() mdw.pl
2012:03:30-00:10:16 ***** middleware[3523]: >=========================================================================
2012:03:30-00:10:16 ***** middleware[3523]: E Failed: /usr/sbin/tc qdisc del dev eth1.20 parent 1:3 handle 2:
2012:03:30-00:10:16 ***** middleware[3523]: 
2012:03:30-00:10:16 ***** middleware[3523]:  1. utils::IPRoute::tc_cmd:949() /utils/IPRoute.pm
2012:03:30-00:10:16 ***** middleware[3523]:  2. utils::IPRoute::tc_qdisc_cmd:919() /utils/IPRoute.pm
2012:03:30-00:10:16 ***** middleware[3523]:  3. utils::IPRoute::tc_qdisc_del:911() /utils/IPRoute.pm
2012:03:30-00:10:16 ***** middleware[3523]:  4. modules::qos::cleanSystem:257() /modules/qos.pm
2012:03:30-00:10:16 ***** middleware[3523]:  5. modules::qos::setAll:157() /modules/qos.pm
2012:03:30-00:10:16 ***** middleware[3523]:  6. core::Config::load:278() /core/Config.pm
2012:03:30-00:10:16 ***** middleware[3523]:  7. main::top-level:221() mdw.pl


or config daemon

2012:03:30-14:14:43 ***** confd[31682]: >=========================================================================
2012:03:30-14:14:43 ***** confd[31682]: E Maximal count of pending signals (120) exceeded at /rpc.pm line 426.
2012:03:30-14:14:43 ***** confd[31682]: 
2012:03:30-14:14:43 ***** confd[31682]:  1. sys::_warn:51() /sys.pm
2012:03:30-14:14:43 ***** confd[31682]:  2. sys::_die:57() /sys.pm
2012:03:30-14:14:43 ***** confd[31682]:  3. Astaro::RPC::get_request:426() /rpc.pm
2012:03:30-14:14:43 ***** confd[31682]:  4. Astaro::RPC::server_loop:180() /rpc.pm
2012:03:30-14:14:43 ***** confd[31682]:  5. rpc::launch:50() /rpc.pm
2012:03:30-14:14:43 ***** confd[31682]:  6. main::_rpc:2135() confd.pl
2012:03:30-14:14:43 ***** confd[31682]:  7. main::top-level:394() confd.pl



no /var/storage/cores available. 
Thanks
  • more useful info 

    :/var/storage/cores # ps ax -o pcpu,cmd|sort -n -r|head
    99.2 /bin/httpd -f /etc/httpd/httpd.conf
     6.5 [confd.plx] 
     1.4 /var/chroot-http/usr/bin/httpproxy -f -c /var/chroot-http -u httpproxy
     1.2 confd [worker[:P]rpc:webadmin]
     0.9 /sbin/snort_inline -Q -D -c /etc/snort/snort.conf -R 1 -K none -P 65535 -g 800 -u 800 --daq nfqmnlmmap --daq-var queue=0 --daq-var queue_len=1024 --daq-var verdictcache_len=10 --daq-var verdictcache_timeout=1000 --daq-var proto=ip*
     0.6 /var/webadmin/index.plx
     0.5 /usr/local/bin/selfmonng.plx
     0.5 /usr/lib/ctasd/ctasd -p /var/run/ctasd.pid -l /usr/lib/ctasd
     0.5 ./ctipd.bin -l /usr/lib/ctipd
     0.3 /var/mdw/mdw.plx


    :/var/storage/cores # ps ax -o rss,cmd |sort -n -r|head
    295428 /var/chroot-http/usr/bin/httpproxy -f -c /var/chroot-http -u httpproxy
    246280 /usr/bin/cssd -d
    155012 /sbin/snort_inline -Q -D -c /etc/snort/snort.conf -R 1 -K none -P 65535 -g 800 -u 800 --daq nfqmnlmmap --daq-var queue=0 --daq-var queue_len=1024 --daq-var verdictcache_len=10 --daq-var verdictcache_timeout=1000 --daq-var proto=ip*
    81372 /var/webadmin/index.plx
    63312 /var/mdw/mdw.plx
    50096 confd [worker[:P]rpc:webadmin]
    35460 confd [worker[:P]rpc:system]
    35180 /var/jape/index.plx
    35112 confd [worker[:P]rpc:system]
    34204 confd [master]



    :/ # lsof -nP -i | grep 8080
    httpproxy 20915 httpproxy    5u  IPv4 1307069      0t0  TCP 192.168.2.100:8080->192.168.2.5:53745 (ESTABLISHED)
    httpproxy 20915 httpproxy   73u  IPv4 1300615      0t0  TCP *:8080 (LISTEN)
    httpproxy 20915 httpproxy   76u  IPv6 1300617      0t0  TCP *:8080 (LISTEN)
    httpproxy 20915 httpproxy   77u  IPv4 1300619      0t0  TCP *:18080 (LISTEN)
    httpproxy 20915 httpproxy   78u  IPv6 1300621      0t0  TCP *:18080 (LISTEN)
    httpproxy 20915 httpproxy   84u  IPv4 1302571      0t0  TCP 192.168.2.100:8080->192.168.2.2:4731 (ESTABLISHED)
    httpproxy 20915 httpproxy   86u  IPv4 1301055      0t0  TCP 192.168.2.100:8080->192.168.2.5:53348 (ESTABLISHED)
    httpproxy 20915 httpproxy  104u  IPv4 1302144      0t0  TCP 192.168.2.100:8080->192.168.2.5:53654 (ESTABLISHED)


    I've tried to run the command "strace -p 31676 " or even output it to a file but the file is empty
  • Okay, that's a new issue. The thing i worry about most is the confd error message "Maximal count of pending signals exceeded". Will take a look at this issue on Monday. We'll probably need a lot of logs to find out what went wrong.

    Just to make this clear: You should reboot and cross fingers that the reboot fixes your problem. Otherwise you'll see a whole lot of strange effects, all caused by this.

    Cheers,
    Kai
  • Thanks Kai

    The CPU is at the moment around 60% so I can wait just in case you need me to perform any kind of troubleshooting
  • Traffic went back to normal today at 21:30 without me rebooting the unit (attached)

    During that time , I did regenerate the Webadmin Certificate (testing something else) and the only error message I got on the conf daemon is (not around the same time)

    2012:03:31-22:55:53 ***** confd[5173]: >=========================================================================
    2012:03:31-22:55:53 ***** confd[5173]: E Use of uninitialized value in string eq at /Object/itfparams.pm line 271.
    2012:03:31-22:55:53 ***** confd[5173]: 
    2012:03:31-22:55:53 ***** confd[5173]:  1. sys::_warn:51() /sys.pm
    2012:03:31-22:55:53 ***** confd[5173]:  2. Object::itfparams::set_itfparams:271() /Object/itfparams.pm
    2012:03:31-22:55:53 ***** confd[5173]:  3. (eval):1() (eval 1807)
    2012:03:31-22:55:53 ***** confd[5173]:  4. sys::AUTOLOAD:353() /sys.pm
    2012:03:31-22:55:53 ***** confd[5173]:  5. (eval):1() (eval 1805)
    2012:03:31-22:55:53 ***** confd[5173]:  6. Astaro::RPC::server_loop:198() /rpc.pm
    2012:03:31-22:55:53 ***** confd[5173]:  7. rpc::launch:50() /rpc.pm
    2012:03:31-22:55:53 ***** confd[5173]:  8. main::_rpc:2135() confd.pl
    2012:03:31-22:55:53 ***** confd[5173]:  9. main::top-level:394() confd.pl


    Let me know if you want me to send you the config log with the timestamps for the web admin certificate regeneration

    Thanks
  • ... I can wait just in case you need me to perform any kind of troubleshooting


    Well, but then you should stop testing the beta, because you can get all kinds of strange behavior when the confd signal handling is in such a bad shape. 

    Cheers,
    Kai
  • Hi All

    The CPU went up suddenly because of httpd and since then it stayed there (55%). Before the increase the cpu was around 15% 

    attached is the diagram as well

    wwwrun   31676 99.2  0.1  18656  4724 ?        R    Mar30 1452:42  \_ /bin/httpd -f /etc/httpd/httpd.conf

    Maybe I am not reading something right but http daemon (httpd) controls webadmin[:S] The confd failing at the time of high cpu spike would also indicate some kind of backend problem while handling a configuration change in webadmin. You will get spikes if you for example open flow monitor to see whats going on. There would be no proxy dumps as httpproxy is run under user httpprox and not wwwrun.

    Regards
    Bill.
  • I think we've found the problem. Forget everything about the httpd and the proxy. It's a problem solely related to the confd and it's internal communication mechanism. 

    Thanks wingman for giving us access to your system, otherwise we would have had a hard time finding this problem.

    Cheers,
    Kai
  • Happy I could help Kai. I will disable the access for Ingo but won't delete it.let me know if you need more info so I can re enable it