[Из песочницы] HTTP Error 503. Service Unavailable: случай в поддержке хостинга08.07.2020 01:17

?v=1

Работа в поддержке хостинга в основном однотипная, большинство запросов от клиентов решаются по проработанной схеме, но иногда всё же приходится сталкиваться с нетривиальными проблемами. Тогда главная задача инженера — найти тот самый — единственно верный путь, который приведёт к её решению. В этой статье хочу рассказать о том, как мы столкнулись с плавающей ошибкой «HTTP Error 503. Service Unavailable» на нашем shared-хостинге, как пытались её отловить, провели диагностику и получили неожиданный финал.

Начало


Хостинг предоставляет пользователям типичный стек Linux + Apache + Mysql + PHP и оболочку для управления. В нашем случае это ISP Manager 5 Bussines на базе Centos 7 с конвертацией в CloudLinux. Со стороны административной части, CloudLinux предоставляет инструменты для управления лимитами, а так же PHP-селектор с различными режимами работы (CGI, FastCGI, LSAPI).

В этот раз к нам обратился клиент со следующей проблемой. Его сайт на движке Wordpress периодически начал отдавать 503 ошибку, о чём он нам и сообщил.

Коды ответа, начинающиеся с 50х, относятся к проблемам на стороне сервера. Это могут быть проблемы как самого сайта, так и веб-сервера, который их обслуживает.

Типичные ситуации, при которых мы получаем следующие ошибки:

  • 500 Internal Server Error — довольно часто связана либо с синтаксическими ошибками в коде сайта, либо с отсутствующими библиотеками / не поддерживаемой версией PHP. Так же могут быть проблемы с подключением к базе данных сайта или неверными правами на файлы / каталоги
  • 502 Bad Gateway — например, если Nginx ссылается на неправильный порт веб-сервера Apache или процесс Apache по какой-то причине перестал работать
  • 504 Gateway Timeout — ответ от Apache не был получен в течение заданного в конфигурации веб-сервера времени
  • 508 Resource limit is reached — превышен лимит, выделяемых пользователю ресурсов


В данном списке приведены лишь некоторые, наиболее распространённые случаи. Также стоит отметить, что при превышении лимитов пользователь может получить как 500, так и 503 ошибку.

При выполнении диагностики данных ошибок, первым делом проверяем журналы веб-сервера. Обычно, этого достаточно, чтобы определить виновника и исправить проблему.

Касаемо 503 ошибки в нашем случае, в логах мы видели запись:

[lsapi: error] [pid 49817] [client x.x.x.x:6801] [host XXX.XX] Error on sending request (GET /index.php HTTP/1.0); uri (/index.php) content-length (0): ReceiveAckHdr: nothing to read from backend (LVE ID 8514), check docs.cloudlinux.com/mod_lsapi_troubleshooting.html

На основании только этого лога, определить в чём может быть проблема не представлялось возможным.

Первичная диагностика


Изначально, мы проверили статистику превышения лимитов пользователем. Незначительные превышения были зафиксированы за предыдущие дни, но ошибки в журналах были свежие, более того они появлялись в журнале с периодичностью от одной до нескольких минут.

Так же мы изучили рекомендации CloudLinux, по приведённой в журналах ошибок ссылке.
Изменение каких-либо параметров результата не принесло.

Сайт использовал базу данных на сервере Mysql 5.7, который работает на этом же сервере в контейнере Docker. В логах контейнера присутствовали сообщения: 

[Note] Aborted connection 555 to db: 'dbname' user: 'username' host: 'x.x.x.x' (Got an error reading communication packets)


Как раз, среди этих сообщений были сообщения о прерванном подключении исследуемого сайта. Это дало предположение, о том, что подключение к СУБД выполняется некорректно. Для проверки мы развернули копию сайта на тестовом домене, сконвертировали базу данных сайта под нативную в Centos 7 версию СУБД 5.5.65-MariaDB. На тестовом сайте выполнили несколько сотен запросов с помощью утилиты curl. Ошибку воспроизвести не удалось. Но этот результат был предварительным и после конвертации БД на рабочем сайте проблема так и осталась.

Таким образом, проблема некорректного подключения к СУБД была исключена.

Следующим предположением было проверить — нет ли проблем с самим сайтом. Для этого подняли отдельный виртуальный сервер, на нём подняли максимально схожее окружение. Единственное существенное отличие — отсутствие CloudLinux. На тестовом сервере проблему воспроизвести не удалось. И так, мы определили, что в коде сайта всё в порядке. Тем не менее, пробовали так же отключать плагины Wordpress, но проблема так же сохранялась.

В результате, пришли к тому, что проблема на нашем хостинге.

В ходе анализа журналов других сайтов было обнаружено, что проблема наблюдается на многих из них. Порядка 100 шт. на момент проверки: 

/var/www/httpd-logs# grep -Rl "ReceiveAckHdr: nothing to read from backend" ./ | wc -l
99


В ходе тестирования обнаружили, что только что установленная чистая CMS Wordpress также периодически выдаёт ошибку 503.

Примерно за 2 месяца до этого мы проводили работы по модернизации сервера, в частности изменили режим работы Apache с Worker на Prefork, с целью получить возможность использовать PHP в режиме LSAPI, вместо медленного CGI. Было предположение, о том, что это могло повлиять, либо требуются какие-то дополнительные настройки Apache, но вернуть обратно режим Worker мы уже не могли. В ходе изменения режима работы Apache выполняется изменение всех конфигов сайтов, процесс не быстрый и не всё могло пройти гладко.

Корректировка настроек Apache так же не дала желаемого результата.

Попутно искали схожие проблемы в поисковых системах. На одном из форумов участники утверждали, что проблема у хостера и нужно его менять, если проблему не решают. Звучит не очень оптимистично, когда ты находишься с другой стороны, но и клиента понять можно. Зачем ему нерабочий хостинг.

На данном этапе мы собрали имеющуюся информацию и результаты проведённых работ. С ними обратились в поддержку CloudLinux.

Детальная диагностика


В течение нескольких дней сотрудники поддержки CloudLinux вникали в проблему. В основном рекомендации были относительно установленных лимитов пользователей. Этот вопрос мы так же проверяли. При отключенных лимитах (Опция CageFS для пользователя) и с включенными лимитами в режиме PHP как модуль Apache проблема не наблюдалась. Исходя из этого, было сделано предположение, что каким-то образом оказывает влияние CloudLinux. В итоге, к концу недели запрос был эскалирован на 3-ий уровень поддержки, но решения пока не было.

Попутно изучали документацию Apache по режимам работы CGI и LSAPI, подняли второй экземпляр Apache на сервере хостинга на другом порту с тестовым сайтом, исключили влияние Nginx, отправляя запросы напрямую к Apache и получая те же коды ошибок.

Сдвинуться с мёртвой точки помогла документация LSAPI, как раз по диагностике 503 ошибки:
www.litespeedtech.com/support/wiki/doku.php/litespeed_wiki: php:503-errors
В секции Advanced Troubleshooting предлагается выполнять трассировку найденных в системе процессов: 

while true; do if mypid=`ps aux | grep $USERNAME | grep lsphp | grep $SCRIPTNAME | grep -v grep | awk '{print $2; }' | tail -1`; then strace -tt -T -f -p $mypid; fi ; done


Команда была доработана, с целью записи всех процессов в файлы с указанием их идентификаторов.

При просмотре файлов трассировок, мы видим в некоторых одинаковые строки: 

cat trace.* | tail
...
47307 21:33:04.137893 --- SIGHUP {si_signo=SIGHUP, si_code=SI_USER, si_pid=42053, si_uid=0} ---
47307 21:33:04.140728 +++ killed by SIGHUP +++
...


Если взглянуть на описание структуры сигналов, отправляемых процессами, то увидим, что

pid_t    si_pid;       /* Sending process ID */


Указывает на идентификатор процесса, отправившего сигнал.

На момент изучения трассировок, процесса с PID 42053 в системе уже нет, поэтому в процессе захвата трассировок решили отслеживать так же процессы, отправившие сигнал SIGHUP.
Под спойлером описаны действия, которые позволили определить что это за процесс, а так же получить его трассировку и дополнительную информацию, о том, каким процессам он отправляет сигнал SIGHUP.

Методика трассировки
Консоль 1. 
tail -f /var/www/httpd-logs/sitename.error.log

Консоль 2. 
while true; do if mypid=`ps aux | grep $USERNAME | grep lsphp | grep "sitename" | grep -v grep | awk '{print $2; }' | tail -1`; then strace -tt -T -f -p $mypid -o /tmp/strace/trace.$mypid; fi ; done

Консоль 3. 
while true; do if mypid=`cat /tmp/strace/trace.* | grep si_pid | cut -d '{' -f 2 | cut -d'=' -f 4 | cut -d',' -f 1`; then ps -aux | grep $mypid; fi; done;

Консоль 4. 
seq 1 10000 | xargs -i sh -c "curl -I http://sitename/"

Ждём пока в консоли 1 появятся сообщения, при этом в консоли 4 видим статус запроса с кодом ответа 503, прерываем выполнение в консоли 4.


В итоге, получили название процесса /opt/alt/python37/bin/python3.7 -sbb /usr/sbin/cagefsctl --rebuild-alt-php-ini

Данный процесс выполнялся в системе с периодичностью раз в минуту.

Делаем трассировку нескольких процессов cagefsctl, чтобы отследить хотя бы один от начала до конца: 

for i in `seq 1 100`; do strace -p $(ps ax | grep cagefsctl | grep rebuild-alt-php-ini | grep -v grep | awk '{print $1}') -o /tmp/strace/cagefsctl.trace.$(date +%s); done;


Далее изучаем что он делал, например: 

cat /tmp/strace/cagefsctl.trace.1593197892 | grep SIGHUP


Так же были получены идентификаторы процессов, которые были завершены сигналом SIGHUP. Завершённые процессы были процессами PHP, выполняющимися в данный момент.

Полученные данные были переданы в поддержку CloudLinux с целью уточнить легитимность данного процесса и должен ли он работать с такой периодичностью.

Позже получили ответ, что работа команды /usr/sbin/cagefsctl --rebuild-alt-php-ini выполняется корректно, единственный нюанс в том, что команда выполняется слишком часто. Обычно вызывается при системном обновлении или изменении параметров PHP.

Единственная зацепка в данном случае осталась — проверить, кто является родительским процессом cagefsctl.

Результат не заставил себя долго ждать и какого же было наше удивление — родительским процессом для cagefsctl являлся процесс ispmgrnode. Это было немного странно, потому что уровень журналирования для ISP Manager был задан максимальным и в ispmgr.log не увидели вызов cagefsctl.

Теперь данных было достаточно, чтобы обратиться и в поддержку ISP System.

Итоги


Проблема была спровоцирована после выполнения обновления ISP Manager. В целом, обновление ISP Manager — штатная ситуация, но она привела к запуску процесса синхронизации, который завершался с ошибкой и перезапускался ежеминутно. Процесс синхронизации вызывал за собой процесс cagefsctl, который в свою очередь завершал процессы PHP.

Причиной зависания процесса синхронизации стали проведённые на хостинге работы по модернизации оборудования. За несколько месяцев до возникновения проблемы, в сервер был установлен PCI-e NVMe-накопитель, создан раздел XFS и смонтирован в каталог /var. На него были перенесены в том числе и файлы пользователей, но не обновились дисковые квоты. Опций монтирования было не достаточно, требовалось так же изменить тип файловой системы в параметрах ISP Manager, т.к. она вызывает команды обновления дисковых квот. Для Ext4 и XFS эти команды отличаются.

Таким образом, проблема дала о себе знать спустя несколько месяцев после проведения работ.

Выводы


Мы сами создали проблему, но это было не ясно до последнего момента. На будущее, будем стараться учесть как можно больше нюансов. Благодаря помощи более подготовленных коллег из поддержки CloudLinux и ISP System, проблема была решена. Теперь наш хостинг работает стабильно. А нами был получен опыт, который пригодится нам в будущей работе.

P.S.: Надеюсь, Вам было интересно ознакомиться с материалом статьи, а кому-нибудь она поможет быстрее решить подобную проблему.

© Habrahabr.ru