Hi,<br><br>Unfortunately the changes did not seem to be the silver bullet I was hoping for - however - although the processes are still sleeping, and the servers are still getting very high loads, it does seem to have helped - downloads are no longer unable to start, which is great! <br>
<br>I'm not sure if it's helpful, but an strace on a sleeping process looks like this:<br><br>io_submit(47044328767488, 1, {{0x13dab860, 0, 0, 0, 66}}) = 1<br>epoll_wait(9, {{EPOLLOUT, {u32=1554189657, u64=47044330982745}}, {EPOLLOUT, {u32=1554179536, u64=47044330972624}}}, 512, 36) = 2<br>
writev(250, [{"\321\4\vS\0313\237F\222\337\246\322\33(\30\245=g\352\271\2\361\244p\240\377Q\314\2371^\256"..., 161636}], 1) = 20440<br>writev(69, [{"\235\337}\33\201\214)\321\343\233\22\346$z\374\2126T\\j\210\250L\250\331{\220\333\323\343\341J"..., 386840}], 1) = 130320<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554194624, u64=47044330987712}}}, 512, 9) = 1<br>writev(222, [{"<\247\260`P\237\2455\236\244\352!\237s\223h\25\206N3[{\351f\31\275\344b\5\204\f\v"..., 396976}], 1) = 95568<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554205480, u64=47044330998568}}}, 512, 26) = 1<br>
writev(286, [{"E\260q\214\346X[\376\305\5\275\352\344`\256q\327\344m\r\236\t\321\354\200\325\333\351E\340\374\232"..., 240116}], 1) = 64240<br>epoll_wait(9, {{EPOLLOUT, {u32=1554195361, u64=47044330988449}}}, 512, 25) = 1<br>
writev(133, [{"\243Y\373y\10\0252\34\32\22\2\36\227\325e\345\333\372=\365./\340\34V\251U\0373\234\35\250"..., 13732}], 1) = 13732<br>io_submit(47044328767488, 1, {{0x12599628, 0, 0, 0, 209}}) = 1<br>epoll_wait(9, {{EPOLLOUT, {u32=1554199961, u64=47044330993049}}}, 512, 5) = 1<br>
writev(49, [{"+\347^\17\322\354\201\20=\35\246b\200\0\214K'z>\344k\331\272Svh\234`\334)|\205"..., 176592}], 1) = 84120<br>epoll_wait(9, {}, 512, 1) = 0<br>epoll_wait(9, {}, 512, 4) = 0<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554179905, u64=47044330972993}}}, 512, 14) = 1<br>epoll_wait(9, {{EPOLLOUT, {u32=1554193521, u64=47044330986609}}}, 512, 10) = 1<br>writev(137, [{"\212\375\216\330'\315^\20|\350N\362\25j\272\304=v\227\210?\3539S\343\6D\265C-\360J"..., 336856}], 1) = 96360<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554181193, u64=47044330974281}}}, 512, 9) = 1<br>writev(79, [{"\321\277\340\360E\323A\352\352\377\357w\357m_\377\377R\0\200\177\365l\200 \314D\24z\21U\0"..., 228056}], 1) = 128480<br>
epoll_wait(9, {}, 512, 3) = 0<br>epoll_wait(9, {}, 512, 8) = 0<br>epoll_wait(9, {}, 512, 2) = 0<br>epoll_wait(9, {{EPOLLOUT, {u32=1554204009, u64=47044330997097}}}, 512, 26) = 1<br>
writev(67, [{"\204-& V\325?\375\33\202B\236\216\r\240\360\17\0103\25\274\3\300>\352\267\211BJ\265\23\327"..., 166588}], 1) = 26280<br>epoll_wait(9, {}, 512, 12) = 0<br>epoll_wait(9, {{EPOLLIN, {u32=6779072, u64=6779072}}}, 512, 14) = 1<br>
read(10, "\1\0\0\0\0\0\0\0", 8) = 8<br>io_getevents(47044328767488, 1, 64, {{0x13dab860, 0x13dab820, 524288, 0}}, {0, 0}) = 1<br>writev(80, [{"X\361N8\2\214\203n\263t\240\\\335\241k\212N\366\24\222\32\201u\267\272\32\v\326=\373\34\v"..., 524288}], 1) = 56608<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554187265, u64=47044330980353}}}, 512, 13) = 1<br>epoll_wait(9, {{EPOLLOUT, {u32=1554183217, u64=47044330976305}}}, 512, 3) = 1<br>epoll_wait(9, {}, 512, 1) = 0<br>epoll_wait(9, {{EPOLLOUT, {u32=1554181744, u64=47044330974832}}}, 512, 13) = 1<br>
writev(121, [{"\371s\222d\231\313\17\t\227\31\33a\315\304\365NZ7\323\200\347\337\260\355\253\203\30\215N\313\260d"..., 331027}], 1) = 49640<br>epoll_wait(9, {}, 512, 2) = 0<br>epoll_wait(9, {}, 512, 8) = 0<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554192968, u64=47044330986056}}}, 512, 12) = 1<br>epoll_wait(9, {{EPOLLIN, {u32=6779072, u64=6779072}}}, 512, 12) = 1<br>read(10, "\1\0\0\0\0\0\0\0", 8) = 8<br>io_getevents(47044328767488, 1, 64, {{0x12599628, 0x125995e8, 524288, 0}}, {0, 0}) = 1<br>
writev(133, [{"&yj\373dw\335\364\232k\310\6\204\363\365=c{V\257\6:\225\354\233\253b\27*\221\4\264"..., 524288}], 1) = 114748<br>epoll_wait(9, {{EPOLLOUT, {u32=1554203825, u64=47044330996913}}}, 512, 6) = 1<br>
epoll_wait(9, {{EPOLLOUT, {u32=1554179536, u64=47044330972624}}}, 512, 5) = 1<br>writev(69, [{"X\4\250\274\3415\212A\20D\30\2122.\23\351n%\226\245\250\242b$\271\t\22/fX\303\263"..., 256520}], 1) = 130320<br>epoll_wait(9, {{EPOLLOUT, {u32=1554192784, u64=47044330985872}}}, 512, 27) = 1<br>
<br><br>An strace -c taken only when a process is in the 'D' state shows:<br><br>[root@HOST16 ~]# time strace -p 22334 -c<br>Process 22334 attached - interrupt to quit<br>Process 22334 detached<br>% time seconds usecs/call calls errors syscall<br>
------ ----------- ----------- --------- --------- ----------------<br> 70.65 0.008273 109 76 io_submit<br> 29.35 0.003437 10 360 writev<br> 0.00 0.000000 0 26 read<br>
0.00 0.000000 0 3 open<br> 0.00 0.000000 0 8 close<br> 0.00 0.000000 0 3 fstat<br> 0.00 0.000000 0 1 ioctl<br>
0.00 0.000000 0 1 socket<br> 0.00 0.000000 0 1 1 connect<br> 0.00 0.000000 0 11 3 recvfrom<br> 0.00 0.000000 0 1 getsockname<br>
0.00 0.000000 0 3 getsockopt<br> 0.00 0.000000 0 44 fcntl<br> 0.00 0.000000 0 26 io_getevents<br> 0.00 0.000000 0 180 epoll_wait<br>
0.00 0.000000 0 4 epoll_ctl<br>------ ----------- ----------- --------- --------- ----------------<br>100.00 0.011710 748 4 total<br><br>real 0m8.570s<br>user 0m0.016s<br>
sys 0m0.028s<br><br>When it's out of sleeping state, about 25% of the time is spent in epoll_wait. I've also noticed that vmstat shows far less frequent swapping, although now instead of 5-10MB regularly, it'll swap ~100MB every 30+ seconds.<br>
<br><br>Cheers,<br><br>Drew<br><br><div class="gmail_quote">On Fri, May 25, 2012 at 2:57 PM, Drew Wareham <span dir="ltr"><<a href="mailto:m3rlin@gmail.com" target="_blank">m3rlin@gmail.com</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
Hi Maxim,<br><br>Thanks for your reply and sorry for the delay in responding!<br><br>I've applied your suggested changes to three servers in the cluster - hopefully that will give me an accurate idea of their effectiveness. I'll report back when I have more useful info.<br>
<br><br>Thanks again,<br><br>Drew<div><div><br>
<br><br><div class="gmail_quote">On Sat, May 12, 2012 at 9:18 PM, Maxim Dounin <span dir="ltr"><<a href="mailto:mdounin@mdounin.ru" target="_blank">mdounin@mdounin.ru</a>></span> wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
Hello!<br>
<div><br>
On Sat, May 12, 2012 at 08:28:14PM +1000, Drew Wareham wrote:<br>
<br>
> Hello,<br>
><br>
> I have tried to summarize this as much as possible but it's still a lot of<br>
> text. I apologize but wanted to make sure that I provide enough<br>
> information to explain the issue properly.<br>
><br>
> I'm hoping that somebody that uses nginx as a high traffic/concurrency<br>
> download server will be able to shed some light on this issue. I've tried<br>
> as many things as I can think of and everything keeps pointing to it being<br>
> an issue with nginx, not the server - but I am of course more than willing<br>
> to try any suggestions provided.<br>
><br>
</div>> *Background:*<br>
<div>> Approx. 1,500 - 5,000 concurrent connections (peak / off-peak),<br>
> Files vary in size from 5MB to 2GB,<br>
> All downloads; only very small dynamic content scripts run on these servers<br>
> and none take more than 1-3 seconds,<br>
> File are hosted on direct-attached AoE storage with a dedicated 10GE link,<br>
> Server is running nginx-1.0.11, php-fpm 5.3 and CentOS 5.8x64<br>
> (2.6.18-308.4.1.el5.centos.plus).<br>
> Specs are: Dual Xeon E5649 (6 Core), 32GB RAM, 300GB 10k SAS HDD, AoE DAS<br>
> over 10GE<br>
> Download speeds are restricted by the PHP handoff using X-Accel-Redirect,<br>
> but obviously not when I'm testing ;)<br>
><br>
</div>> *Issue:*<br>
<div>> After running for a short, but random period of time (5min ~ 90min) all<br>
> nginx workers will eventually end up in a 'D' state according to ps/top.<br>
> This causes all downloads to run extremely slowly (~25kb/s) but it doesn't<br>
> seem to be caused by I/O because an scp of the same file will complete at<br>
> the expected speed of ~750MB+/s.<br>
><br>
> I usually run with worker_processes set to 13, but I've had to raise this<br>
> to 50 to prevent the issue. This works short term, but I'm guessing<br>
> eventually I will need to restart nginx to fix it.<br>
><br>
</div>> *Config:*<br>
<div>> I'm using sendfile with epoll, and using the following events / http<br>
> settings (I've removed the location block with the fastcgi handler, etc):<br>
<br>
</div>With rotational disks you have to optimize iops to minimize seeks.<br>
This includes:<br>
<br>
1. Switch off sendfile, it works bad on such workloads under linux<br>
due to no ability to control readahead (and hence blocks read from<br>
disk).<br>
<br>
2. Use large output buffers, something like<br>
<br>
output_buffers 1 512k<br>
<br>
would be a good starting point.<br>
<br>
3. Try using aio to ensure better disk concurrency (and note under<br>
linux it needs directio as well), i.e. something like this<br>
<br>
aio on;<br>
directio 512;<br>
<br>
(this will require newer kernel though, but using 2.6.18 nowadays<br>
looks like bad idea, at least if you need speed)<br>
<br>
4. Try tuning io scheduler, there have been reports that deadline<br>
might be better for such workloads.<br>
<br>
More details can be found here:<br>
<br>
<a href="http://nginx.org/r/output_buffers" target="_blank">http://nginx.org/r/output_buffers</a><br>
<a href="http://nginx.org/r/aio" target="_blank">http://nginx.org/r/aio</a><br>
<a href="http://nginx.org/r/directio" target="_blank">http://nginx.org/r/directio</a><br>
<br>
Maxim Dounin<br>
<br>
_______________________________________________<br>
nginx mailing list<br>
<a href="mailto:nginx@nginx.org" target="_blank">nginx@nginx.org</a><br>
<a href="http://mailman.nginx.org/mailman/listinfo/nginx" target="_blank">http://mailman.nginx.org/mailman/listinfo/nginx</a><br>
</blockquote></div><br>
</div></div></blockquote></div><br>