Cтранности с kevent

Wed Nov 26 15:15:08 MSK 2008

On Wed, Nov 26, 2008 at 02:08:55PM +0300, Никита Козлов wrote:

> В общем перешли на nginx/0.6.33, проблема с "замиранием" kevent ушла.

По идее, 0.7.22 и 0.6.33 в этом месте должны себя вести одинаково.

> 2008/11/24 Никита Козлов <niakrisn at gmail.com>:
> > Пардон, а вот слона та я и не заметил...
> > В логах на счет дисков пусто, а вот iostat -x вон что кажет:
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       86.9   0.2  5563.6     9.3    1  13.1  96
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       76.5   0.0  4893.2     0.0    1  15.2  96
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       92.4   0.0  5910.6     0.0    1  11.5  96
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       87.4   0.0  5592.8     0.0    2  13.0  98
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       69.5   0.0  4448.8     0.0    1  18.6 100
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       72.5   0.0  4639.5     0.0    1  16.1  97
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       77.5   0.0  4957.3     0.0    1  14.6  99
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       78.5   0.0  5020.8     0.0    1  15.0  98
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       76.5   0.0  4893.7     0.0    1  14.3  97
> >                        extended device statistics
> > device     r/s   w/s    kr/s    kw/s wait svc_t  b
> > da1       93.3   0.0  5974.0     0.0    1  11.9  98
> >
> >
> > Видимо причина в этом.
> >
> > Игорь, на сколько я понял строка "2008/11/24 18:45:14 [debug] 40079#0:
> > *111 kevent: 119: ft:-1 fl:0020 ff:00000000 d:527 ud:48C00DD5", это
> > дамп события?
> >
> > Правильно ли я понял, что с момента kevent set event до дампа kevent
> > происходит какая-то операция с диском, которая может дать такую
> > задержку?
> >
> > 24 ноября 2008 г. 20:38 пользователь Igor Sysoev <is at rambler-co.ru> написал:
> >> On Mon, Nov 24, 2008 at 08:10:37PM +0300, Никита Козлов wrote:
> >>
> >>> top кажет:
> >>> last pid: 41119;  load averages:  0.14,  0.10,  0.08
> >>>
> >>>           up 14+00:57:58  20:05:23
> >>> 58 processes:  1 running, 57 sleeping
> >>> CPU states:  0.2% user,  0.0% nice,  0.3% system,  0.0% interrupt, 99.5% idle
> >>> Mem: 268M Active, 1772M Inact, 378M Wired, 74M Cache, 197M Buf, 7804K Free
> >>> Swap: 8192M Total, 420K Used, 8191M Free
> >>>
> >>>   PID USERNAME    THR PRI NICE   SIZE    RES STATE  C   TIME   WCPU COMMAND
> >>> 40079 www           1  -8    0 47560K 46016K biord  7   1:08  0.83% nginx
> >>> 40869 www           1  20    0 21136K 11292K lockf  2   0:01  0.10% httpd
> >>>   935 mysql        18  96    0  1170M   160M ucond  5  19:22  0.00% mysqld
> >>>   859 pgsql         1  96    0 40904K  6104K select 0   2:11  0.00% postgres
> >>> 82170 root          1  96    0 20112K 10588K select 0   1:58  0.00% httpd
> >>>   957 root          1  96    0  5848K  2456K select 6   0:19  0.00% sendmail
> >>>   860 pgsql         1  96    0  9096K  2488K select 3   0:09  0.00% postgres
> >>>   967 root          1   8    0  3184K  1016K nanslp 7   0:07  0.00% cron
> >>> 51026 root          1  96    0  7244K  3616K select 0   0:06  0.00% proftpd
> >>>
> >>>
> >>> Попробую накатить STABLE
> >>
> >> А с диском проблем нет ? Нужно смотреть в /var/log/messages
> >>
> >>> 24 ноября 2008 г. 19:46 пользователь Igor Sysoev <is at rambler-co.ru> написал:
> >>> > On Mon, Nov 24, 2008 at 07:02:30PM +0300, Никита Козлов wrote:
> >>> >
> >>> >> Добрый день всем.
> >>> >>
> >>> >> Дня два назад, nginx начал медленно отдаваться контент с сайтов
> >>> >> (использую nginx/0.7.22).
> >>> >> Поставил дебаг на свой IP, посмотреть что происходит и заметил следующую вещь:
> >>> >> 2008/11/24 14:36:18 [debug] 33593#0: *13445002 accept: 213.85.189.1 fd:689
> >>> >> 2008/11/24 14:36:18 [debug] 33593#0: *13445002 event timer add: 689:
> >>> >> 60000:3460959328
> >>> >> 2008/11/24 14:36:18 [debug] 33593#0: *13445002 kevent set event: 689:
> >>> >> ft:-1 fl:0025
> >>> >> 2008/11/24 14:36:29 [debug] 33593#0: *13445002 kevent: 689: ft:-1
> >>> >> fl:0020 ff:00000000 d:451 ud:48D004B0
> >>> >>
> >>> >> Обратите внимание на время между kevent set event и дампом kevent.
> >>> >> И так с каждым новым подключением, задержка бывает разной, удалось
> >>> >> заметить от 10 до 12 секунд.
> >>> >>
> >>> >> Кто-нибудь сталкивался с подобной проблемой?
> >>> >
> >>> > Что показывает top в такие моменты ?
> >>> >
> >>> >> После перезагрузки или релода nginx, некоторое время все работает нормально:
> >>> >> 2008/11/24 18:45:14 [debug] 40079#0: *111 accept: 213.85.189.1 fd:119
> >>> >> 2008/11/24 18:45:14 [debug] 40079#0: *111 event timer add: 119: 60000:3475894737
> >>> >> 2008/11/24 18:45:14 [debug] 40079#0: *111 kevent set event: 119: ft:-1 fl:0025
> >>> >> 2008/11/24 18:45:14 [debug] 40079#0: *111 kevent: 119: ft:-1 fl:0020
> >>> >> ff:00000000 d:527 ud:48C00DD5
> >>> >>
> >>> >> ОС: FreeBSD 7.0-RELEASE #3
> >>> >
> >>> > Возможно, имеет смыл накатить до -STABLE.
> >>> >
> >>> >
> >>> > --
> >>> > Игорь Сысоев
> >>> > http://sysoev.ru
> >>> >
> >>> >
> >>
> >> --
> >> Игорь Сысоев
> >> http://sysoev.ru
> >>
> >>
> >

-- 
Игорь Сысоев
http://sysoev.ru