Перейти к содержимому
BXWiki

Логирование решения - логгер по стандарту, настройка, контекст

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

Механика

Ядро платформы даёт логгер по общепринятому стандарту логирования. Прикладной код зависит от интерфейса логгера, а конкретную реализацию подставляет фабрика по строковому идентификатору.

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

Уровень записи, приёмник и форматтер задают в файле настроек продукта. Секция настроек описывает журналы по именам, и смена приёмника не требует ни одной правки в бизнес-логике.

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

Устойчивая зависимость от журнала передаётся классу через конструктор. Сервис, команда или обработчик получают логгер снаружи, а не создают его заново в каждом методе.

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

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

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

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

Журнал решения не заменяет собой контракт ошибки. Пользователю по-прежнему возвращают результат с ошибкой, а запись в журнал только помогает разобраться потом.

Журнал полезен ровно настолько, насколько его читают. Записи без имени операции и без идентификатора объекта складываются в поток текста, по которому нельзя ответить ни на один вопрос через неделю после сбоя.

Поэтому у каждой записи есть три обязательные части: что происходило, с каким объектом и чем закончилось. Всё остальное - подробности, которые добавляют по мере необходимости.

Шаги

  1. Выбрать имена журналов по крупным частям решения: обмен, оплата, фоновые задания и импорт.
  2. Пробросить логгер в классы решения через конструктор, а не создавать его внутри методов.
  3. Описать уровень записи, приёмник и форматтер в секции настроек по именам журналов.
  4. Замыкания настроек вынести в дополнительный файл настроек продукта.
  5. Разделить сообщение и его контекст, убрав из записи чувствительные данные.
  6. Задать размер ротации файла и положить сам журнал вне каталога сайта проекта.

Код

Получаем логгер по имени:

use Bitrix\Main\Diag\LoggerFactory;


$logger = (new LoggerFactory())->createById('vendor.exchange.orders');
$logger->info('Выгрузка заказов начата');
// имя собирают из модуля и области: так журналы настраиваются по частям
// уровни стандартные: debug, info, warning, error и другие

Фабрика по имени - современный способ получить журнал. Создание конкретной реализации прямо в прикладном коде лишает возможности перенастроить приёмник без правки этого кода.

Принимаем логгер снаружи:

use Psr\Log\LoggerAwareInterface;
use Psr\Log\LoggerAwareTrait;
use Psr\Log\NullLogger;


class OrderExporter implements LoggerAwareInterface
{
    use LoggerAwareTrait;                       // даёт метод установки логгера


        public function __construct() { $this->logger = new NullLogger(); }
    // пустой логгер по умолчанию: класс работает и без настройки журнала
}

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

Пишем сообщение с контекстом:

$this->logger->error('Заказ {orderId} не выгружен: {reason}', [
    'orderId' => $order->getId(),
    'reason' => $result->getErrorMessages()[0] ?? 'нет описания',
    'attempt' => $attempt,
]);
// подстановки берутся из контекста форматтером, склеивать строку не нужно
// уровень выбирают по смыслу: error - сбой, info - обычный ход работы

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

Настраиваем журнал в файле настроек:

/bitrix/.settings.php
'loggers' => ['value' => [
    'vendor.exchange.orders' => [
        'className' => \Bitrix\Main\Diag\FileLogger::class,
        'constructorParams' => ['/var/log/bitrix/exchange.log', 10485760],
        'level' => \Psr\Log\LogLevel::INFO,
    ],
], 'readonly' => true],

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

Убираем из журнала лишнее:

$this->logger->info('Ответ сервиса получен', [
    'status' => $response->getStatus(),
    'hasToken' => $token !== '',        // сам токен в журнал не попадает
    'bodyLength' => strlen($body),      // тело целиком тоже не нужно
]);

Пароли, токены и тела запросов в журнале - готовая утечка. Записывают признаки и размеры, а не значения, и это правило особенно важно для журналов, доступных подрядчикам.

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

AddMessage2Log('аварийная ситуация в прологе', 'vendor.module');
// годится для процедурного кода и раннего этапа загрузки
// в новом коде решения его место занимает логгер по стандарту

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

Проверяем, что журнал действительно пишется:

Окно терминала
ls -lh /var/log/bitrix/exchange.log && tail -5 /var/log/bitrix/exchange.log
grep -c "orderId" /var/log/bitrix/exchange.log
# пустой файл при работающем обмене означает уровень выше уровня сообщений

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

Ограничения

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

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

Файл журнала - это тоже данные с ограничениями доступа. Он лежит вне каталога сайта, и доступ к нему выдают так же осознанно, как доступ к базе.

Разные части решения ведут свои отдельные журналы. Общий файл на всё решение неудобно читать и невозможно настроить по частям.

Типичные проблемы

Журнал не пишется, хотя вызовы есть.

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

Настройки журналов исчезли после сохранения в админке.

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

Файл журнала вырос до гигабайтов.

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

В журнале нашлись токены и пароли.

В контекст записи попали сами значения целиком. В журнал пишут признаки и размеры значений, а не сами значения целиком.

Класс требует логгер, а его негде взять.

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

Частые вопросы

Чем логгер по стандарту лучше своей функции записи?

Его уровень и приёмник настраиваются снаружи, а код остаётся прежним. Своя функция записи в файл жёстко фиксирует и место, и формат.

Где хранить файлы журналов?

Вне каталога сайта, в системном каталоге журналов. Файл внутри сайта скачивается из браузера всеми, кто угадает имя.

Нужны ли отдельные журналы под каждую часть решения?

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

Как быть с журналом в агентах и заданиях?

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

Считать ли журнал заменой мониторингу?

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

Смежное

Первоисточник