1040 Too many connections: как один JavaScript-цикл положил прод и почему Laravel-приложение не могло восстановиться

В середине обычного рабочего дня B2B-приложение, с которым работают наши партнёры, перестало обслуживать запросы. MariaDB исчерпала лимит подключений, пользователи получали HTTP 500, а за четыре минуты в журнал приложения упало около 20 тысяч ошибок.

Сначала всё выглядело как типичная проблема производительности базы. Расследование показало другое: толчком стал зациклившийся JavaScript в одной вкладке браузера. Но этот всплеск объясняет только начало аварии. Четыре минуты простоя обеспечило само приложение: обработчик ошибок записывал ошибки в уже недоступную базу, страница ошибки снова обращалась к той же базе, а Auth::check() при каждой неудаче пытался подключиться заново.

Ниже — как мы восстанавливали картину по логам Apache, Laravel и счётчикам MariaDB, какие версии не подтвердились, где мы сами ошибались по ходу анализа и что в итоге поменяли.

Контекст

Речь об одном из наших legacy-проектов — B2B-приложении для партнёров: заявки, расчёт стоимости, обмен с внешней учётной системой через HTTP API. Стек: PHP, Laravel, MariaDB, Apache, MPM prefork + mod_php, внешняя система, доступная приложению через HTTP API.

Для расследования оказались важны четыре особенности.

Apache + prefork + mod_php. Каждый процесс Apache несёт в себе интерпретатор PHP и может открыть собственное подключение к MariaDB. PHP-FPM на сервере нет.

Внешняя система отвечает медленно, и это штатно. Весь обмен с ней идёт через единый клиент. Операции расчёта штатно занимают десятки секунд — так устроена обработка на стороне внешней системы, повлиять на это мы не можем. Таймаут curl выставлен чуть меньше минуты. Пока PHP ждёт ответа, подключение к MariaDB остаётся открытым и ничего не делает.

View composer на все шаблоны. В ViewServiceProvider зарегистрирован composer со звёздочкой:

view()->composer(’*’, function ($view) {
if (Auth::check()) {
// данные пользователя для шаблонов
}
});

Он срабатывает при рендере каждой вьюхи: layout, header, footer, каждого @include.

Ошибки пишутся в ту же базу. Обработчик исключений сохраняет их в отдельную таблицу в той же MariaDB. Собственная страница ошибки — обычный Blade-шаблон, который проходит через тот же глобальный composer.

Последние два пункта и определили, почему авария длилась минуты, а не секунды.

Что вообще произошло?

Ниже время указано относительно момента срыва — назовём его T.

Сама ошибка — стандартная:

SQLSTATE[HY000] [1040] Too many connections

Интереснее оказалась хронология. Сервер замер раньше, чем появилась первая ошибка. Apache пишет строку в access_log в момент завершения запроса. Поэтому число строк за секунду показывает, сколько запросов завершилось. Провал в этом числе означает не затишье, а запросы, которые висят и не могут завершиться.

В момент T завершённые запросы почти исчезли — это и есть срыв. Через несколько секунд очередь прорвало, и за одну секунду завершилось почти втрое больше запросов, чем обычно, — максимум за весь файл.

Первая запись об ошибке 1040 появилась в laravel.log только через двадцать секунд, и сразу пачкой: в ту же секунду пришли ещё почти три десятка. Постепенного нарастания не было — пул подключений не подтекал, он закончился разом.

Дальше по минутам:

Ещё через минуту шторм стих сам.

Отсюда первый методический вывод: если смотреть только на журнал приложения, начало аварии сдвигается на двадцать секунд. Точный момент срыва дал именно провал в access_log.

Накануне нагрузка была почти вдвое ниже.

Для сравнения взяли то же двадцатиминутное окно предыдущего дня. В день инцидента запросов было примерно в 1,8 раза больше, и все перцентили интенсивности — p50, p90, p95, p99 и максимум — выросли в 1,7–1,8 раза. Но сам по себе рост трафика не объяснял, почему база перестала принимать соединения. Нужно было понять, откуда взялся прирост и сколько времени запросы удерживали подключения.

Первые подозрения: виновата база?

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

Здесь мы допустили первую ошибку анализа. Шестизначное число отказов по лимиту подключений выглядело катастрофой, и пару выводов мы успели сделать до того, как получили Uptime и Connections. С делителем картина другая: 0,27% попыток. Та же история с Threads_created: сотни тысяч созданных потоков сначала выглядели как неработающий thread cache, а после нормировки оказались 99% попаданий в кеш — норма. Абсолютные счётчики MySQL и MariaDB без Uptime и Connections читать бесполезно.

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

Почему slow query log был чистым

Следующей версией были медленные SQL-запросы. Но slow query log оказался практически пустым. На первый взгляд это противоречит исчерпанному пулу. На самом деле нет: подключение может быть открыто и при этом не выполнять ни одного запроса. PHP прочитал данные из базы, отправил запрос во внешнюю систему и ждёт ответа десятки секунд. Всё это время соединение занимает слот, но в slow log не попадает в принципе.

Снимок счётчиков согласуется с этой картиной: из двух десятков подключений активно было одно, остальные простаивали. Это единичный снимок в спокойное время, а не измерение во время аварии. Подтвердить гипотезу напрямую могли бы регулярные снимки PROCESSLIST с Command = Sleep.

Так что чистый slow query log не опроверг проблему с подключениями, а подсказал, где её искать: слоты заняты ожиданием, а не работой.

Сколько запаса было на самом деле

Оценить запас помогает закон Литтла: среднее число объектов в системе равно интенсивности их поступления, умноженной на среднее время пребывания.

N = λ × T

Здесь N — число одновременно занятых подключений, λ — интенсивность динамических запросов (без статики), T — среднее время удержания подключения. Подставив наш лимит и данные контрольного дня, получаем:

— при среднем потоке пул заканчивается, если среднее удержание подключения превышает около 14 секунд;

— при пиковом потоке — уже около 3,4 секунды.

Теперь посмотрим на время ответа внешней системы. За два часа до инцидента логировались вызовы дольше 5 секунд:

Во внешнюю систему ходит лишь часть запросов, поэтому среднее время удержания по всем запросам заметно меньше. Но порог в 3,4 секунды на пике очень низкий: достаточно, чтобы заметная доля запросов ждала внешнюю систему по 10–30 секунд, и среднее подбирается к нему вплотную. Ежедневные отказы говорят о том, что так и происходило.

База данных здесь работала не только хранилищем, но и ресурсом, который приложение держало, пока ждало совершенно другую систему. Увеличение max_connections само по себе эту проблему не решает.

Триггер: одна вкладка и 150 запросов в секунду

Когда дошли до access_log за день инцидента, нашлась аномалия. На эндпоинт сброса расчёта за двадцатиминутное окно пришло около четверти всего трафика приложения.

Все запросы по заявке A пришли с одним User-Agent и одним Referer — страницей редактирования этой заявки. «Одна вкладка» — вывод, а не установленный факт, но вывод надёжный: одна заявка, один браузер, одна страница. Цикл раскручивался несколько минут: примерно за семь минут до срыва от вкладки приходили единичные запросы в минуту, за две минуты — десятки, за минуту — сотни. На пике вкладка давала больше 150 запросов в секунду, примерно в десять раз больше медианной нагрузки всего приложения накануне.

Что было не так с JavaScript?

Функция в исходном коде:

function resetCalculation()
{
if (ajaxGet("/orders/" + ORDER_ID + «/reset-calculation») === 200) {
// ...
}
}

Здесь два дефекта.

Неверная проверка результата. ajaxGet() возвращает тело HTTP-ответа, а не код статуса. Сравнение с числом 200 не бывает истинным никогда, и содержимое if не выполняется вообще.

Синхронный XMLHttpRequest. Внутри ajaxGet() стоит:

async: false

Каждый вызов блокирует основной поток страницы до ответа сервера. При 150 с лишним запросах в секунду на один запрос приходится около 6 миллисекунд. Важно: синхронный XHR не умножал нагрузку, наоборот — выстраивал запросы строго один за другим. Но это давно устаревший приём, и в тугом цикле он подвешивает страницу.

Откуда взялся сам цикл. resetCalculation() вызывается при любом изменении на странице заявки, вплоть до её перезагрузки. Так задумано: после любой правки результат расчёта сбрасывается, и пользователь обязан заново пересчитать заявку. Вторая часть — автозаполнение блока с несколькими связанными полями. Когда скрипт подставляет значения, он програмно вызывает change на каждом из полей, и каждое снова вызывает resetCalculation().

В итоге одно действие пользователя порождало каскад вызовов, а программные изменения полей порождали новые события change. На заявке A этот каскад не затух.

Как одна вкладка уронила пул подключений

По закону Литтла 150 запросов в секунду × 6 мс ≈ одно одновременное подключение. Сама по себе вкладка держала примерно один слот и пул исчерпать не могла. Она сработала как толчок для системы, у которой запаса не было: добавила к обычному трафику тысячи коротких запросов, каждый из которых занимал воркер Apache и открывал подключение к базе. При этом часть слотов постоянно была занята ожиданием внешней системы, а Apache был готов запустить в разы больше процессов, чем могла обслужить база.

Как именно пул оказался выбран до дна в момент T, по имеющимся данным восстановить до конца нельзя. Но картина согласуется со всеми данными, которые у нас есть.

Оставался главный вопрос: почему приложение не восстановилось через несколько секунд после срыва?

Почему приложение не восстановилось

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

Auth::check() не запоминает неудачу.

В LaravelSessionGuard::user() устроен так (упрощённо):

if (! is_null($this->user)) {
return $this->user;
}
$id = $this->session->get($this->getName());
if (! is_null($id) && $this->user = $this->provider->retrieveById($id)) {
// пользователь найден
}

Кеш $this->user заполняется только при успешном retrieveById(). Если запрос к базе упал с 1040, $this->user остаётся null, и следующий вызов Auth::check() снова пойдёт в базу. Это не баг фреймворка: кешировать исключение было бы странно. Проблема в сочетании с нашим composer на ’*’, который вызывает Auth::check() на каждой вьюхе. В нормальной работе это лишние вызовы, но дешёвые: после первого успеха пользователь закеширован. При недоступной базе исключение вылетает на первой же вьюхе. В нашем случае это был шаблон подключения стилей в layout: практически все ошибки в логе падали именно там.

Обработчик пишет ошибку о недоступной базе в эту же базу

Получив исключение 1040, обработчик пытается сохранить его в таблицу ошибок. Таблица лежит в той же MariaDB, которая не принимает подключения. Значит, нужна ещё одна попытка подключения, и она тоже получает 1040. Это хорошо видно в логе. Разбивка строк по одному пользователю:

~6,9 тыс. production.ERROR: SQLSTATE[...] 1040 Too many connections
~6,7 тыс. production.ERROR: Ошибка записи в таблицу ошибок: ... 1040

Соотношение почти ровно 1:1: каждая ошибка подключения порождала вторую попытку подключения. Логирование, которое должно помогать диагностике, само добавляло нагрузку на упавший ресурс. Страница ошибки падает там же.

Около 7,5 тысячи записей в логе заканчиваются одинаковым суффиксом, повторённым дважды:

(View: .../layouts/styles.blade.php) (View: .../layouts/styles.blade.php)

Laravel добавляет (View: путь), когда исключение брошено при рендере вьюхи. Двойная обёртка означает: исключение возникло при рендере страницы, Laravel пошёл рендерить страницу ошибки, и она упала в том же месте — в composer, на Auth::check().

Как это складывается

На каждый запрос, пришедший в момент аварии:

рендер страницы
→ composer → Auth::check() → подключение № 1 → 1040
→ Handler пишет в таблицу ошибок → подключение № 2 → 1040
→ рендер страницы ошибки → composer → Auth::check() → подключение № 3 → 1040
→ необработанная ошибка, HTTP 500

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

Отдельная деталь — распределение ошибок по пользователям. На одного пользователя пришлось 68% всех строк, у следующего за ним — в пятьдесят раз меньше. В пиковую секунду на него пришлось около 700 строк лога, а каждая строка здесь — неудачная попытка подключения. Легко решить, что это и есть источник атаки. Но заявка A к нему не относится, а за два часа лога он сделал ровно один вызов во внешнюю систему — уже после шторма. Сопоставить его строки в laravel.log с запросами в access_log напрямую не удалось.

Отсюда методический вывод: число строк в laravel.log нельзя приравнивать к числу HTTP-запросов. Один запрос порождает несколько исключений, и без сопоставления с access_log легко обвинить пользователя, робота или партнёра.

Какие версии не подтвердились

Про внешнюю систему стоит сказать отдельно. Медленные вызовы шли ровным фоном, около десяти в минуту, а во время шторма их стало меньше: 6, 4, 4 и 1 за четыре минуты аварии. Причина простая: приложение уже не могло получить подключение к базе, и до обращения во внешнюю систему дело не доходило. Настоящих curl-таймаутов за два часа было всего два, оба задолго до инцидента. Внешняя система — постоянный фоновый фактор риска, но не толчок.

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

Отдельная проблема: Apache против MariaDB

В конфигурации обнаружилась диспропорция: MaxRequestWorkers в Apache был в восемь раз больше, чем max_connections в MariaDB.

С prefork и mod_php каждый процесс Apache может открыть своё подключение. Веб-сервер готов принять в восемь раз больше параллельной работы, чем база способна обслужить. При такой связке ошибка 1040 — вопрос времени: как только одновременных запросов к базе становится больше лимита, начинаются отказы. Будь лимит воркеров сопоставим с лимитом подключений, лишние запросы ждали бы в очереди, а не порождали сотни процессов, дерущихся за слоты.

Есть и вопрос памяти. Процесс prefork с mod_php обычно занимает десятки мегабайт RSS, и завышенный лимит воркеров легко превышает реальную память сервера. Получается неприятная вещь: ошибка 1040 в такой конфигурации работает предохранителем. Она останавливает рост параллелизма раньше, чем сервер начнёт задыхаться от нехватки памяти, — ценой отказа в обслуживании.

Реальный потолок определяется измерением, а не формулой:

free -m
ps -ylC apache2 —sort:rss | awk ’
NR > 1 { sum += $8; n++ }
END { print «процессов:», n, «средний RSS, МБ:», sum / n / 1024 }’

MaxRequestWorkers не должен превышать (свободная память − память под базу и прочее) / средний RSS. И воркеров не должно быть больше, чем подключений к базе, с запасом на cron, очереди и административные задачи.

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

В более широком смысле prefork с mod_php плохо подходит приложению, где заметная часть запросов ждёт внешнюю систему по 10–50 секунд: полноценный процесс с интерпретатором всё это время простаивает. Переход на MPM event и PHP-FPM — отдельная задача.

Что мы исправили

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

Источник нагрузки

Разобрались с resetCalculation():

— нашли все места вызова функции, включая обработчики change в автозаполнении; — разорвали цикл повторных вызовов; — исправили проверку результата: теперь проверяется реальный код ответа, а не тело; — отказались от синхронного XHR; — добавили защиту от повторного запуска, пока предыдущий запрос не завершился.

Composer: один вызов на запрос и никаких исключений

Убрали повторные вызовы Auth::check() в рамках одного HTTP-запроса: данные пользователя получаем один раз и раздаём шаблонам через view()->share(). Набор переменных при этом не меняется — какие из сотен шаблонов их используют, выяснить надёжно невозможно.

public function boot()
{
$isConsole = $this->app->runningInConsole();
view()->composer(’*’, function () use ($isConsole) {
static $shared = false;
if ($shared && ! $isConsole) {
return;
}
$userId = $userName = null;
try {
if (Auth::check()) {
$user = Auth::user();
$userId = $user->id;
$userName = $user->name;
}
} catch (\Throwable $e) {
// БД или сессия недоступны — рендер не роняем
}
view()->share([
’user_id’ => $userId,
’user_name’ => $userName,
]);
$shared = true;
});
}

В этом коде три неочевидные детали

1. Флаг $shared выставляется после view()->share(). Иначе при исключении переменные не раздадутся вовсе, а composer на следующей вьюхе молча выйдет по return, и вместо настоящей ошибки мы получим «Undefined variable».

2. Проверка runningInConsole() обязательна. Queue-воркер живёт часами и рендерит письма для разных пользователей. Без этой проверки первая задача в очереди «запомнит» первого пользователя, и все следующие письма уйдут с его именем. Для приложения, которое формирует документы, это тихая подмена данных.

3. try/catch гарантирует, что недоступная база больше не роняет рендер страницы на первой же вьюхе.

Ошибки базы обрабатываются мимо базы и мимо Blade

Для ошибок подключения сделали отдельную ветку в Handler. Она стоит до любой попытки записать что-либо в таблицу ошибок:

if ($exception instanceof \PDOException) {
\Log::error(’DB недоступна: ’ . $exception->getMessage());
if ($request->expectsJson() || $request->ajax()) {
return response()->json([’error’ => ’Сервис временно недоступен’], 503);
}
$html = @file_get_contents(public_path(’errors/503.html’));
return response($html ?: ’Сервис временно недоступен’, 503, [’Retry-After’ => 30]);
}

QueryException наследуется от PDOException, так что одной проверки хватает. Ошибка пишется в файловый лог, который не зависит от упавшего ресурса. Страница — статический HTML без Blade и без обращений к базе. Отдельная ветка для AJAX нужна, потому что большая часть взаимодействия в приложении идёт через AJAX-запросы.

Код 503 потребовал согласования с фронтендом: часть обработчиков ошибок AJAX по-своему интерпретировала коды ответа, и их пришлось поправить.

Подключение не держится во время ожидания внешней системы

Время ответа внешней системы — её особенность, поэтому сокращать общий таймаут до нескольких секунд нельзя. Вместо этого перед вызовом мы отпускаем подключение к базе:

$releaseDb = \DB::transactionLevel() === 0;
if ($releaseDb) {
\DB::disconnect();
}
$response = curl_exec($curl);

Laravel переподключится сам при первом же следующем обращении к базе. Отключаться можно только вне транзакции — отсюда проверка transactionLevel(). Перед выкаткой мы прошлись по всем местам с beginTransaction и DB::transaction(, чтобы убедиться, что внешний вызов не происходит внутри транзакции.

Какие данные стоит собирать заранее

Значительная часть любого подобного расследования уходит на восстановление того, что можно было бы просто прочитать в логах. Вот что, по нашему опыту, стоит собирать до инцидента.

— Реальный IP клиента в access_log, если запросы приходят через прокси или балансировщик. — Время обработки запроса (%D) — это прямое измерение времени удержания подключения. — Регулярные снимки PROCESSLIST, чтобы видеть состояние пула в момент аварии, а не восстанавливать его по косвенным признакам. — Контекст в записях об ошибках: URL, метод и идентификатор сессии, а не только сообщение и трейс.

Формат лога Apache для этого:

LogFormat "%h %{X-Forwarded-For}i %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\" %D %X" xff_combined

Здесь %{X-Forwarded-For}i — реальный IP клиента, %D — время обработки запроса в микросекундах, %X — оборвал ли клиент соединение.

Снимок подключений MariaDB, например раз в 10 секунд:

SELECT NOW(), id, user, host, db, command, time, state, LEFT(info, 200)
FROM information_schema.processlist;

Главное в этих снимках — подключения в состоянии Sleep. Только они показывают ситуацию, когда база не выполняет SQL, а слоты всё равно заняты. Плюс mod_status с ExtendedStatus On.

Ещё один инструмент, без которого разбор ушёл бы в тупик, — сквозной идентификатор запроса в логах. В какой-то момент по логам казалось, что return в PHP «не прерывает выполнение»: после него выполнялась другая ветка кода. Идентификатор запроса показал, что это два разных HTTP-запроса, строки которых просто шли в логе подряд.

Итоги

В этом инциденте не было одной ошибки. Отказ сложился из нескольких факторов:

1. У пула подключений MariaDB практически не было запаса относительно реальной нагрузки.

2. PHP держал подключения к базе, пока ждал ответа внешней системы.

3. Apache мог запустить в разы больше процессов, чем база готова была обслужить.

4. JavaScript в одной вкладке начал генерировать тысячи запросов.

5. Обработчик ошибок пытался записать ошибку в ту же базу, которая уже отказала.

6. Страница ошибки снова обращалась к базе через глобальный composer, а Auth::check() не запоминал неудачу.

Толчок вызвал отказ, но устройство приложения превратило короткую просадку в четырёхминутный шторм.

Я бы выделил четыре практических вывода.

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

Обработка ошибок должна быть независимой от отказавшего ресурса. Если база недоступна, нельзя записывать информацию об этом в ту же базу. Если упал механизм рендеринга, нельзя рендерить им страницу ошибки.

Медленная внешняя система способна исчерпать ресурсы совсем другой системы. Внешняя система не создавала пиковой нагрузки в момент аварии, но её штатное время ответа в десятки секунд постоянно держало подключения к MariaDB.

Метрики без контекста ведут к неправильным выводам. Шестизначное число отказов оказалось 0,27% попыток. Чистый slow query log не опроверг проблему с базой, а подтвердил её. Пользователь с 68% ошибок оказался не атакующим, а жертвой петли в обработке ошибок.

Главным результатом расследования стал не найденный цикл в JavaScript. Оно показало, насколько опасно сочетание долгих внешних вызовов, удержания подключений и обработки ошибок, которая сама зависит от упавшего ресурса. Такие сочетания особенно часто встречаются в системах, которые годами развиваются без пересмотра решений, принятых в самом начале.