С помощью strace можно увидеть, какие системные вызовы делает процесс, с какими аргументами и сколько времени на них тратит. Данной утилитой часто пользуются системные администраторы и разработчики под unix, в то время как php разработчики для диагностики используют модули профилирования и отладки под конкретную CMS или подключают php-модуль xdebug (раз, два) или xhprof.
Данные модули вполне годные, но их целесообразно применять для определенного круга задач. А вот strace более универсален, и позволяет отслеживать не только сам php процесс, но и порожденные им (например, запущенные через exec).
В диагностике каких проблем помогает strace?
- сайт «тормозит»: то есть страницы сайта медленно генерируются и нужно выяснить, какие операции выполняются долго (это может быть медленная работа с БД, много запросов к БД, подключения к внешним серверам и загрузка данных, долгая обработка каких-то данных и пр)
- на сайте производятся несанкционированные изменения (добавляется код в файлы, изменяется содержимое файлов, удаляются, создаются новые, постоянно вставляется код в базу и т.п.)
- посмотреть время генерации страницы: сколько времени тратит сервер на обработку запроса, вызовы в скрипте и пр.
- веб-сервер сильно загружает процессор, нужно выяснить – чем именно
- заражение сайта, в результате чего он начинает медленно открываться, так как внедренный в скрипты код может загружать данные с внешних серверов или отправлять данные в командный центр, расшифровывать обфусцированный код, обращаться к базе данных и пр.
- спам-рассылка: при выполнении скриптов выполняется регулярная несанкционированная отправка писем
- вставка спам-страниц или спам-ссылок: это может быть внедренный код бирж ссылок sape, trustlink, linkfeed и других, также это может быть система автоматической публикации статей на сайте, которыми пользуются black hat seo специалисты
- изменение в файле .htaccess или внедрение кода в php скрипт (например, index.php) при обращении к сайту
- динамическая вставка вирусного кода в html код страницы
- временно настроить сайт (можно даже без переключения домена) на каком-нибудь облачном VPS сервере, сейчас его стоимость составляет порядка 250 руб в месяц
- попросить тех поддержку хостинга запустить strace для вашего сайта и прислать вам лог для анализа (если они не знакомы с утилитой, дайте им ссылку на эту статью)
Итак, что необходимо сделать для сбора информации о работе процесса: утилите strace нужно указать идентификатор процесса PID, имя файла, куда сохранять трейс-лог и несколько дополнительных параметров. Для анализа работы сайта нужно “натравить” strace на веб-сервер Apache или nginx (зависит от настроек вашего хостинга), открыть страницы сайта, собрать логи и завершить работу strace.
Проблема здесь в поиске PID веб-сервера, так как нужен идентификатор не worker’а, а дочернего процесса, который изменяется и заранее узнать его нельзя. Поэтому есть различные варианты сбора логов:
- указать в настройках веб-сервера, что он работает в один поток и прицепиться к процессу
- остановить веб-сервер и запустить его из strace
strace –r –f –o strace.log apache2ctl -k start
- подключиться к серверу как в этом видео через telnet
- (самый удобный способ) прицепиться сразу ко всем дочерним процессам без перезапуска веб-сервера, и снять логи, а затем выбрать нужный. Вариантов масса
ps h --ppid $(cat /var/run/apache2.pid) | awk '{print"-p " }' | xargs strace -r -o strace.log
ps auxw | grep sbin/apache | awk '{print"-p " }' | xargs strace -f -r -o strace.log
А теперь примеры.
1. Страницы сайта открываются по 20 секунд. Почему?
Поскольку сайт работает на виртуальном хостинге, для strace переносим его на VPS сервер и запускаем strace.
Открываем страницу, ждем завершения загрузки и останавливаем strace.
В каталоге сайта образовалось несколько файлов (так как у веб-сервера было несколько дочерних процессов), берем тот, у которого размер несколько мегабайт.
Открываем его и смотрим, какие системные вызовы происходили в момент открытия страницы
Здесь можно увидеть обращения к файлам и директориям, операции с базой данных и сетевые запросы. Столбец слева от запроса отображает продолжительность запроса (опция -r в strace). Так можно определить время выполнения в миллисекундах. Удобно написать какой-нибудь скрипт, который бы отображал еще и суммарную статистику по времени вызовов (то, что сейчас отображается в первом столбце), так как изначально в отчете ее нет. Итак, смотрим в отчет и проверяем, на что уходит время при генерации страницы.
Замечаем, что в процессе генерации стартовой страницы было отправлено 559 запросов к базе данных, что явно перебор. Именно из-за некорректной работы с базой данных тормозит сайт (в данном примере был сайт на opencart, у которого разработчики некорректно реализовали вывод товара на странице).
2. Страница зависает на 30 секунд, а затем завершается с ошибкой 500.
Делаем сбор лога strace, смотрим, где зависает процесс:
... connect(8, {sa_family=AF_INET, sin_port=htons(80), sin_addr=inet_addr("204.11.56.48"}, 16) = -1 EINPROGRESS (Operation now in progress)
... poll([{fd=8, events=POLLIN|POLLOUT|POLLERR|POLLHUP}], 1, 60000"
Видим, что из скрипта идет подключение к внешнему IP на 80й порт (то есть скрипт что-то пытается загрузить в процессе работы по HTTP), но удаленный хост ему не отвечает и скрипт завершается с ошибкой. Ищем в скриптах вставку и обнаруживаем хакерский код с указанным IP. Удаляем код – сайт начинает работать.
На сегодня все.
--
Если у вас возникнут вопросы по анализу strace лога, вы всегда можете прислать его нам, мы поможем найти проблему.
