Hello!

On Wed, Aug 28, 2013 at 06:16:42PM +0300, Serge Negodyuck wrote:

> 28 августа 2013 г., 0:38 пользователь Maxim Dounin <mdounin@mdounin.ru> написал:
> > Hello!
> >
> > On Tue, Aug 27, 2013 at 10:59:25PM +0300, Serge Negodyuck wrote:
> > >
> >> > Поигравшись с "while true; do gdb66 -ex "backtrace full" --batch -p
> >> > 41159; done"
> >> > получилось, что бОльшую часть времени эти процессы проводят в
> >> > состоянии: " if (c[i].fd != -1 && c[i].idle) {":
> >>
> >> Добавление usleep(1) решило все проблемы:
> >>
> >> --- ngx_process_cycle.c.orig 2013-08-27 22:42:36.000000000 +0300
> >> +++ ngx_process_cycle.c 2013-08-27 22:42:46.000000000 +0300
> >> @@ -792,6 +792,7 @@
> >> c[i].close = 1;
> >> c[i].read->handler(c[i].read);
> >> }
> >> + usleep(1);
> >> }
> >>
> >> if (ngx_event_timer_rbtree.root == ngx_event_timer_rbtree.sentinel)
> >>
> >>
> >> IMHO, как-то грязновато. Может можно как-то по событиям? Или вынести
> >> цикл по дескрипторам соединений в отдельный поток.
> >
> > Этот цикл - занимается закрытием idle-соединений, и выполняется
> > только при получении из ядра каких-либо событий (i.e. - редко).
> > Если время теряется в нём - это как бы намекает, что в ядре nginx
> > почему-то не остаётся, а сразу возвращается обратно. В этом и
> > есть настоящая проблема.
> >
> > Было бы интересно посмотреть на nginx -V (интересует, в первую
> > очередь, отсутствие сторонних модулей/патчей), полный конфиг и
> > debug log. Ссылка на всякий случай:
> >
> > http://nginx.org/ru/docs/debugging_log.html
>
> # nginx -V
> nginx version: nginx/1.4.2
> TLS SNI support enabled
> configure arguments: --prefix=/usr/local/etc/nginx --with-cc-opt='-I
> /usr/local/include' --with-ld-opt='-L /usr/local/lib'
> --conf-path=/usr/local/etc/nginx/nginx.conf
> --sbin-path=/usr/local/sbin/nginx --pid-path=/var/run/nginx.pid
> --error-log-path=/var/log/nginx-error.log --user=www --group=www
> --with-debug --with-file-aio
> --http-client-body-temp-path=/var/tmp/nginx/client_body_temp
> --http-fastcgi-temp-path=/var/tmp/nginx/fastcgi_temp
> --http-proxy-temp-path=/var/tmp/nginx/proxy_temp
> --http-scgi-temp-path=/var/tmp/nginx/scgi_temp
> --http-uwsgi-temp-path=/var/tmp/nginx/uwsgi_temp
> --http-log-path=/var/log/nginx-access.log --with-http_dav_module
> --with-http_gzip_static_module --with-http_realip_module
> --with-http_stub_status_module --with-pcre
> --add-module=/usr/ports/www/nginx/work/gabor-nginx-x-rid-header-0daa3cc
> --with-http_ssl_module
>
> nginx-x-rid-header вряд ли тут при чем. Он участвует только при новом запросе.
>
> Урезаная версия конфига в атаче (Убрана большая часть локейшинов, и
> виртуальных хостов с похожим конфигом на разных ip адресах около 10.)
>
> В дебаг логе ничего - только события от таймера
>
> 2013/08/28 16:14:10 [debug] 27687#0: posted events 0000000000000000
> 2013/08/28 16:14:10 [debug] 27687#0: worker cycle
> 2013/08/28 16:14:10 [debug] 27687#0: kevent timer: -1, changes: 0
> 2013/08/28 16:14:10 [debug] 27687#0: kevent events: 1
> 2013/08/28 16:14:10 [debug] 27687#0: kevent: 0: ft:-7 fl:0020
> ff:00000000 d:1 ud:0000000000000000
> 2013/08/28 16:14:10 [debug] 27687#0: timer delta: 2
> 2013/08/28 16:14:10 [debug] 27687#0: posted events 0000000000000000
> 2013/08/28 16:14:10 [debug] 27687#0: worker cycle
> 2013/08/28 16:14:10 [debug] 27687#0: kevent timer: -1, changes: 0
> 2013/08/28 16:14:10 [debug] 27687#0: kevent events: 1
> 2013/08/28 16:14:10 [debug] 27687#0: kevent: 0: ft:-7 fl:0020
> ff:00000000 d:1 ud:0000000000000000
> 2013/08/28 16:14:10 [debug] 27687#0: timer delta: 1
> 2013/08/28 16:14:10 [debug] 27687#0: posted events 0000000000000000
> 2013/08/28 16:14:10 [debug] 27687#0: worker cycle
> 2013/08/28 16:14:10 [debug] 27687#0: kevent timer: -1, changes: 0
> 2013/08/28 16:14:10 [debug] 27687#0: kevent events: 1
> 2013/08/28 16:14:10 [debug] 27687#0: kevent: 0: ft:-7 fl:0020
> ff:00000000 d:1 ud:0000000000000000
> 2013/08/28 16:14:10 [debug] 27687#0: timer delta: 2
>
> Cобытий таймера порядка 600-700 в секунду. Я так понимаю, при
> timer_resolution 1ms их должно быть около 1000. Значит, что-то мешает
> таймеру выполняться.
>
> И я, всё же, думаю что это тот цикл по соединениям.
> Соединений на воркер у меня 32000, таймер работает 1000 раз в секунду.
> Т.е. в секунду процессор должен делать 32 миллиона итераций по циклу.
> Не знаю, много это или мало. Думаю, прилично.

Ну таки да, timer_resolution 1ms + worker_connections 32000
поведение объясняют. Простейшее решение - выпилить из конфига
timer_resolution и/или поднять до каких-нибудь более разумных
100ms.

--
Maxim Dounin
http://nginx.org/en/donation.html

_______________________________________________
nginx-ru mailing list
nginx-ru@nginx.org
http://mailman.nginx.org/mailman/listinfo/nginx-ru