Laravel logging error: разбираемся с ошибкой логгирования

Опубликовано: 01.09.2018

Всем привет!

Сегодня вас ожидает не полноценная статья на 20-30 тысяч символов, к которым привык я и фанаты моего творчества, а коротенький очерк, описывающий недавний случай, приключившийся у меня на работе.

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

С одной из таких я совсем недавно столкнулся во время мониторинга логов одного из своих Laravel сайтов. Выглядела она следующим образом:

[2018-05-27 18:25:28] laravel.EMERGENCY: Unable to create configured logger. Using emergency logger. {"exception":"[object] (InvalidArgumentException(code: 0): Log [] is not defined. at C:\\OSPanel\\domains\\laravel.portfolio\\vendor\\laravel\\framework\\src\\Illuminate\\Log\\LogManager.php:181) [stacktrace] ... Длинный-длинный листинг запросов, которые предшествовали возникновению ошибки ...

Причём, такая вот борода была после каждого логгируемого сообщения, генерируемого в коде Laravel приложения.

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

Я бы, наверное, и не заподозрил бы ничего неладного, если бы однажды не обратил внимание на размер файла логов Laravel, который превышал 200 мегабайт.

Кстати, если вдруг вы до сих пор не понимаете, о чём сейчас идёт речь, и где искать файлы логов Laravel приложения, то вам нужен файл storage\logs\laravel.log , который можно открыть в обычном текстовом редакторе (лучше всего использовать стандартный Блокнот, потому что IDE-шка может загнуться, если размер файла будет очень большим).

Хотя, если вы либо кто-то другой до вас серьёзно занимался настройкой Laravel logging system, то вместо данного единого файла у вас может быть несколько, как с другим названием, так и с другим местоположением.

Но сегодня разговор будет не о том, как это сделать, а о том, как побороть Laravel logging error, описанную выше.

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

Правда, в процессе Laravel update я не придал значение появившемуся в Laravel 5.6 конфигу logging.php , который был добавлен в фреймворк в связи с усовершенствованием системы логгирования.

Как раз-таки из-за отсутствия данного конфига в моём приложении и возникала указанная Laravel logging error.

Поэтому, первым делом я добавил файл config\logging.php в свой проект со следующим содержимым:

<?php use Monolog\Handler\StreamHandler; return [ /* |-------------------------------------------------------------------------- | Default Log Channel |-------------------------------------------------------------------------- | | This option defines the default log channel that gets used when writing | messages to the logs. The name specified in this option should match | one of the channels defined in the "channels" configuration array. | */ 'default' => env('LOG_CHANNEL', 'stack'), /* |-------------------------------------------------------------------------- | Log Channels |-------------------------------------------------------------------------- | | Here you may configure the log channels for your application. Out of | the box, Laravel uses the Monolog PHP logging library. This gives | you a variety of powerful log handlers / formatters to utilize. | | Available Drivers: "single", "daily", "slack", "syslog", | "errorlog", "monolog", | "custom", "stack" | */ 'channels' => [ 'stack' => [ 'driver' => 'stack', 'channels' => ['single'], ], 'single' => [ 'driver' => 'single', 'path' => storage_path('logs/laravel.log'), 'level' => 'debug', ], 'daily' => [ 'driver' => 'daily', 'path' => storage_path('logs/laravel.log'), 'level' => 'debug', 'days' => 7, ], 'slack' => [ 'driver' => 'slack', 'url' => env('LOG_SLACK_WEBHOOK_URL'), 'username' => 'Laravel Log', 'emoji' => ':boom:', 'level' => 'critical', ], 'stderr' => [ 'driver' => 'monolog', 'handler' => StreamHandler::class, 'with' => [ 'stream' => 'php://stderr', ], ], 'syslog' => [ 'driver' => 'syslog', 'level' => 'debug', ], 'errorlog' => [ 'driver' => 'errorlog', 'level' => 'debug', ], ], ];

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

Ну, и следующим шагом моей запоздалой настройки системы логгирования, недостатки которой приводили к упомянутой Laravel logging error, стала коррекция файла настроек окружения .env .

Она заключалась в удалении следующего параметра, как ненужного пережитка прошлого:

APP_LOG_LEVEL=debug

Вместо него добавляем в конфиг окружения следующий:

LOG_CHANNEL=stack

В самом сэпле .env у Laravel 5.6 он располагается под APP_URL.

Вот и всё. После этого ошибка логгирования Laravel у меня исчезла из laravel.log , облегчив его, тем самым, процентов на 80.

А это, нужно сказать, весьма существенно. В моём случае, при размере файла в 200 Мб данное обстоятельство не было критичным, но при возникновении данной Laravel logging error в production окружении может привести к тому, что ваш файл логов банально съест всё дисковое пространство сервера, и ваш сайт приляжет отдохнуть.

А это — потерянное время, транзакции клиентов, траффик и убытки, убытки, убытки… Даже если сайт будет не вашим личным, а клиентским, на вашем доходе это отразится весьма негативно.

Какова мораль всей этой истории и чему она меня научила?

Во-первых, обновление версии фреймворка на «боевом» проекте нужно проводить тщательно, ответственно и внимательно, уделяя внимание каждой мелочи, т.к. последствия могут быть намного серьёзней, чем ошибка системы логгирования Laravel, а причину вы будете искать ооочень долго.

Более, чем уверен, что, если вы обнаружите баг спустя некоторое время после обновления движка, вы даже и не подумаете, что он возник из-за некорректного Laravel update, проведённого несколько месяцев назад. И будете ругать себя самыми неприличными словами, когда всё-таки докопаетесь до правды Но, в этом всём есть и плюс — урок вы получите хороший и на всю жизнь

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

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

Ну, и третье, что я для себя понял после всего случившегося — это обращать внимание на любые подозрительные мелочи, особенно перед запуском сайта в продакшене и после обновления версий серверных компонентов (хотя, к клиентским JS/CSS/HTML либам это тоже относится).

Вещь эта вроде как очевидная и понятная, и по этой же причине многие ей пренебрегают И я в том числе Даже в данной ситуации. Я ведь видел описанную Laravel logging error в файле лога перед выкаткой сайта в прод. Но не придал ей тогда значение, потому что ничего странного в сообщении об ошибке Laravel компонента в файле лога нет.

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

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

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

Если вы столкнётесь с другими Laravel logging error — милости прошу делиться ими в комментариях, чтобы сообща докопаться до причины и решить её. А, возможно, это поможет вам навсегда вписать своё имя в историю Laravel framework, т.к. результатом решения фейла станет pull request в репозитории проекта на GitHub, кто знает…

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

Всем добра и до новых встреч ????