Skip to main content

Downtimes - cause unknown

scullydion
Hi I run a couple of wordpress websites on VPS and I still seem to be experiencing daily downtimes. Thankfully they are now never for more than a couple of minutes, but it shouldn't be happening. My last fix was to disable xlmrpc.php and that kept things running smooth for a good while... Here are some log reports from which may show what is happening during the downtime - I think it has something to do with people trying to hack my e-mail?:
lfd log: Jan 23 02:02:00 server lfd[12490]: *Email Queue* Unable to obtain exim queue length within 30 seconds - Timed out Jan 23 02:02:48 server lfd[12559]: *LOAD* 5 minute load average is 10.14, threshold is 6 - email sent Jan 23 02:02:55 server lfd[12493]: Directory Watching terminated after 40 seconds Jan 23 02:03:18 server lfd[12493]: LF_DIRWATCH taking 40 seconds, temporarily throttled to run every 900 seconds Jan 23 02:11:42 server lfd[14615]: *Excessive Processes* User:pp Kill:0 Process Count:12 error_log: [Sat Jan 23 02:00:02.741109 2016] [:error] [pid 5164] [client 127.0.0.1] ModSecurity: Access denied with code 406 (phase 2). Match of "rx ^apache.*perl" against "REQUEST_HEADERS:User-Agent" required. [file "/usr/local/apache/conf/modsec2.user.conf"> [line "58"> [id "990011"> [msg "Request Indicates an automated program explored the site"> [severity "NOTICE"> [hostname "127.0.0.1"> [uri "/whm-server-status"> [unique_id "VqLeotWv0bMAABQsmi0AAAAI"> [Sat Jan 23 02:00:09.320098 2016] [:error] [pid 3741] [client 127.0.0.1] ModSecurity: Access denied with code 406 (phase 2). Match of "rx ^apache.*perl" against "REQUEST_HEADERS:User-Agent" required. [file "/usr/local/apache/conf/modsec2.user.conf"> [line "58"> [id "990011"> [msg "Request Indicates an automated program explored the site"> [severity "NOTICE"> [hostname "127.0.0.1"> [uri "/whm-server-status"> [unique_id "VqLeqdWv0bMAAA6dSVoAAAAA"> [Sat Jan 23 02:03:55.166159 2016] [access_compat:error] [pid 12580] [client 141.101.104.90:55467] AH01797: client denied by server configuration: /home/domain/public_html/xmlrpc.php [Sat Jan 23 02:05:11.883515 2016] [:error] [pid 12547] [client 127.0.0.1] ModSecurity: Access denied with code 406 (phase 2). Match of "rx ^apache.*perl" against "REQUEST_HEADERS:User-Agent" required. [file "/usr/local/apache/conf/modsec2.user.conf"> [line "58"> [id "990011"> [msg "Request Indicates an automated program explored the site"> [severity "NOTICE"> [hostname "127.0.0.1"> [uri "/whm-server-status"> [unique_id "VqLf19Wv0bMAADEDgrgAAAAQ"> [Sat Jan 23 02:05:12.602328 2016] [:error] [pid 12715] [client 127.0.0.1] ModSecurity: Access denied with code 406 (phase 2). Match of "rx ^apache.*perl" against "REQUEST_HEADERS:User-Agent" required. [file "/usr/local/apache/conf/modsec2.user.conf"> [line "58"> [id "990011"> [msg "Request Indicates an automated program explored the site"> [severity "NOTICE"> [hostname "127.0.0.1"> [uri "/whm-server-status"> [unique_id "VqLf2NWv0bMAADGrze4AAAAc"> [Sat Jan 23 02:06:21.741501 2016] [access_compat:error] [pid 12546] [client 141.101.104.228:58623] AH01797: client denied by server configuration: /home/rgdomain/public_html/xmlrpc.php [2016-01-23 02:00:11 +0000] info [backup] Started at Sat Jan 23 02:00:07 2016 [23-Jan-2016 02:00:10 UTC] PHP Warning: array_keys() expects parameter 1 to be array, null given in /usr/local/cpanel/whostmgr/docroot/cgi/srbl/black.php on line 32 Cron Jan 23 02:00:01 server CROND[11843]: (root) CMD (/usr/lib64/sa/sa1 1 1) Jan 23 02:00:01 server CROND[11844]: (root) CMD (/usr/local/sbin/lsm -c >> /dev/null 2>&1) Jan 23 02:00:01 server CROND[11845]: (root) CMD (sh /root/tmon.sh) Jan 23 02:00:01 server CROND[11853]: (root) CMD (/usr/local/cpanel/bin/backup) Jan 23 02:00:01 server CROND[11852]: (root) CMD (/root/clearcache.sh >/dev/null 2>&1) Jan 23 02:00:01 server CROND[11849]: (root) CMD (/usr/local/cpanel/3rdparty/bin/php-cgi -q /usr/local/cpanel/whostmgr/docroot/cgi/srbl/black.php > /dev/null 2>&1) Jan 23 02:00:01 server CROND[11850]: (root) CMD (/usr/local/cpanel/scripts/dcpumon-wrapper >/dev/null 2>&1) Jan 23 02:00:01 server CROND[11846]: (root) CMD (/usr/local/maldetect/maldet --mkpubpaths >> /dev/null 2>&1) Jan 23 02:01:05 server CROND[12463]: (root) CMD (run-parts /etc/cron.hourly) Jan 23 02:01:06 server run-parts(/etc/cron.hourly)[12463]: starting 0anacron Jan 23 02:01:06 server anacron[12475]: Anacron started on 2016-01-23 Jan 23 02:01:06 server run-parts(/etc/cron.hourly)[12477]: finished 0anacron Jan 23 02:01:06 server run-parts(/etc/cron.hourly)[12463]: starting mail.sh Jan 23 02:01:07 server anacron[12475]: Jobs will be executed sequentially Jan 23 02:01:07 server anacron[12475]: Normal exit (0 jobs run) Jan 23 02:02:01 server run-parts(/etc/cron.hourly)[12509]: finished mail.sh Jan 23 02:02:01 server CROND[12513]: (root) CMD (/usr/local/bandmin/bandmin) Jan 23 02:02:01 server CROND[12514]: (root) CMD (sh /root/tmon.sh) Jan 23 02:04:01 server CROND[12665]: (root) CMD (sh /root/tmon.sh) Jan 23 02:05:03 server CROND[12806]: (root) CMD (/usr/local/cpanel/scripts/dcpumon-wrapper >/dev/null 2>&1) Jan 23 02:06:01 server CROND[13398]: (root) CMD (sh /root/tmon.sh) Jan 23 02:08:01 server CROND[13614]: (root) CMD (sh /root/tmon.sh) exim 2016-01-23 02:00:08 cwd=/etc/csf 4 args: /usr/sbin/sendmail -f root -t 2016-01-23 02:00:13 cwd=/ 2 args: /usr/sbin/exim -bpu 2016-01-23 02:00:14 1aMnUo-00036R-H5 <= root@server.server.com U=root P=local S=1405 T="lfd on server.server.com: Log Scanner Report for 02:00, (lines:6)" for root 2016-01-23 02:00:14 cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc 1aMnUo-00036R-H5 2016-01-23 02:00:16 1aMnUo-00036R-H5 => me@myself.com R=lookuphost T=remote_smtp H=mx1.hotmail.com [65.55.33.119] X=TLSv1.2:ECDHE-RSA-AES256-SHA384:256 CV=yes C="250 Queued mail for delivery" 2016-01-23 02:00:16 1aMnUo-00036R-H5 Completed 2016-01-23 02:01:07 cwd=/ 2 args: exim -bpc 2016-01-23 02:01:30 cwd=/etc/csf 2 args: /usr/sbin/exim -bpc 2016-01-23 02:02:48 cwd=/etc/csf 4 args: /usr/sbin/sendmail -f root -t 2016-01-23 02:03:07 SMTP connection from [192.0.96.41]:55976 (TCP/IP connection count = 1) 2016-01-23 02:03:45 cwd=/etc/csf 4 args: /usr/sbin/sendmail -f root -t 2016-01-23 02:04:15 1aMnXS-0003GX-HR <= root@server.server.com U=root P=local S=550 T="lfd on server.server.com: Email queue size alert" for root 2016-01-23 02:04:15 1aMnXS-0003GX-HR no immediate delivery: load average 27.66 2016-01-23 02:04:24 1aMnYJ-0003Hs-Nh <= root@server.server.com U=root P=local S=35646 T="lfd on server.server.com: High 5 minute load average alert - 10.14" for root 2016-01-23 02:04:24 1aMnYJ-0003Hs-Nh no immediate delivery: load average 27.25 2016-01-23 02:05:02 SMTP connection from [192.0.97.250]:33988 (TCP/IP connection count = 2) 2016-01-23 02:05:17 cwd=/ 2 args: /usr/sbin/exim -bpu 2016-01-23 02:05:17 SMTP connection from [192.0.85.213]:23499 (TCP/IP connection count = 3) 2016-01-23 02:05:19 SMTP connection from [127.0.0.1]:36711 (TCP/IP connection count = 4) 2016-01-23 02:05:20 SMTP connection from (localhost) [127.0.0.1]:36711 closed by QUIT 2016-01-23 02:05:36 SMTP connection from smtp-backup-out2.dca.wordpress.com [192.0.97.250]:33988 lost while reading message data (header) 2016-01-23 02:05:45 SMTP connection from [192.0.85.11]:5047 (TCP/IP connection count = 3) 2016-01-23 02:05:48 SMTP connection from [192.0.97.250]:30620 (TCP/IP connection count = 4) 2016-01-23 02:05:48 SMTP connection from smtp-backup-out2.dfw.wordpress.com [192.0.85.213]:23499 lost while reading message data (header) 2016-01-23 02:06:16 SMTP connection from smtp-backup.dfw.wordpress.com [192.0.85.11]:5047 lost while reading message data (header) 2016-01-23 02:06:17 SMTP connection from [209.85.213.70]:34444 (TCP/IP connection count = 3) 2016-01-23 02:06:19 SMTP connection from smtp-backup-out2.dca.wordpress.com [192.0.97.250]:30620 lost while reading message data (header) 2016-01-23 02:06:59 H=mail-vk0-f70.google.com [209.85.213.70]:34444 Warning: "Increment Connection Ratelimit - mail-vk0-f70.google.com [209.85.213.70]:34444 because of RBL match" 2016-01-23 02:06:59 H=mail-vk0-f70.google.com [209.85.213.70]:34444 X=TLSv1.2:AES128-GCM-SHA256:128 CV=no F=<3On2iVhQKBHkdlldibXiboqp-klobmivdlldib.ZljfkcloltbkXdXkabo.Zlj@alerts.bounces.google.com> rejected RCPT : "JunkMail rejected - mail-vk0-f70.google.com [209.85.213.70]:34444 is in an RBL, see Blocked - see SpamCop.net - Blocking List ( bl.spamcop.net )" 2016-01-23 02:06:59 SMTP connection from mail-vk0-f70.google.com [209.85.213.70]:34444 closed by DROP in ACL 2016-01-23 02:07:24 1aMnYX-0003Gx-Sl spam acl condition: error reading from spamd socket: Connection timed out 2016-01-23 02:07:24 1aMnYX-0003Gx-Sl H=smtp2.dca.wordpress.com [192.0.96.41]:55976 Warning: "SpamAssassin as rosebdes detected message as NOT spam ()" 2016-01-23 02:07:24 1aMnYX-0003Gx-Sl malware acl condition: clamd: unable to connect to UNIX socket (/var/clamd): No such file or directory 2016-01-23 02:07:24 1aMnYX-0003Gx-Sl H=smtp2.dca.wordpress.com [192.0.96.41]:55976 Warning: Message has been scanned: no virus or other harmful content was found 2016-01-23 02:07:24 1aMnYX-0003Gx-Sl <= info=rbddomain.com@bounces.jetpack.me H=smtp2.dca.wordpress.com [192.0.96.41]:55976 P=esmtps X=TLSv1.2:DHE-RSA-AES256-GCM-SHA384:256 CV=no S=8764 id=03b0de3a092140ea123127384a59dc35@wordpress.com T="[Jetpack Monitor] We noticed that your site www.rbddomain.com was down!" for info@rbddomain.com 2016-01-23 02:07:24 SMTP connection from smtp2.dca.wordpress.com [192.0.96.41]:55976 closed by QUIT 2016-01-23 02:07:24 cwd=/var/spool/exim 3 args: /usr/sbin/exim -Mc 1aMnYX-0003Gx-Sl 2016-01-23 02:07:25 1aMnYX-0003Gx-Sl => info R=virtual_user T=virtual_userdelivery 2016-01-23 02:07:25 1aMnYX-0003Gx-Sl => rose (info@rbddomain.com) R=virtual_user T=virtual_userdelivery 2016-01-23 02:07:25 1aMnYX-0003Gx-Sl Completed 2016-01-23 02:07:49 SMTP connection from [192.0.96.239]:56794 (TCP/IP connection count = 1) 2016-01-23 02:07:51 SMTP connection from [192.0.97.249]:51648 (TCP/IP connection count = 2) 2016-01-23 02:08:19 SMTP connection from [192.0.97.107]:13339 (TCP/IP connection count = 3) 2016-01-23 02:08:21 SMTP connection from smtp-backup-out1.dca.wordpress.com [192.0.97.249]:51648 lost while reading message data (header) 2016-01-23 02:08:39 SMTP connection from [127.0.0.1]:36750 (TCP/IP connection count = 3) 2016-01-23 02:08:39 SMTP connection from (localhost) [127.0.0.1]:36750 closed by QUIT 2016-01-23 02:08:49 SMTP connection from smtp-backup.dca.wordpress.com [192.0.97.107]:13339 lost while reading message data (header) 2016-01-23 02:08:53 SMTP connection from [146.185.239.5]:8018 (TCP/IP connection count = 2) 2016-01-23 02:08:53 no host name found for IP address 146.185.239.5
All suggests / help wwelcome! Thanks Clare

Comments

7 comments

Date Votes
  • cPanelMichael
    Hello :) I suggest accessing your server when the load average is high and reviewing this thread to determine how to best handle the high load average: Troubleshooting high server loads on Linux servers Thank you.
    0
  • scullydion
    Hi I think I'm getting closer to tracking the cause. I'm still getting "High 5 minute load average alert" e-mails for a spike around 2am. I'm using cloudlflare and have now installed mod_cloudflare so that I can track down the IPs. Last night's notificaion e-mail is the first true reading I have, however I'm struggling to understand what's really going on and if the IPs that are causing the high CPU usage are actually doing something dodgy or not. Anyway, here's the e-mail I got:
    Apache Server Status for 127.0.0.1 (via 127.0.0.1) Server Version: Apache/2.4.18 (Unix) OpenSSL/1.0.1e-fips mod_bwlimited/1.4 Server MPM: prefork Server Built: Feb 8 2016 14:32:28 ________________________________________ Current Time: Tuesday, 09-Feb-2016 01:52:04 GMT Restart Time: Monday, 08-Feb-2016 16:33:47 GMT Parent Server Config. Generation: 6 Parent Server MPM Generation: 5 Server uptime: 9 hours 18 minutes 17 seconds Server load: 17.59 7.03 2.85 Total accesses: 6167 - Total Traffic: 112.5 MB CPU Usage: u3.06 s2.8 cu238.9 cs49.06 - .877% CPU load .184 requests/sec - 3520 B/second - 18.7 kB/request 5 requests currently being processed, 5 idle workers _....W._..............W__WW._.W................................. ................................................................ ...................... Scoreboard Key: "_" Waiting for Connection, "S" Starting up, "R" Reading Request, "W" Sending Reply, "K" Keepalive (read), "D" DNS Lookup, "C" Closing connection, "L" Logging, "G" Gracefully finishing, "I" Idle cleanup of worker, "." Open slot with no current process Srv PID Acc M CPU SS Req Conn Child Slot Client VHost Request 0-5 9221 0/28/435 _ 25.42 34 34127 0.0 0.36 7.67 192.0.102.40 XXX.XXX.XXX.XXX:80 NULL 1-5 - 0/0/419 . 8.09 1602 0 0.0 0.00 9.62 ::1 server.example.com:443 OPTIONS * HTTP/1.0 2-5 - 0/0/338 . 13.60 1610 0 0.0 0.00 7.31 ::1 server.example.com:443 OPTIONS * HTTP/1.0 3-5 - 0/0/402 . 12.29 1613 0 0.0 0.00 6.74 ::1 server.example.com:443 OPTIONS * HTTP/1.0 4-5 - 0/0/322 . 17.34 1608 0 0.0 0.00 7.46 ::1 server.example.com:443 OPTIONS * HTTP/1.0 5-5 9215 0/25/285 W 26.83 76 0 0.0 0.24 4.35 66.249.65.44 CLV.com:80 GET /welcome-to-fabulous-las-vegas-sign/ HTTP/1.1 6-5 - 0/0/339 . 9.09 1612 10 0.0 0.00 6.61 ::1 server.example.com:443 OPTIONS * HTTP/1.0 7-5 10747 0/23/257 _ 23.32 119 2 0.0 0.28 5.04 127.0.0.1 server.example.com:80 GET /whm-server-status?auto HTTP/1.1 8-5 - 0/0/215 . 6.66 1611 0 0.0 0.00 5.47 ::1 server.example.com:443 OPTIONS * HTTP/1.0 9-5 - 0/0/265 . 0.03 1607 0 0.0 0.00 5.74 ::1 server.example.com:443 OPTIONS * HTTP/1.0 10-5 - 0/0/310 . 0.09 1603 0 0.0 0.00 4.55 ::1 server.example.com:443 OPTIONS * HTTP/1.0 11-5 - 0/0/218 . 0.01 1616 0 0.0 0.00 3.10 ::1 server.example.com:443 OPTIONS * HTTP/1.0 12-5 - 0/0/276 . 0.02 1615 0 0.0 0.00 4.42 ::1 server.example.com:443 OPTIONS * HTTP/1.0 13-5 - 0/0/176 . 0.02 1614 0 0.0 0.00 3.00 ::1 server.example.com:443 OPTIONS * HTTP/1.0 14-5 - 0/0/210 . 0.04 1609 0 0.0 0.00 3.40 ::1 server.example.com:443 OPTIONS * HTTP/1.0 15-5 - 0/0/135 . 0.02 1605 0 0.0 0.00 2.06 ::1 server.example.com:443 OPTIONS * HTTP/1.0 16-5 - 0/0/208 . 0.04 1604 0 0.0 0.00 3.19 ::1 server.example.com:443 OPTIONS * HTTP/1.0 17-5 - 0/0/87 . 0.09 1600 0 0.0 0.00 1.44 ::1 server.example.com:443 OPTIONS * HTTP/1.0 18-5 - 0/0/181 . 0.02 1601 0 0.0 0.00 3.17 ::1 server.example.com:443 OPTIONS * HTTP/1.0 19-5 - 0/0/89 . 0.00 1617 0 0.0 0.00 1.21 ::1 server.example.com:443 OPTIONS * HTTP/1.0 20-5 - 0/0/39 . 2.33 1606 0 0.0 0.00 0.57 ::1 server.example.com:443 OPTIONS * HTTP/1.0 21-5 - 0/0/67 . 0.02 1599 0 0.0 0.00 1.00 ::1 server.example.com:443 OPTIONS * HTTP/1.0 22-5 12211 0/13/28 W 11.07 98 0 0.0 0.15 0.23 79.67.158.121 CLV.com:443 GET /extraterrestrial-highway/ HTTP/1.1 23-5 12212 0/13/68 _ 11.06 76 3847 0.0 0.20 0.77 192.0.102.40 XXX.XXX.XXX.XXX:80 NULL 24-5 12214 0/13/50 _ 19.61 98 3882 0.0 0.18 0.67 66.249.66.103 XXX.XXX.XXX.XXX:80 NULL 25-5 12215 0/13/29 W 9.84 65 0 0.0 0.18 0.27 192.0.102.40 TVV.com:80 HEAD / HTTP/1.1 26-5 12216 0/13/134 W 11.91 0 0 0.0 0.10 3.48 127.0.0.1 server.example.com:80 GET /whm-server-status HTTP/1.1 27-5 - 0/0/49 . 0.01 1598 0 0.0 0.00 0.76 ::1 server.example.com:443 OPTIONS * HTTP/1.0 28-5 12218 0/13/66 _ 17.64 68 4174 0.0 0.15 0.98 66.249.66.103 XXX.XXX.XXX.XXX:80 NULL 29-3 - 0/0/42 . 0.01 11010 0 0.0 0.00 0.57 ::1 server.example.com:443 OPTIONS * HTTP/1.0 30-5 9214 0/27/123 W 18.47 65 0 0.0 0.33 2.65 208.115.111.73 PP.com:80 GET /services/ HTTP/1.1 31-3 - 0/0/8 . 0.01 11007 0 0.0 0.00 0.01 ::1 server.example.com:443 OPTIONS * HTTP/1.0 32-3 - 0/0/25 . 0.01 11008 0 0.0 0.00 0.32 ::1 server.example.com:443 OPTIONS * HTTP/1.0 33-3 - 0/0/9 . 0.78 11005 0 0.0 0.00 0.01 ::1 server.example.com:443 OPTIONS * HTTP/1.0 34-3 - 0/0/27 . 6.30 10834 0 0.0 0.00 0.22 ::1 server.example.com:443 OPTIONS * HTTP/1.0 35-3 - 0/0/43 . 4.54 10838 0 0.0 0.00 0.64 ::1 server.example.com:443 OPTIONS * HTTP/1.0 36-3 - 0/0/15 . 6.78 10839 1 0.0 0.00 0.13 ::1 server.example.com:443 OPTIONS * HTTP/1.0 37-3 - 0/0/28 . 5.45 10836 0 0.0 0.00 0.18 ::1 server.example.com:443 OPTIONS * HTTP/1.0 38-3 - 0/0/20 . 0.01 10999 0 0.0 0.00 0.21 ::1 server.example.com:443 OPTIONS * HTTP/1.0 39-3 - 0/0/18 . 0.00 11033 1 0.0 0.00 0.15 ::1 server.example.com:443 OPTIONS * HTTP/1.0 40-3 - 0/0/79 . 0.00 11034 1 0.0 0.00 2.77 ::1 server.example.com:443 OPTIONS * HTTP/1.0 41-0 - 0/0/18 . 19.24 31863 9 0.0 0.00 0.24 ::1 server.example.com:443 OPTIONS * HTTP/1.0 42-0 - 0/0/2 . 0.00 32152 0 0.0 0.00 0.00 ::1 server.example.com:443 OPTIONS * HTTP/1.0 43-0 - 0/0/1 . 0.00 33009 0 0.0 0.00 0.00 ::1 server.example.com:443 OPTIONS * HTTP/1.0 44-0 - 0/0/10 . 5.71 32764 0 0.0 0.00 0.09 ::1 server.example.com:443 OPTIONS * HTTP/1.0 45-0 - 0/0/1 . 0.00 33008 1 0.0 0.00 0.00 ::1 server.example.com:443 OPTIONS * HTTP/1.0 46-0 - 0/0/1 . 0.00 33007 1 0.0 0.00 0.00 ::1 server.example.com:443 OPTIONS * HTTP/1.0
    Again, many thanks for your time and input! Clare
    0
  • cPanelMichael
    Hello :) Were you able to troubleshoot further and track down the cause of the issue? Thank you.
    0
  • scullydion
    Hi! Yes! I think I figured it out just last night in fact, I disabled the automatic server updates and for the first time in a while there were no notifications. I have now selected manual updates - is it normal for updates to cause this? I will leave on this setting and keep monitoring. Do you know how often updates are available on average? Just so I know how often I should check this. Thanks, Clare
    0
  • cPanelMichael

    cPanel update preferences are documented at: https://docs.cpanel.net/whm/server-configuration/update-preferences/ What's the load average increase during cPanel updates? Thank you.

    0
  • scullydion
    After lots of investigations my problems actually boiled down to my server specs, I upgraded and everything ran much better :)
    0
  • cPanelMichael
    I'm happy to see you were able to address the issue. Thank you for updating us with the outcome.
    0

Please sign in to leave a comment.

Didn't find what you were looking for?

New post