Re: connect -1 errno 36, sendfile -1 errno 35, L A и затыки сервера

[Igor Sysoev <igor@xxxxxxxxx>]

On Mon, Sep 06, 2010 at 02:54:15PM +0400, cronfy wrote:

> Всем добрый день!
> 
> В последнее время на сервере (FreeBSD 7.3, nginx 0.8.20 + apache)
> начали случаться затыки с высоким LA (до 100, в обычном режиме 3-7).
> При этом все воркеры nginx кушают по 20% CPU (в обычном режиме менее
> процента). Idle у сервера почти на нуле, user 10%, system на уровне
> 85% (в обычном режиме user 15%, system 5%). Анализ ktrace'ом показал,
> что во время работы присутствуют такие ошибки:
> 
> # kdump -E -f ktrace.out.ngx | grep errno | grep -v 'stat -1'
>  26333 nginx    0.198233 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    0.499356 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    0.649365 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    0.879417 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
>  26333 nginx    0.983806 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    1.166272 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
>  26333 nginx    1.324759 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    1.456000 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    1.782381 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
>  26333 nginx    1.787654 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    1.790079 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    1.790748 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    1.967399 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
>  26333 nginx    2.013909 RET   connect -1 errno 36 Operation now in progress
>  26333 nginx    2.277270 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
>  26333 nginx    2.447097 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
>  26333 nginx    2.475434 RET   sendfile -1 errno 35 Resource
> temporarily unavailable
> 
> Во время обычной работы они тоже появляются, но хотелось бы понять,
> каких там ресурсов sendfile/connect не хватает.

Это нормально для неблокирующихся соединений.

> Еще посмотрел, между какими операциями проходит много времени (более
> сотой секунды), в основном это от stat/lstat до момента возврата
> данных:
> 
>  26333 nginx    14.469116 CALL  lstat(0x7fffffffdf00,0x7fffffffe300)
>  26333 nginx    14.469128 NAMI  "/home/*****/domains"
>  26333 nginx    14.480034 STRU  struct stat {dev=71, ino=14672900,
> mode=drwxr-xr-x , nlink=6, uid=1665, gid=1666, rdev=58601884,
> atime=1280930234, stime=1283126415, ctime=1283126463,
> birthtime=1258817957, size=512, blksize=16384, blocks=4, flags=0x0 }
> 
>  26333 nginx    14.511089 RET   lstat 0
>  26333 nginx    14.511211 CALL  stat(0x7b6f08,0x800ffbf80)
>  26333 nginx    14.521749 NAMI
> "/home/*****/domains/******/public_html/wp-includes/js/.htaccess"
> 
>  26333 nginx    14.528772 CALL  stat(0x7b6f08,0x800ffbf80)
>  26333 nginx    14.528818 NAMI
> "/home/******/domains/******/public_html/wp-includes/js/tw-sack.js"
>  26333 nginx    14.540026 STRU  struct stat {dev=71, ino=14956822,
> mode=-rw-r--r-- , nlink=1, uid=1665, gid=1666, rdev=59751877,
> atime=1280930314, stime=1246650542, ctime=1280930314,
> birthtime=1246650542, size=4969, blksize=16384, blocks=12, flags=0x0 }
> 
> В штатном режиме работы между stat и возвратом даже тысячной секунды
> не проходит, а тут сотые. Странно, что gstat при этом весь зеленый -
> нагрузку на диск показывает обычную или даже ниже. А бывает даже так:
> 
>  26333 nginx    14.761612 CALL  gettimeofday(0x7fffffffe390,0)
>  26333 nginx    14.818053 RET   gettimeofday 0
> 
> 
> Хотелось бы понять, что это может быть, связано ли с nginx и куда
> можно покопать. что еще для диагностики запустить?

Что показывает "top -S" ?


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

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