The Community Forums

Interact with an entire community of cPanel & WHM users!
  1. This site uses cookies. By continuing to use this site, you are agreeing to our use of cookies. Learn More.

Sudden load spike - no apparent reason

Discussion in 'General Discussion' started by 4u123, May 21, 2006.

  1. 4u123

    4u123 Well-Known Member
    PartnerNOC

    Joined:
    Jan 2, 2006
    Messages:
    765
    Likes Received:
    1
    Trophy Points:
    18
    One server is suddenly reaching a very high load and there is seemingly no explanation. I was watching top when this happend today - the load went up to 30 within about 2 or 3 minutes - no unusual processes, the cpu and memory usage were normal, no swap being used.

    Message log shows this...

    May 21 09:00:01 server crond(pam_unix)[24863]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24867]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24870]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24875]: session opened for user kevprice by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24875]: session closed for user kevprice
    May 21 09:00:01 server crond(pam_unix)[24877]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24880]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24883]: session opened for user mailman by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24872]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24873]: session opened for user bcouncil by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24862]: session opened for user root by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24874]: session opened for user bcouncil by (uid=0)
    May 21 09:00:01 server crond(pam_unix)[24874]: session closed for user bcouncil
    May 21 09:00:01 server crond(pam_unix)[24873]: session closed for user bcouncil
    May 21 09:00:02 server crond(pam_unix)[24867]: session closed for user root
    May 21 09:00:02 server crond(pam_unix)[24880]: session closed for user root
    May 21 09:00:02 server crond(pam_unix)[24863]: session closed for user root
    May 21 09:00:02 server crond(pam_unix)[24862]: session closed for user root
    May 21 08:00:03 server stunnel: LOG5[3773:4143926192]: cpanelhttps connected from monitor.server.ip.ip:18985
    May 21 08:00:03 server stunnel: LOG3[3773:4143926192]: SSL_accept: Peer suddenly disconnected
    May 21 08:00:03 server stunnel: LOG5[3773:4143926192]: Connection reset: 0 bytes sent to SSL, 0 bytes sent to socket
    May 21 09:00:03 server pure-ftpd: (?@monitor.server.ip.ip) [INFO] New connection from monitor.server.ip.ip
    May 21 09:00:03 server pure-ftpd: (?@monitor.server.ip.ip) [INFO] Logout.
    May 21 09:00:03 server crond(pam_unix)[24872]: session closed for user root
    May 21 09:00:04 server crond(pam_unix)[24883]: session closed for user mailman
    May 21 09:00:04 server crond(pam_unix)[24870]: session closed for user root
    May 21 09:00:06 server crond(pam_unix)[24877]: session closed for user root
    May 21 09:01:01 server crond(pam_unix)[26117]: session opened for user root by (uid=0)
    May 21 09:01:01 server crond(pam_unix)[26117]: session closed for user root
    May 21 09:01:42 server pure-ftpd: (?@127.0.0.1) [INFO] New connection from 127.0.0.1
    May 21 09:01:42 server pure-ftpd: (?@127.0.0.1) [INFO] Logout.
    May 21 09:02:01 server crond(pam_unix)[26175]: session opened for user root by (uid=0)
    May 21 09:02:01 server crond(pam_unix)[26174]: session opened for user root by (uid=0)
    May 21 09:02:01 server crond(pam_unix)[26175]: session closed for user root
    May 21 09:02:04 server crond(pam_unix)[26174]: session closed for user root
    May 21 09:04:03 server crond(pam_unix)[26378]: session opened for user root by (uid=0)
    May 21 09:04:09 server crond(pam_unix)[26378]: session closed for user root
    May 21 08:04:27 server stunnel: LOG5[3773:4143926192]: whmhttps connected from 84.9.64.163:1745
    May 21 08:04:41 server stunnel: LOG5[3773:4143926192]: Connection closed: 32759 bytes sent to SSL, 563 bytes sent to socket
    May 21 09:05:02 server crond(pam_unix)[26509]: session opened for user root by (uid=0)
    May 21 09:05:02 server crond(pam_unix)[26508]: session opened for user root by (uid=0)
    May 21 09:05:02 server crond(pam_unix)[26507]: session opened for user root by (uid=0)
    May 21 09:05:06 server crond(pam_unix)[26508]: session closed for user root
    May 21 09:05:19 server wall[26588]: wall: user root broadcasted 1 lines (58 chars)
    May 21 09:05:20 server shutdown: shutting down for system reboot

    The last line where the server reboots is because of our sim config, it reboots if the load gets too high. At this point the load was at 30 and I have no idea why. The usual checks show nothing unusual at all. I'm scratching my head here.

    The message log would seem to suggest that the load is shooting up when a cron job is running - is it normal to see so many entries for cron like this ?

    Any comments would be geatly appreaciated!
     
  2. 4u123

    4u123 Well-Known Member
    PartnerNOC

    Joined:
    Jan 2, 2006
    Messages:
    765
    Likes Received:
    1
    Trophy Points:
    18
    To add...

    This problem is happening 2 or 3 times a day.

    Typical sim output is as follows...

    - Events Summary:
    Total event count: 7
    Average event count: 7

    - Service Summary:
    No service modules enabled - edit conf.sim

    - System Summary:
    LOAD [17.00 - status critical - 2 events]

    - SIM Log:
    [05/21/06 03:55:01]: LOAD 0.68 (status good)
    [05/21/06 04:00:01]: LOAD 0.90 (status good)
    [05/21/06 04:05:01]: LOAD 1.30 (status good)
    [05/21/06 04:10:02]: LOAD 1.66 (status good)
    [05/21/06 04:15:01]: LOAD 1.14 (status good)
    [05/21/06 04:20:01]: LOAD 0.77 (status good)
    [05/21/06 04:25:01]: LOAD 1.15 (status good)
    [05/21/06 04:30:01]: LOAD 0.61 (status good)
    [05/21/06 04:35:01]: LOAD 0.49 (status good)
    [05/21/06 04:40:01]: LOAD 0.71 (status good)
    [05/21/06 04:45:01]: LOAD 0.87 (status good)
    [05/21/06 04:50:01]: LOAD 0.90 (status good)
    [05/21/06 04:55:01]: LOAD 0.78 (status good)
    [05/21/06 05:00:06]: LOAD 8.32 (status warning)
    [05/21/06 05:05:02]: LOAD 17.00 (status critical)

    - System Log:
    May 21 05:01:03 server crond(pam_unix)[5013]: session opened for user root by (uid=0)
    May 21 05:01:09 server crond(pam_unix)[5013]: session closed for user root
    May 21 05:02:03 server crond(pam_unix)[5102]: session opened for user root by (uid=0)
    May 21 05:02:03 server crond(pam_unix)[5103]: session opened for user root by (uid=0)
    May 21 05:02:06 server crond(pam_unix)[5103]: session closed for user root
    May 21 05:02:08 server crond(pam_unix)[5102]: session closed for user root
    May 21 05:04:01 server crond(pam_unix)[5291]: session opened for user root by (uid=0)
    May 21 05:04:04 server crond(pam_unix)[5291]: session closed for user root
    May 21 05:05:01 server crond(pam_unix)[5391]: session opened for user root by (uid=0)
    May 21 05:05:01 server crond(pam_unix)[5394]: session opened for user root by (uid=0)
    May 21 05:05:01 server crond(pam_unix)[5397]: session opened for user root by (uid=0)
    May 21 05:05:03 server wall[5457]: wall: user root broadcasted 1 lines (58 chars)
    May 21 05:05:04 server crond(pam_unix)[5394]: session closed for user root
    May 21 05:05:04 server shutdown: shutting down for system reboot
    May 21 05:05:05 server init: Switching to runlevel: 6
     
  3. 4u123

    4u123 Well-Known Member
    PartnerNOC

    Joined:
    Jan 2, 2006
    Messages:
    765
    Likes Received:
    1
    Trophy Points:
    18
    /var/spool/cron/root

    0 1 * * * /scripts/cpbackup
    */15 * * * * /usr/local/cpanel/whostmgr/bin/dnsqueue > /dev/null 2>&1
    25 17 * * * cd /usr/local/cpanel/whostmgr/docroot/cgi/fantastico/scripts/ ; /usr/local/cpanel/3rdparty/bin/php cron.php > /dev/null 2>&1
    2,58 * * * * /usr/local/bandmin/bandmin
    0 0 * * * /usr/local/bandmin/ipaddrmap
    0 0 * * * echo '' > /etc/apf/deny_hosts.rules;/etc/apf/apf -f;/etc/apf/apf -r;/sbin/iptables -F
    3 0 * * * /scripts/upcp
    0 6 * * * /scripts/exim_tidydb > /dev/null 2>&1
    52 0 * * * /usr/local/cpanel/whostmgr/docroot/cgi/cpaddons_report.pl --notify
    */5 * * * * /usr/local/cpanel/bin/dcpumon >/dev/null 2>&1
     
  4. nyjimbo

    nyjimbo Well-Known Member

    Joined:
    Jan 25, 2003
    Messages:
    1,125
    Likes Received:
    0
    Trophy Points:
    36
    Location:
    New York
    Just for the heck of it, did you investigate the accounts of "bcouncil" and "kevprice" ?. Remember that individual users can have their own crontabs and if I am reading your logs right (it's early so forgive me if I get it wrong), it looks like those two accounts around 9:00 do some kind of cron job.

    Your 5:00 log doesn't show any cron before 5:01 so I don't know if you edited it out or if you just didnt have anything there. Your 5:00 spike is before the listed cron logged events.
     
  5. 4u123

    4u123 Well-Known Member
    PartnerNOC

    Joined:
    Jan 2, 2006
    Messages:
    765
    Likes Received:
    1
    Trophy Points:
    18
    Yep, I checked those out.

    kevprice runs a script every 15 mins - "send_reminders.php" Its from an installation of "web calendar" The calendar files are there but hes deleted the database.

    bcouncil also runs a "send_reminders.php" script from his domain every 15 minutes but the file doesnt exist. He runs another script scheduled at 15 minutes also which doesnt exist either. Ive removed all of those cron jobs but I am sure they have no impact on this issue.
     
  6. 4u123

    4u123 Well-Known Member
    PartnerNOC

    Joined:
    Jan 2, 2006
    Messages:
    765
    Likes Received:
    1
    Trophy Points:
    18
    Again this morning...



    - Events Summary:
    Total event count: 7
    Average event count: 7

    - Service Summary:
    No service modules enabled - edit conf.sim

    - System Summary:
    LOAD [22.19 - status critical - 1 events]

    - SIM Log:
    [05/22/06 08:15:02]: LOAD 0.35 (status good)
    [05/22/06 08:20:01]: LOAD 0.30 (status good)
    [05/22/06 08:25:01]: LOAD 0.50 (status good)
    [05/22/06 08:30:02]: LOAD 0.36 (status good)
    [05/22/06 08:35:02]: LOAD 0.39 (status good)
    [05/22/06 08:40:01]: LOAD 0.64 (status good)
    [05/22/06 08:45:01]: LOAD 0.48 (status good)
    [05/22/06 08:50:01]: LOAD 0.44 (status good)
    [05/22/06 08:55:01]: LOAD 0.29 (status good)
    [05/22/06 09:00:01]: LOAD 0.35 (status good)
    [05/22/06 09:05:01]: LOAD 0.52 (status good)
    [05/22/06 09:10:02]: LOAD 0.25 (status good)
    [05/22/06 09:15:01]: LOAD 0.32 (status good)
    [05/22/06 09:20:01]: LOAD 4.27 (status good)
    [05/22/06 09:25:01]: LOAD 22.19 (status critical)

    - System Log:
    May 22 09:20:08 server crond(pam_unix)[27702]: session closed for user root
    May 22 09:20:08 server crond(pam_unix)[27703]: session closed for user root
    May 22 09:20:08 server crond(pam_unix)[27709]: session closed for user root
    May 22 09:22:03 server crond(pam_unix)[28326]: session opened for user root by (uid=0)
    May 22 09:22:35 server crond(pam_unix)[28326]: session closed for user root
    May 22 09:22:39 server crond(pam_unix)[27707]: session closed for user root
    May 22 09:24:01 server crond(pam_unix)[28915]: session opened for user root by (uid=0)
    May 22 09:24:07 server crond(pam_unix)[28915]: session closed for user root
    May 22 09:25:01 server crond(pam_unix)[29043]: session opened for user root by (uid=0)
    May 22 09:25:01 server crond(pam_unix)[29044]: session opened for user root by (uid=0)
    May 22 09:25:01 server crond(pam_unix)[29045]: session opened for user root by (uid=0)
    May 22 09:25:05 server crond(pam_unix)[29044]: session closed for user root
    May 22 09:25:10 server crond(pam_unix)[29045]: session closed for user root
    May 22 09:25:11 server wall[29123]: wall: user root broadcasted 1 lines (58 chars)
    May 22 09:25:12 server shutdown: shutting down for system reboot
     
  7. 4u123

    4u123 Well-Known Member
    PartnerNOC

    Joined:
    Jan 2, 2006
    Messages:
    765
    Likes Received:
    1
    Trophy Points:
    18
    Ahh, between 09:15 and 09:20...

    May 22 09:15:03 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1747
    May 22 09:15:04 server stunnel: LOG5[3785:4143856560]: Connection closed: 25117 bytes sent to SSL, 853 bytes sent to socket
    May 22 09:15:04 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1748
    May 22 09:15:05 server stunnel: LOG5[3785:4143856560]: Connection closed: 2107 bytes sent to SSL, 678 bytes sent to socket
    May 22 09:15:05 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1749
    May 22 10:15:05 server crond(pam_unix)[13721]: session closed for user root
    May 22 09:15:05 server stunnel: LOG5[3785:4143856560]: Connection closed: 1037 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:05 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1750
    May 22 09:15:05 server stunnel: LOG5[3785:4143856560]: Connection closed: 2712 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:12 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1751
    May 22 09:15:13 server stunnel: LOG5[3785:4143856560]: Connection closed: 27927 bytes sent to SSL, 853 bytes sent to socket
    May 22 09:15:13 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1752
    May 22 09:15:14 server stunnel: LOG5[3785:4143856560]: Connection closed: 2107 bytes sent to SSL, 678 bytes sent to socket
    May 22 09:15:14 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1753
    May 22 09:15:14 server stunnel: LOG5[3785:4143856560]: Connection closed: 1037 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:14 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1754
    May 22 09:15:14 server stunnel: LOG5[3785:4143856560]: Connection closed: 2712 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:17 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1755
    May 22 09:15:18 server stunnel: LOG5[3785:4143856560]: Connection closed: 23012 bytes sent to SSL, 853 bytes sent to socket
    May 22 09:15:18 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1756
    May 22 09:15:19 server stunnel: LOG5[3785:4143717296]: Connection closed: 2712 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:19 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1757
    May 22 09:15:19 server stunnel: LOG5[3785:4143717296]: Connection closed: 2107 bytes sent to SSL, 678 bytes sent to socket
    May 22 10:15:20 server pure-ftpd: (bcouncil@203.162.33.222) [NOTICE] /home/bcouncil//public_html/editnews/index.php uploaded (5749 bytes, 0.51KB/sec)
    May 22 10:15:22 server pure-ftpd: (bcouncil@203.162.33.222) [INFO] Can't change directory to /public_html/editnews/_notes: No such file or directory
    May 22 10:15:23 server pure-ftpd: (bcouncil@203.162.33.222) [INFO] Can't change directory to /public_html/editnews/_notes/: No such file or directory
    May 22 09:15:24 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1758
    May 22 09:15:24 server stunnel: LOG5[3785:4143717296]: Connection closed: 40790 bytes sent to SSL, 853 bytes sent to socket
    May 22 09:15:25 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1759
    May 22 09:15:25 server stunnel: LOG5[3785:4143717296]: Connection closed: 2712 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:25 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1760
    May 22 09:15:25 server stunnel: LOG5[3785:4143717296]: Connection closed: 2107 bytes sent to SSL, 678 bytes sent to socket
    May 22 09:15:29 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1761
    May 22 09:15:30 server stunnel: LOG5[3785:4143717296]: Connection closed: 46966 bytes sent to SSL, 841 bytes sent to socket
    May 22 09:15:30 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1762
    May 22 09:15:31 server stunnel: LOG5[3785:4143717296]: Connection closed: 2712 bytes sent to SSL, 674 bytes sent to socket
    May 22 09:15:31 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1763
    May 22 09:15:31 server stunnel: LOG5[3785:4143717296]: Connection closed: 2107 bytes sent to SSL, 666 bytes sent to socket
    May 22 09:15:37 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1764
    May 22 09:15:38 server stunnel: LOG5[3785:4143717296]: Connection closed: 25110 bytes sent to SSL, 807 bytes sent to socket
    May 22 09:15:38 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1765
    May 22 09:15:39 server stunnel: LOG5[3785:4143717296]: Connection closed: 2107 bytes sent to SSL, 644 bytes sent to socket
    May 22 09:15:39 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1766
    May 22 09:15:39 server stunnel: LOG5[3785:4143717296]: Connection closed: 2712 bytes sent to SSL, 652 bytes sent to socket
    May 22 09:15:39 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1767
    May 22 09:15:39 server stunnel: LOG5[3785:4143717296]: Connection closed: 437 bytes sent to SSL, 628 bytes sent to socket
    May 22 09:15:55 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1768
    May 22 09:15:56 server stunnel: LOG5[3785:4143717296]: Connection closed: 25730 bytes sent to SSL, 819 bytes sent to socket
    May 22 09:15:56 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1769
    May 22 09:15:57 server stunnel: LOG5[3785:4143717296]: Connection closed: 2712 bytes sent to SSL, 686 bytes sent to socket
    May 22 09:15:57 server stunnel: LOG5[3785:4143717296]: webmailhttps connected from 81.178.116.207:1770
    May 22 09:15:57 server stunnel: LOG5[3785:4143856560]: webmailhttps connected from 81.178.116.207:1771
    May 22 09:15:57 server stunnel: LOG5[3785:4143717296]: Connection closed: 24371 bytes sent to SSL, 641 bytes sent to socket
    May 22 09:15:57 server stunnel: LOG5[3785:4143856560]: Connection closed: 2107 bytes sent to SSL, 678 bytes sent to socket

    These continue until the server is rebooted.
     
Loading...

Share This Page