connect -1 errno 36, sendfile -1 errno 35, LA и затыки сервера

cronfy cronfy на gmail.com
Пн Сен 6 14:54:15 MSD 2010


Всем добрый день!

В последнее время на сервере (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 и куда
можно покопать. что еще для диагностики запустить?

Спасибо :)

-- 
// cronfy


Подробная информация о списке рассылки nginx-ru