Представьте: понедельник, утро, кофе еще не выпит. Звонит менеджер: «Почему отчеты не обновляются уже три дня?!» Проверяю — и правда, данные застряли на прошлой неделе. Хотя еще месяц назад все работало как часы.
Знакомая ситуация? У меня такое случилось буквально на прошлой неделе. Laravel-команда, которая должна была каждые 15 минут обрабатывать репозитории, просто… перестала. Без ошибок, без предупреждений. Supervisor бодро рапортует что все ок, логи молчат, а работа стоит.
Как я настраивал (и где накосячил)
Сначала покажу, как выглядела моя «идеальная» настройка. Спойлер: она была далека от идеала.
В файле bootstrap/app.php все выглядело стандартно:
->withSchedule(function (Illuminate\Console\Scheduling\Schedule $schedule) {
// тут еще куча других команд...
$schedule->command('app:process-repo-details')->everyFifteenMinutes();
})
Ну и supervisor, куда без него. В supervisord.conf прописал:
[program:laravel-schedule]
command=/bin/bash -c "while [ true ]; do (php /var/www/html/artisan schedule:run); sleep 60; done"
autostart=true
autorestart=true
user=sail
redirect_stderr=true
stdout_logfile=NONE
Выглядит нормально, да? Цикл крутится, команды запускаются… вот только есть нюанс.
Где собака зарыта
Проблема оказалась в том, о чем я даже не задумывался. Моя команда обрабатывает данные из внешнего API. Обычно это занимает 5-7 минут. Но иногда (когда API тормозит или данных много) процесс может растянуться на 20-25 минут.
И вот что происходит:
- 12:00 — запускается первый экземпляр команды
- 12:15 — scheduler не в курсе что первая еще работает и запускает вторую
Теперь у меня два процесса лезут в одну базу, пытаются обновить одни и те же записи. Результат предсказуем — deadlock’и, испорченные данные и тихие ошибки которые никто не видит.
А почему не видит? Смотрим еще раз на конфиг:
stdout_logfile=NONE
Я буквально сказал системе: «если что-то сломается — молчи». Гениально, правда?
Как я это починил
Первым делом — включил логи
Это вообще должно быть правилом номер один. Поменял в supervisord.conf:
; было
stdout_logfile=NONE
; стало
stdout_logfile=/var/www/html/storage/logs/scheduler.log
После рестарта контейнеров (sail down && sail up -d) наконец увидел что творится. Там была целая простыня ошибок про locked таблицы.
Защита от дублирования
Laravel умеет предотвращать запуск нескольких копий одной команды. Просто добавляем withoutOverlapping():
$schedule->command('app:process-repo-details')
->everyFifteenMinutes()
->withoutOverlapping();
Теперь если команда еще выполняется, новый запуск просто пропустится. Можно еще указать таймаут (по умолчанию 24 часа):
->withoutOverlapping(60); // максимум час
Что еще полезно знать
После этого случая я покопался в документации и нашел еще пару полезных штук:
Если у вас несколько серверов, добавьте ->onOneServer(). Иначе каждый сервер будет запускать свою копию планировщика.
Laravel Telescope — отличная штука для дебага. Показывает когда и какие команды запускались, сколько времени заняли. Несколько раз выручал.
Для сложных сценариев есть Cache::lock(). Когда нужен более тонкий контроль над блокировками между разными командами.
Мораль
Эта история научила меня двум вещам:
- Всегда логируй фоновые процессы. Серьезно,
stdout_logfile=NONE— это выстрел себе в ногу. Лучше пусть логи займут лишние 100 МБ, чем потом гадать что сломалось. - Используй
withoutOverlapping()для долгих задач. Это не паранойя, а здравый смысл. Особенно если работаете с внешними API или большими объемами данных.
В общем, после этих правок мои команды работают уже второй месяц без сбоев. Менеджер доволен, я спокоен, можно и кофе допить.
P.S. Кстати, если у вас есть свои истории про неожиданные баги в планировщике — делитесь в комментариях. Интересно же узнать, кто еще на какие грабли наступал.