Linode Forum
Linode Community Forums
 FAQFAQ    SearchSearch    MembersMembers      Register Register 
 LoginLogin [ Anonymous ] 
Post new topic  Reply to topic
Author Message
PostPosted: Sun Mar 10, 2013 5:37 pm 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
Hi Guys,

So I am a relative linux/vps newbie running a LEMP server, but have had my linode successfully setup and running a few wordpress blogs since January.. until today. I logged into Google Analytics app on my phone earlier and saw that traffic was waay down on all my sites... I thought must be because it is such a nice day outside. But then I check my email just a while ago and got one from linode that says:

Your Linode, linode182850, has exceeded the notification threshold (1000) for disk io rate by averaging 1697.13 for the last 2 hours

When I go and login the dashboard it appears that there has been a huge IO spike since this morning and it appears my sites are down with a 504 Gateway timeout. I tried rebooting my linode but that has not helped. Here are the graphs, any idea what is going on??

https://docs.google.com/file/d/0B6KEPqyasW5kOHlGWENZb0xnM3M/edit?usp=sharing

https://docs.google.com/file/d/0B6KEPqyasW5kQk5WR1NEQ2FSczg/edit?usp=sharing



free output under my linux user that owns my blogs
Code:
cfauver@mail ~:free             
total       used       free     shared    buffers     cached
Mem:           496        490          5          0          1        264
-/+ buffers/cache:        224        271
Swap:          255         18        237


free output under root
Code:
root@mail ~:free        
total       used       free     shared    buffers     cached
Mem:        508100     488816      19284          0        796     258720
-/+ buffers/cache:     229300     278800
Swap:       262140      19000     243140


Top
   
PostPosted: Sun Mar 10, 2013 5:50 pm 
Offline
Senior Member

Joined: Fri Feb 17, 2012 8:20 pm
Posts: 365
What do your logs say? Access/error logs? Also check things like mail logs / auth.log and syslog/messages to see if there's anything special. Same for PHP-FPM logs if you use it. It should tell you which pool is causing it if there's too much traffic for FPM to handle.


Top
   
PostPosted: Sun Mar 10, 2013 5:57 pm 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
Code:
root@mail ~: tail -f /var/log/debug
Mar 10 17:02:58 mail kernel: CPU 0 irqstacks, hard=df408000 soft=df40a000
Mar 10 17:02:58 mail kernel: Xen: using vcpuop timer interface
Mar 10 17:02:58 mail kernel: CPU 1 irqstacks, hard=df482000 soft=df484000
Mar 10 17:02:58 mail kernel: CPU 2 irqstacks, hard=df490000 soft=df492000
Mar 10 17:02:58 mail kernel: CPU 3 irqstacks, hard=df4be000 soft=df4c0000
Mar 10 17:11:01 mail kernel: iptables denied: IN=eth0 OUT= MAC=f2:3c:91:df:b9:2d:c8:4c:75:f5:f0:3f:08:00 SRC=174.138.171.243 DST=74.207.224.68 LEN=44 TOS=0x00 PREC=0x00 TTL=54 ID=0 DF PROTO=TCP SPT=80 DPT=18914 WINDOW=14600 RES=0x00 ACK SYN URGP=0
Mar 10 17:22:09 mail kernel: iptables denied: IN=eth0 OUT= MAC=f2:3c:91:df:b9:2d:c8:4c:75:f5:f0:3f:08:00 SRC=118.123.255.173 DST=74.207.224.68 LEN=40 TOS=0x00 PREC=0x00 TTL=104 ID=256 PROTO=TCP SPT=6000 DPT=1433 WINDOW=16384 RES=0x00 SYN URGP=0
Mar 10 17:54:04 mail kernel: iptables denied: IN=eth0 OUT= MAC=f2:3c:91:df:b9:2d:c8:4c:75:f5:f8:3f:08:00 SRC=174.132.27.126 DST=74.207.224.68 LEN=44 TOS=0x00 PREC=0x00 TTL=55 ID=23801 PROTO=TCP SPT=80 DPT=51470 WINDOW=16384 RES=0x00 ACK SYN URGP=0
Mar 10 17:58:38 mail kernel: iptables denied: IN=eth0 OUT= MAC=f2:3c:91:df:b9:2d:c8:4c:75:f5:f8:3f:08:00 SRC=58.218.199.250 DST=74.207.224.68 LEN=40 TOS=0x00 PREC=0x00 TTL=110 ID=256 DF PROTO=TCP SPT=12200 DPT=8080 WINDOW=8192 RES=0x00 SYN URGP=0
Mar 10 18:19:28 mail kernel: iptables denied: IN=eth0 OUT= MAC=f2:3c:91:df:b9:2d:c8:4c:75:f5:f8:3f:08:00 SRC=69.162.83.102 DST=74.207.224.68 LEN=92 TOS=0x00 PREC=0x00 TTL=54 ID=55388 PROTO=ICMP TYPE=3 CODE=2 [SRC=74.207.224.68 DST=69.162.83.102 LEN=64 TOS=0x00 PREC=0x00 TTL=245 ID=40512 DF PROTO=47 ]


Code:
root@mail ~: tail -f /var/log/messages
Mar 10 17:02:58 mail kernel: VFS: Mounted root (ext3 filesystem) readonly on dev          ice 202:0.
Mar 10 17:02:58 mail kernel: devtmpfs: mounted
Mar 10 17:02:58 mail kernel: Freeing unused kernel memory: 420k freed
Mar 10 17:02:58 mail kernel: Write protecting the kernel text: 6716k
Mar 10 17:02:58 mail kernel: Write protecting the kernel read-only data: 1548k
Mar 10 17:02:58 mail kernel: NX-protecting the kernel data: 2500k
Mar 10 17:02:58 mail kernel: udevd (1077): /proc/1077/oom_adj is deprecated, ple          ase use /proc/1077/oom_score_adj instead.
Mar 10 17:02:58 mail kernel: Adding 262140k swap on /dev/xvdb.  Priority:-1 exte          nts:1 across:262140k SS
Mar 10 17:02:58 mail kernel: EXT3-fs (xvda): using internal journal
Mar 10 17:25:51 mail kernel: hrtimer: interrupt took 7692400 ns




Code:
root@mail ~: tail -f /var/log/auth.log
Mar 10 18:11:46 mail sshd[2919]: pam_unix(sshd:session): session closed for user cfauver
Mar 10 18:11:55 mail sshd[3135]: Accepted publickey for cfauver from 216.164.38.57 port 56929 ssh2
Mar 10 18:11:55 mail sshd[3135]: pam_unix(sshd:session): session opened for user cfauver by (uid=0)
Mar 10 18:12:09 mail sudo:  cfauver : TTY=pts/0 ; PWD=/home/cfauver ; USER=root ; COMMAND=/bin/bash
Mar 10 18:14:38 mail sshd[3135]: pam_unix(sshd:session): session closed for user cfauver
Mar 10 18:14:53 mail sshd[3229]: Accepted publickey for cfauver from 216.164.38.57 port 56936 ssh2
Mar 10 18:14:53 mail sshd[3229]: pam_unix(sshd:session): session opened for user cfauver by (uid=0)
Mar 10 18:15:26 mail sudo:  cfauver : TTY=pts/0 ; PWD=/home/cfauver ; USER=root ; COMMAND=/bin/bash
Mar 10 18:17:03 mail CRON[3307]: pam_unix(cron:session): session opened for user root by (uid=0)
Mar 10 18:17:04 mail CRON[3307]: pam_unix(cron:session): session closed for user root



Code:
root@mail ~: tail -f /var/log/dmesg
VFS: Mounted root (ext3 filesystem) readonly on device 202:0.
devtmpfs: mounted
Freeing unused kernel memory: 420k freed
Write protecting the kernel text: 6716k
Write protecting the kernel read-only data: 1548k
NX-protecting the kernel data: 2500k
udev: starting version 151
udevd (1077): /proc/1077/oom_adj is deprecated, please use /proc/1077/oom_score_adj instead.
Adding 262140k swap on /dev/xvdb.  Priority:-1 extents:1 across:262140k SS
EXT3-fs (xvda): using internal journal



Code:
root@mail ~: tail -f /var/log/nginx/error.log
2013/03/10 09:24:17 [error] 10650#0: *9253 open() "/var/www/nginx-default/proxyheader.php" failed (2: No                    such file or directory), client: 58.218.199.250, server: localhost, request: "GET http://www.verysurf.c                   om/proxyheader.php HTTP/1.1", host: "www.verysurf.com"
2013/03/10 11:23:51 [error] 10650#0: *15550 open() "/var/www/nginx-default/robots.txt" failed (2: No suc                   h file or directory), client: 198.20.70.114, server: localhost, request: "GET /robots.txt HTTP/1.1", hos                   t: "74.207.224.68"


Code:
root@mail ~: tail -f /var/log/nginx/access.log
157.55.33.17 - - [10/Mar/2013:16:04:19 -0400] "GET /idx/mls-pw7907422-5205_trunnion_trl_woodbridge_va_22192 HTTP/1.1" 301 185 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)"
157.55.32.188 - - [10/Mar/2013:16:50:41 -0400] "GET /robots.txt HTTP/1.1" 301 185 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)"
216.164.38.57 - - [10/Mar/2013:17:00:34 -0400] "GET / HTTP/1.1" 301 185 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:19.0) Gecko/20100101 Firefox/19.0"
216.164.38.57 - - [10/Mar/2013:17:01:06 -0400] "GET / HTTP/1.1" 301 185 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:19.0) Gecko/20100101 Firefox/19.0"
157.55.33.17 - - [10/Mar/2013:17:05:30 -0400] "GET /robots.txt HTTP/1.1" 301 185 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)"
157.55.32.146 - - [10/Mar/2013:17:41:29 -0400] "GET /robots.txt HTTP/1.1" 301 185 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)"
69.165.159.215 - - [10/Mar/2013:18:02:14 -0400] "GET / HTTP/1.1" 301 185 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.1; .NET CLR 1.1.4322)"
69.165.159.215 - - [10/Mar/2013:18:02:14 -0400] "GET / HTTP/1.1" 301 185 "-" "Mozilla/4.0 (compatible; MSIE 5.0; Windows XP) Opera 6.05 [en]"
69.165.159.215 - - [10/Mar/2013:18:02:29 -0400] "GET / HTTP/1.1" 301 185 "-" "Mozilla/4.0 (compatible; MSIE 6.0; Windows NT 5.2; .NET CLR 1.0.3705;)"
157.55.32.86 - - [10/Mar/2013:18:06:32 -0400] "GET /robots.txt HTTP/1.1" 301 185 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)"


(I run Office365 Exchange server so no mail server setup)
Code:
root@mail ~: tail -f /var/log/nginx/mail.*
tail: cannot open `/var/log/nginx/mail.*' for reading: No such file or directory
tail: no files remaining


Top
   
PostPosted: Sun Mar 10, 2013 6:43 pm 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
iotop:
Code:
 2466 be/4 mysql    1791.20 K/s    0.00 B/s  0.00 % 97.52 % mysqld
 2454 be/4 mysql    1688.62 K/s    0.00 B/s  0.00 % 97.50 % mysqld
    1 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % init
    2 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kthreadd]
    3 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [ksoftirqd/0]
    4 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/0:0]
    5 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/0:0H]
    6 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/u:0]
    7 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/u:0H]
    8 rt/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [migration/0]
    9 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [rcu_bh]
   10 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [rcu_sched]
   11 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [ksoftirqd/1]
   12 rt/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [migration/1]
   13 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/1:0]
   14 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/1:0H]
   15 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [ksoftirqd/2]
   16 rt/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [migration/2]
   17 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/2:0]
   18 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/2:0H]
   19 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [ksoftirqd/3]
   20 rt/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [migration/3]
   21 be/4 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/3:0]
   22 be/0 root        0.00 B/s    0.00 B/s  0.00 %  0.00 % [kworker/3:0H]


Top
   
PostPosted: Sun Mar 10, 2013 7:51 pm 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
I think maybe this is the problem, found in my php5-fpm.log...

Code:

[10-Mar-2013 19:18:54] NOTICE: fpm is running, pid 2180
[10-Mar-2013 19:18:54] NOTICE: ready to handle connections
[10-Mar-2013 19:18:58] WARNING: [pool www] seems busy (you may need to increase pm.start_servers, or pm.min/max_spare_servers)$
[10-Mar-2013 19:18:59] WARNING: [pool www] server reached pm.max_children setting (10), consider raising it


I don't really know how to handle it..


Top
   
PostPosted: Sun Mar 10, 2013 9:01 pm 
Offline
Senior Member
User avatar

Joined: Sat Aug 30, 2008 1:55 pm
Posts: 1739
Location: Rochester, New York
Sounds like you've got some rather inefficient MySQL usage going on. Try SHOW PROCESSLIST to ask the MySQL server what's going on right now.

Fire up mysqltuner.pl to see if it has any advice. In particular, turn on the slow_query log to see what's taking so long.

_________________
Code:
/* TODO: need to add signature to posts */


Top
   
PostPosted: Sun Mar 10, 2013 10:21 pm 
Offline
Senior Member

Joined: Tue Feb 19, 2008 10:55 am
Posts: 164
so my guess is the io is cause mostly by swapping, you only have 19M of free swap.
what's happening is (still a guess)
an http request comes in that is handled by php
php, which uses 50MB of memory, opens a DB connection
the DB is soooo slooow that the php process has to sit idly wait for it to return the result, while it's idle it still uses up 50MB of memory.
meanwhile, another http request comes in
eventually you have all these php processes hanging around waiting for the database to finish returning a result that it starts swapping
the swapping causes extra io which slows the database down even more
meanwhile, more request come in.

so, while it might seem logical to increase the number of php processes, this is actually the opposite of what you should do, you need to decrease them so under normal operation it doesn't swap. you have 500MB, lets guess a php process uses 50MB, you can only have a max of 10 php processes running at the same time.
however, you are going to run out of php slots because each one is waiting so long for the database quieres to finish.

so, as hoops said, tune the database. but you'll get the most bang for buck by installing a wordpress caching plugin, then 99% of http requests won't even need to use a php process to handle the query.


Top
   
PostPosted: Mon Mar 11, 2013 5:22 am 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
Well before you'll responded I goofed.. I went in and changed my pm.max_children to 50 and now I can't get into my server by Console, Remote Access, or FTP...

I think I figured out that it is probably WP_Autoblog plugin I have running on a few sites which also imports pictures and I could go in and either delete the plugin via FTP or clear the active plugins in my wordpress tables but it appears I'm locked out, how can I get back in?


Top
   
PostPosted: Mon Mar 11, 2013 5:29 am 
Offline
Senior Member

Joined: Tue Feb 19, 2008 10:55 am
Posts: 164
reboot. you'll want to be quick about logging in after it come back up though


Top
   
PostPosted: Mon Mar 11, 2013 5:34 am 
Offline
Senior Member

Joined: Fri Feb 17, 2012 8:20 pm
Posts: 365
Better get /etc/init.d/php-fpm (or php5-fpm) stop on your copy/paste :)

PS. htop might be handy for showing memory and such through. I find it a lot clearer than normal top and free.


Top
   
PostPosted: Mon Mar 11, 2013 5:54 am 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
Thanks for the help guys! I did a reboot and logged in by ftp the second it rebooted, deleted the autoblog plugin and it cleared the IO problems and now my sites are back and running!

That's great, except now my question is how can I run the auto-blog plugin without this happening again and why was I able to run it on 4 sites for a month and then all of a sudden one day BOOM my IO runs through the roof and my sites won't serve? Do I simply need a bigger linode?

EDIT: Well I thought that was the case.. but actually one site loaded, but now they aren't loading... and one site says "Error establishing database connection"


Top
   
PostPosted: Mon Mar 11, 2013 6:06 am 
Offline
Senior Member

Joined: Fri Feb 17, 2012 8:20 pm
Posts: 365
Can you manually login to mysql? use mysql -u <user> -p <enter>, then fill in password. You could then also execute show full processlist; to see if it's very busy.


Top
   
PostPosted: Mon Mar 11, 2013 6:21 am 
Offline
Senior Member

Joined: Tue Feb 19, 2008 10:55 am
Posts: 164
if i was the admin,

I would reboot again, login and set pm.max_children to 10 (as a starting place) then restart php

then as hoops suggested, run mysqltuner.pl

then install a wordpress cache plugin.

basically your site is receiving more traffic now, and your database has grown, so php is spending more time waiting for queries as well as more php processes required for the extra traffic.

after you've tuned mysql and installed a wordpress cache, then you can look at whether you need up upgrade your linode.

also, depending on what back end is in use, you might need to run mysqlcheck periodically, make it a cron job


Top
   
PostPosted: Mon Mar 11, 2013 6:26 am 
Offline
Senior Member

Joined: Fri Feb 17, 2012 8:20 pm
Posts: 365
chesty wrote:
if i was the admin,

I would reboot again, login and set pm.max_children to 10 (as a starting place) then restart php

then as hoops suggested, run mysqltuner.pl

then install a wordpress cache plugin.

basically your site is receiving more traffic now, and your database has grown, so php is spending more time waiting for queries as well as more php processes required for the extra traffic.

after you've tuned mysql and installed a wordpress cache, then you can look at whether you need up upgrade your linode.

also, depending on what back end is in use, you might need to run mysqlcheck periodically, make it a cron job


Is it really traffic though? The graphs were showing like, 300kbit max, that shouldn't cause these issues.


Top
   
PostPosted: Mon Mar 11, 2013 6:30 am 
Offline
Junior Member

Joined: Fri Dec 21, 2012 8:35 am
Posts: 31
Nuvini wrote:
Can you manually login to mysql? use mysql -u <user> -p <enter>, then fill in password. You could then also execute show full processlist; to see if it's very busy.


Code:
mysql> show full processlist;
+-----+---------+-----------+------+---------+------+-------+-------------------                                     ----+
| Id  | User    | Host      | db   | Command | Time | State | Info                                                       |
+-----+---------+-----------+------+---------+------+-------+-------------------                                     ----+
| 166 | cfauver | localhost | NULL | Sleep   |   67 |       | NULL                                                       |
| 184 | root    | localhost | NULL | Query   |    0 | NULL  | show full processl                                     ist |
+-----+---------+-----------+------+---------+------+-------+-------------------                                     ----+


Top
   
Display posts from previous:  Sort by  
Post new topic  Reply to topic


Who is online

Users browsing this forum: No registered users and 5 guests


You cannot post new topics in this forum
You cannot reply to topics in this forum
You cannot edit your posts in this forum
You cannot delete your posts in this forum

Search for:
Jump to:  
RSS

Powered by phpBB® Forum Software © phpBB Group