Стоял у меня один apache сервер на Linux/CentOS сервере, и вдруг он стал ни с того ни с сего падать :)
Совершенно причем непонятно - сервер запускался, работал пару секунд и падал.
Пришлось доставать из загажника тяжелые инструменты. В частности, утилиту strace. Для не-программиста ее вывод страшен и может испугать до смерти. В действительности, ничего страшного там нет.
Давайте посмотрим как это было.
Я мониторил все лог файлы на своем сервере:
tail -f /data/sites/*/logs/error_log /var/log/*
Ошибка, с которой слетает команда tail -
Too many open files
Отлично, увеличиваем лимит количества открытых файлов
limit descriptors 250
и tail запускается.
Apache вылетает и при этом полная тишина в файлах. Вообще. Ти-ши-на.
Значит будем смотреть, что еще делает apache, перед тем как вылететь.
fcntl(3, F_SETFL, O_RDWR|O_NONBLOCK) = 0
pipe([25, 26]) = 0
fcntl(25, F_GETFL) = 0 (flags O_RDONLY)
fcntl(25, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
open(”/etc/httpd/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 27
dup2(27, 2) = 2
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 28
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 29
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 30
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 31
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 32
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 33
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 34
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 35
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 36
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 37
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 38
open(”/data/sites/nevazhno.ru/logs/error_log”, O_WRONLY|O_CREAT|O_APPEN
open(”/data/sites/nevazhno.ru/logs/access_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 69
open(”/data/sites/nevazhno.ru/logs/access_log”, O_WRONLY|O_CREAT|O_APPEND, 0666) = 70
open(”/etc/mime.types”, O_RDONLY) = 71
fstat(71, {st_mode=S_IFREG|0644, st_size=13099, …}) = 0
read(71, “# This is a comment. I love comm”…, 4096) = 4096
read(71, “ion/vnd.groove-tool-message\nappl”…, 4096) = 4096
read(71, “-wbxml\napplication/vnd.uplanet.s”…, 4096) = 4096
read(71, “\ntext/sgml\t\t\tsgml sgm\ntext/tab-s”…, 4096) = 811
read(71, “”, 4096) = 0
close(71) = 0
semget(IPC_PRIVATE, 1, IPC_CREAT|0600) = -1 ENOSPC (No space left on device)
open(”/etc/localtime”, O_RDONLY) = 71
fstat(71, {st_mode=S_IFREG|0644, st_size=1267, …}) = 0
fstat(71, {st_mode=S_IFREG|0644, st_size=1267, …}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0×2a98c29000
read(71, “TZif\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\4\0\0\0\4\0″…, 1024) = 1024
read(71, “\0\1\0\1\0\1\0\1\2\3\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1\0\1″…, 1024) = 243
close(71) = 0
munmap(0×2a98c29000, 4096) = 0
write(27, “[Fri Feb 20 17:39:14 2009] [crit"..., 110) = 110
write(2, "Configuration Failed\n", 21) = 21
close(70) = 0
close(69) = 0
close(68) = 0
close(67) = 0
close(66) = 0
close(65) = 0
close(64) = 0
close(63) = 0
close(62) = 0
close(61) = 0
close(60) = 0
close(59) = 0
close(58) = 0
close(57) = 0
Ого, я заметил лог файл, который я не мониторил (/etc/httpd/logs/error_log), ну и видна ошибка (Configuration Failed).
Начинаем мониторить еще один файл
tail -f /etc/httpd/logs/error_log
Читаем сообщение:
[Fri Feb 20 17:40:01 2009] [crit] (28)No space left on device: mod_rewrite: could not create rewrite_log_lock
Configuration Failed
Проверяем место на диске:
@gasparch ~> df
Filesystem 1K-blocks Used Available Use% Mounted on
/dev/vzfs xxxxx xxxxx 1150814 xx% /
@gasparch ~>
Есть как минимум один гигабайт свободно места - и тем не менее No space left.
Попутно я проверил количество свободный inodes - они тоже были свободны. А места нет :)
@gasparch ~> strace -o log httpd
@gasparch ~> grep rewrite log
open("/etc/httpd/modules/mod_rewrite.so", O_RDONLY) = 4
Записываем лог выполнения httpd в файл log и проверяем, что же там вытворяет rewrite модуль и какой файл он пытается отрыть. В результате - пустота. Странно. Проверяем по конфигу.
@gasparch ~> grep -i rewrite /etc/httpd/conf/httpd.conf
LoadModule rewrite_module modules/mod_rewrite.so
Значит rewrite модуль активируется где-то в .htaccess файлах.
Я помню, что запуск Rewrite модуля был в корневой директории какого-то сайта, поэтому можно искать просто patter-ом, а не командой find.
Просто командой
grep -i rewrite /data/sites/*/htdocs/.htaccess
Никах упоминаний RewriteLog или чего-то подобного.
А вот как я это лечил и заставил всю эту фигню работать - это читайте в книжке. Плюс там я подробнее разберу, как именно разбирать и понимать лог файл strace. На FreeBSD аналог этой команды - ktrace/kdump.
Понравилось? Подпишись на RSS!
Хочешь написать статью? Мы ищем авторов (и не только за красивые глаза, но и за дохлых президентов).
Ну вот и все, грандиозная распродажа 26 декабря 2008 года закончилась.
