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

Дата публикации: 18.06.2018

laravel-logging-errorВсем привет! 🙂

Сегодня вас ожидает не полноценная статья на 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.

http://cccp-blog.com/wp-includes/images/banners/templatemonster/banner_content.jpg

А это, нужно сказать, весьма существенно. В моём случае, при размере файла в 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, кто знает…

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

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

Понравилась статья? Поделись с друзьями:
  1. 5
  2. 4
  3. 3
  4. 2
  5. 1
4 голоса, в среднем: 5 из 5

Похожие темы

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

  1. Alexey

    Приветствую, Админ!

    Благодарю за интересные и познавательные статьи — как раз недавно вплотную приступил к изучению Ларавеля. Дела медленно, но продвигались — сам не торопился, чтобы вникнуть в саму структуру фреймворка. И вот сегодня, практически на ровном месте (в папке движка не ковырялся, глобальных настроек не менял никаких) начались проблемы: при отправке post-запроса с формы вылезает страница «The page has expired due to inactivity. Please refresh and try again», при попытке аутентификации через стандартно установленный Auth выдает то же самое, залогиниться никак не получается. Хотя до последнего момента всё было прекрасно — я не раз отправлял с формы данные, они прекрасно валидировались, выводились через dump(), Без проблем проходил аутентификацию, авторизовывался в закрытом разделе, короче, всё как в оф.мануале. И вот на тебе…

    Я поначалу даже на сборку сервера начал грешить (у меня на винде openServer), перенес проект на шаред хостинг, результат ровно тот же.

    Заметил, что сервер не сохраняет сессии. То есть, выполняя в контроллере такой код:
    session([‘key’ => ‘value’]);
    $request->session()->push(‘key2’, ‘value2’);
    dump(Session::all());

    данные сессии выводятся, но при следующей перезагрузке страницы не добавляются. Если закомментировать первые две строки, то после очередной перезагрузки переменные key и key2 пропадают. И токен каждый раз новый выдает. Вот страница, где это видно: http://anna.proff-site.ru/public/contact . Все файлы конфигов проверил-перепроверил на всякий случай, атрибуты на папку storage/ выставлены 777. Есесно, конструкция «@csrf» присутствует там, где должна — раньше ведь работало всё без проблем.

    Помогите, пожалуйста, советом — что за оказия могла произойти?

    Могу скинуть доступ по ФТП

    1. Pashaster Автор

      Здравствуйте! Спасибо за комментарий 🙂

      По поводу проблемы — я бы для начала очистил каталог с сессиями и кэшом Laravel приложения — он хранится в каталогах storage/framework (для уверенности можно очистить все папки, кроме файлов .gitignore в них).

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

      Как показывает практика, ничего «само по себе» не происходит 🙂 Это следствие либо вашего кода, либо обновления каких-то пакетов или компонентов фреймворка.

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

      Удалите vendor каталог и выполните в консоли команду:

      composer install
      

      Удачи 🙂

Добавить комментарий

Ваш e-mail не будет опубликован. Обязательные поля помечены *