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