Логи-убийцы или история бесконечных падений сайта

Привет! Я Женя – руководитель отдела разработки. Делюсь кодом, мыслями и историями в телеграм-канале БАГодельня, но тут пост большой получился и не влезает в формат телеграма. Да и история веселая и поучительная, как раз для выходного дня. Поэтому выкладываю на просторы vc.ru.

Акт первый. Предыстория

У одного из наших заказчиков есть сайт, который работает на cms-ке wordpress с кучей плагинов, в том числе wooCommerce для каталога товаров и онлайн продаж. Под капотом страшновато, но проект свои функции выполняет – много уникального контента, красивые картинки/видео, каталог товаров, можно сделать онлайн заказ. Долгое время сайтом управляли как конструктором, в код никто не лазил, а все доработки логики происходили через добавление готовых плагинов. И когда их количество набрало критическую массу, дорабатывать что-то через добавление новых или настройки установленных, стало невозможно. К тому же сайт рос и стали появляться новые ожидания и идеи, которые нельзя реализовать без доработок кодовой базы. Тогда мы – отдел разработки, и подключились. Первое время было страшновато что-то менять, поскольку небольшие доработки в одном месте, могли сломать пару разделов на другом краю сайта. Но потихоньку разобрались и начали вносить изменения.

Спустя какое-то время, заказчик начал готовить большую маркетинговую акцию – предзаказ нового товара. Был предварительный серьезный разогрев аудитории через соц.сети, много кто проявил интерес и с нетерпением ждал старта продаж. Параллельно шла подготовка и на сайте: собрали красивую «продажную» страницу, добавили туда кнопки покупок, все в лучших традициях. Красиво. Все работает. И даже в срок.

Акт второй. Падение

Запуск запланировали на 12:00. Проверка всех систем – порядок. Ключ на старт и поехали! Ссылки на страницу публикуются в ВК, ютуб, почтовая рассылка и тд. Сразу же полетели заказы, оплаты проходят, сайт держится. Пять минут – полет нормальный. Трафик посетителей, если судить по метрике, скакнул примерно в 20-25 раз относительно спокойных дней.

12:07, сайт падает. Караул! Семь минут всего продержались. В чем дело? Бегом разбираться. Сервер выкидывает 504ю ошибку – лютые таймауты. На хостинге нагрузка запредельная, до 500% перерасход допустимых ресурсов. В консоле карнавал из подвисших процессов php. «Убиваем» руками самые долгие процессы. Параллельно перепроверяем код страницы, вырезаем все запросы к базе данных, которые не критичны и меняем значения на статичные – счетчик продаж, просмотров и тд. Пол часа и сайт снова заработал, пропали 504е, но страницы открываться со скрипом, явно что-то не так. Еще 10 минут и сайт снова падает – процессы подвисают и насилуют процессор на всю катушку. Пока ищем в коде, что еще можно быстро оптимизировать, руками чистим процессы, чтобы сайт хоть как-то держался. Трафик посетителей в это время только растет.

Акт третий. Бан от хостинга

13:30 хостинг выписывает бан и блокирует доступ к сайту. Из-за перерасхода ресурсов, хостер автоматически наложил блокировку. И теперь при входе на сайт стала появляться серверная basic auth авторизация, которая не пускает никого на сайт. Трафик идет на сайт, а он не работает. Срочно нужно решать проблему. Самое понятное – докупить ресурсов. Бегом к хостеру повышать тариф. Но автоматика не дает обновить тарифный план, если есть блокировка по нагрузке. Странновато. Пишем в поддержку, просим поднять тариф и снять блокировку. Саппорт молчит, сайт лежит. Звоним. Описали проблему, договорились – все ок. Бан нам сняли и тариф подняли. Сайт ожил, но не на долго. Победили последствия, а не причину. Ищем дальше, что может создавать такую серьезную нагрузку и один за другим вешать процессы. Идей нет, все сделано хорошо, если мерить рамками вордпресса. Плагины кеширования все включены, но они кешат только статику. Быстренько накидываем логику кеша запросов к базе. Пока разбирались и дописывали кеш, сайт снова падает. Апаем доработки с кешем, убиваем процессы. Сайт запускается, но работает все так же с жуткими тормозами. Кеширование явно не помогло. Еще пол часа и ловим новый бан от хостинга, поскольку израсходовали ресурсы и от более высокого тарифа.

Акт четвертый. Хацкеры

Блокировка сайта хостингом проходила просто добавлением basic auth. Но авторизация какая-то странноватая оказалась. Логин и пароль были admin и admin. Это оказалось тоже проблемой. В соц.сетях люди стали обсуждать падение сайта и проблему, что нельзя купить анонсированный товар. Активисты начали писать рекомендации, как починить и что проверить. А самые шустрые подобрали доступ и скинули его всем в комментариях. И тогда даже на заблокированный сайт стали заходить посетители о оформлять заказы. Но сайт закрыт не только для пользователей, а и для всех сервисов, которые пытаются достучаться. В том числе и банковские колбеки, которые должны приходить на сайт после успешной оплаты, делать отметку на сайте и обновлять статус заказа. Так помимо проблем с нагрузкой, добавилась беда с оплатами – деньги списываются, а заказы висят в статусе «ожидает оплаты».

Антракт

Быстрые фиксы не помогают, нужно искать кардинальное решение. И мы решаем закрыть полностью доступ к сайту и быстренько перенести его на свой сервер, который для отладки используется. Тестовый сервер у нас помощней клиентского боевого раза в 2-3. Плюс на своем серваке мы имеем полный доступ, в отличии от хостинга, который даже логи не все предоставляет. Идея казалась адекватной: перенести к себе, линконуть по-быстрому домен через а-записи, которые обновляются за 10 минут, открыть доступ и полноценно отдебажить, понять в чем дело.

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

Сайт заработал, но страницы открываются еще медленнее. Такого поворота даже и предположить не могли. Процессор в 4-5 раз мощнее, оперативки в два раза больше. В чем дело? Дело в жестком диске. На тестовом сервере HDD, нам больше важен объем чем скорость. Хоть скорость hdd серьезно уступает ssd, но она не должна так влиять на скорость отдачи контента. А все запросы к базе данных, что есть на посадочной странице, мы закешировали.

Акт пятый. Да ладно?

Начинаем смотреть все подряд запросы, что происходят в вордпрессе. Ужас, несколько сотен запросов на каждой странице. Каждый плагин, который установлен, и даже не используется, делает какие-то свои запросы на чтение и на запись. Разобрать, что нужное, а что лишнее, просто не реально сходу. Нужно анализировать каждый плагин и его запросы, просто так отключить или закешировать не получается – сайт начинает падать.

Приходит две идеи: отвязать страницу от вордпресса и на время показывать статику, и перенести базу данных сайта в оперативку, чтобы заработала быстрей, чем на hdd. Занялись параллельно двумя решениями.

Время 21:30. Мысли начинают путаться, а пальцы промахиваются по клавишам. Одно неверное движение и при переносе БД в виртуальный диск, который сделали из оперативки, меняются настройки прав на файлы бд. База умирает. Реанимация не помогает. Возвращаем файлы БД наместо на hdd, перезапускаем mysql, а он не стартует и падает с ошибками. Доигрались. На сервере, помимо тестовых сайтов еще и рабочий таскменджер развернут, он тоже мертв. Через режим реанимации(innodb_force_recovery) запускаем mysql и пытаемя убить БД от сайта, который пытались оживить. Структура таблиц видна, объем данных тоже, но сами данные не доступны и удалить всю БД нельзя. Решили снести самые «тяжелые» таблицы и попробовать еще раз перезапустить mysql. И тут натыкаемся на таблицу весом 2 гб. Интересненько, это 80% веса всей базы данных. А что там? Логи. Логи плагина от почтового сервиса мейлчимп.

Кое-как удаляем базу данных, перезапускаем mysql – ожил. С рабочего хостинга стягиваем еще раз базу данных к себе на сервер и запускаем без махинаций с виртуальным диском в оперативке. Полезли смотреть, что за логи и откуда такой объем. Оказывается, отключенный плагин для отправки почты, собирает каждое действие пользователя на сайте и сохраянет их БД. Самое интересное, что плагин был установлен давным-давно и так же давно отключен. Но это ему не мешало потихоньку заполнять базу данных, будучи деактивированным.

Удаляем мусор из БД, удаляем код плагина, стартуем сайт и о чудо, никаких тормозов. Работает даже в 2-3 раза быстрей, чем раньше в спокойные времена. На всякий случай проверяем нагрузку, а ее нет совсем. Дальше дело техники: возвращаем сайт на хостинг заказчика и открываем доступ.

Время 22:51. Сайт снова запущен и полноценно функционирует. Покупатели в соц.сетях снова активизировались и побежали оформлять заказы. Нагрузка на хостинге в пределах нормы. Все довольны. А мы уползаем по домам отсыпаться.

Занавес

Мораль истории такова, что нужно осторожно использовать плагины. А при отладке стоит посмотреть по сторонам, проблема может быть не там, где ее ищешь.