Битрикс логирование ошибок

Просмотров: 9826
Дата последнего изменения: 21.04.2022

Объяснять, что такое логи — нет необходимости. Когда есть логи, то проще разобраться с возникшими проблемами и выяснить, почему они начались. Основные моменты в использовании логов.

Логи не должны занимать всё свободное пространство на диске, т.е. в логи нужно помещать только нужную информацию, а не всё подряд. Устаревшие логи должны удаляться. Для удаления устаревших логов лучше всего настроить задание на cron.

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

Все логи нужно держать в одной папке, чтобы было удобней их изучать (/logs/, /_logs/, /local/logs/ и т.п. ). В целях защиты следует закрыть доступ к папке с логами по http — настраивается в .htacces,

deny from all

и/или добавить к названию файла уникальный идентификатор.

Папку для логов надо предварительно создать и убедиться, что битрикс (веб-сервер) имеет права на запись в нее.

В системе 1С-Битрикс существует 2 вида логов:

ADDMESSAGE2LOG(…)

Это функция из старого ядра. Многие модули пишут через нее отладочную информацию.

Пример настройки места хранения логов, выводимых данной функцией, выглядит так (папка logs/bx должна быть создана):

define("LOG_FILENAME", $_SERVER["DOCUMENT_ROOT"] . "/logs/bx/" . date("Y-m-d") . ".log");

Прописать данную настройку можно, например, в dbconn.php.

СЕКЦИЯ EXCEPTION_HANDLING В ФАЙЛЕ .SETTINGS.PHP

Это уже функционал нового ядра D7.

Битрикс через данный функционал пишет информацию обо всех ошибках и исключениях. Что именно пишется — зависит от настроек.

Пример настройки логов с разделением по дате:

'exception_handling' => array (
  'value' => array (
      'debug' => false, // disables error output to screen
       // ошибки для вывода в лог
      'handled_errors_types' => E_ALL & ~E_NOTICE & ~E_STRICT & ~E_WARNING,
      'exception_errors_types' => E_ALL & ~E_NOTICE & ~E_WARNING & ~E_STRICT & ~E_COMPILE_WARNING,
      'ignore_silence' => true,
      'assertion_throws_exception' => true,
      'assertion_error_type' => 256,
      'log' => array (
          'settings' => array (
              'file' => "logs/bx_error/" . date("Y-m-d") . ".log",
			  'log_size' => 1000000, // ~ 1Mb per file
          ),
      ),
  ),
  'readonly' => true,
),

ФУНКЦИИ ОТЛАДКИ В ЯДРЕ D7

На замену функции AddMessage2Log в ядре D7 пришли новые функции:

use BitrixMainDiagDebug;
Debug::dumpToFile($_SERVER); // для случаев, когда нужен var_dump
Debug::writeToFile($_SERVER); // когда нужен print_r

Также в ядре D7 появились методы, для измерения времени. В старом ядре аналогов не было.

use BitrixMainDiagDebug;
Debug::startTimeLabel("foo");
foo();
Debug::endTimeLabel("foo");

Debug::startTimeLabel("bar");
bar();
Debug::endTimeLabel("bar");

print_r(Debug::getTimeLabels());

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

Если битрикс свежий и в папке /bitrix/ есть файл .settings.php, то там можно указать файл для лога ошибок и типы ошибок которые будут туда записываться.

У меня на локалке настройки такие:

'exception_handling' => 
  array (
    'value' => 
    array (
      'debug' => true,
      'handled_errors_types' => E_ALL & ~E_NOTICE & ~E_STRICT & ~E_USER_NOTICE & ~E_DEPRECATED,
      'exception_errors_types' => E_ALL & ~E_NOTICE & ~E_WARNING & ~E_STRICT & ~E_USER_WARNING & ~E_USER_NOTICE & ~E_COMPILE_WARNING,
      'ignore_silence' => true,
      'assertion_throws_exception' => false,
      'assertion_error_type' => 256,
      'log' => array (
        'settings' => array (
          'file' => 'bitrix/modules/error.log',
          'log_size' => 1000000,
        ),
	  ),
    ),
    'readonly' => true,
  ),

Обработка ошибок в Битрикс

При разработке под Битрикс можно пользоваться не только логами, установленными в конфигурации сервера, но и своими. Для этого нужно настроить обработчик ошибок в секции exception_handling в файле /bitrix/.settings.php.

'exception_handling' =>
    array (
        'value' =>
            array (
              'handled_errors_types' => E_ALL & ~E_NOTICE & ~E_STRICT & ~E_USER_NOTICE & ~E_DEPRECATED,
              'exception_errors_types' => E_ALL & ~E_NOTICE & ~E_WARNING & ~E_STRICT & ~E_USER_WARNING & ~E_USER_NOTICE & ~E_COMPILE_WARNING,
              'ignore_silence' => true,
              'assertion_throws_exception' => false,
              'assertion_error_type' => 256,
              'debug' => true,
              'log' => array (
                            'settings' => array (
                            'file' => 'bitrix/modules/error.log',
                            'log_size' => 1000000,
                            ),
            ),
    ),
),

• handled_errors_types — типы обрабатываемых ошибок

• exception_errors_types — типы ошибок, в случае которых системой выбрасывается исключение, и работа скрипта останавливается

• ignore_silence — отменить действие оператора подавления ошибок (значок @ перед функцией, например @file(), документация).

• assertion_throws_exception — выбрасывают ли утверждения (assert()) исключения.

• assertion_error_type — тип ошибки для неверного утверждения (по умолчанию — 256 E_USER_ERROR)

• debug — если выставить debug = true, информация об ошибке будет выведена пользователю в браузер. Если debug = false, при возникновении ошибки будет выведено стандартное сообщение от Битрикс, кроме ошибок E_ERROR | E_PARSE

if ($this->debug)
{
    error_reporting($this->handledErrorsTypes);
    @ini_set('display_errors', 'On');
    @ini_set('display_startup_errors', 'On');
    @ini_set('report_memleaks', 'On');
}
else
{
    error_reporting(E_ERROR | E_PARSE);
}

При отключении режима отладки, также сбрасываются настройки для assert()

if ($this->debug)
{
  assert_options(ASSERT_ACTIVE, 1);
  assert_options(ASSERT_WARNING, 0);
  assert_options(ASSERT_BAIL, 0);
  assert_options(ASSERT_QUIET_EVAL, 0);
  assert_options(ASSERT_CALLBACK, array($this, "handleAssertion"));
}
else
{
   assert_options(ASSERT_ACTIVE, 0);
}

• log — секция с указанием логгера. Если пусто, то запись ошибок происходить не будет. В данном случае по умолчанию всю работу на себя возьмет объект класса BitrixMainDiagFileExceptionHandlerLog.
• settings — секция с настройками обработчика ошибок. Можно задавать произвольные параметры. Они все передадутся массивом в метод initialize() обработчика.
• file — относительный путь к файлу логов от корневой директории сайта (BitrixMainApplication::getDocumentRoot().’/’.$file).
• log_size — максимальный размер файла логов в байтах.

Можно использовать собственный обработчик ошибок для записи логов. Для этого в секции log нужно указать:

'class_name' => 'MyLog',
'extension' => 'MyLogExt',
'required_file' => 'modules/mylog.module/mylog.php'

• class_name — имя класса-обработчика. Класс должен наследоваться от BitrixMainDiagExceptionHandlerLog. Метод write в 16 версии отличается от реализации в 15 версии, эта несовместимость может сломать сайт, будьте внимательны.
• extension — подключаемое расширение, содержащее класс-обработчик
• required_file — файл, содержащий нужный класс.

Модули АХТУНГ 500 И АХТУНГ 500 ПРО

Модули Ахтунг 500 и Ахтунг 500 ПРО предназачены для мгновенного оповещения об ошибках по e-mail и через браузер, когда администратор находится на сайте.

Мониторинг ошибок происходит не только через обработчик ошибок Битрикса, но и через чтение файлов логов сервера, есть поиск.

Перейти к подробному описанию Ахтунг 500 ПРО

Два года назад писали про внутренней инструмент для логирования. С помощью модуля Intensa Logger мы выполняем отладку на проектах на 1С-Битрикс.

Ниже расскажем про релиз-версию, в которой:

• повысили уровень качества, стабильности и безопасности кода,
• упростили установку,
• улучшили производительность и отказоустойчивость,
• добавили в проект тесты,
• добавили трекер SQL-запросов,
• добавили новые возможности для кастомизации в рамках проекта.

Результат выложили в 1С-Битрикс: Маркетплейс, пользуйтесь.

Сегодня поделимся обновленной документацией, расскажем о фичах в новой версии и на примерах разберем, как использовать Intensa Logger в проектах.

Учимся логировать с модулем

Intensa Logger — простой функциональный модуль CMS Bitrix, который логирует данные проекта в файлы. Подойдет для отслеживания «‎узких»‎ мест в проекте и дебага при разработке.

В модуле реализованы:

• оповещения о критических проблемах в проекте,
• очищение устаревших лог-файлов,
• таймеры выполнения,
• SQL-трекер на основе diag.

Как добавить модуль в проект

Самый простой способ — установить его через маркетплейс.

Но можно и вручную. Для этого:

1. Клонируем репозиторий в директорию с модулями /bitrix/modules/ или /local/modules/.
2. Переходим в директорию intensa.logger/lib (команда cd intensa.logger/lib).
3. Устанавливаем зависимости composer install --no-dev.
4. Добавляем модуль через админскую часть сайта /bitrix/admin/partner_modules.php.

При установке модуль создает:

• защищённую директорию /logs/ в корне проекта для хранения лог-файлов,
• почтовое события для оповещений фатальных уровней логирования,
• агента для удаления устаревших лог-файлов.

Как работать с хранилищем логов

По умолчанию лог-файлы хранятся в директории /logs/ в корне проекта. Изменить место хранения можно в настройках модуля. Защита логов от просмотра в браузере реализована через .htaccess.

В проектах, которые используют nginx в качестве веб-сервера, нужно самостоятельно обезопасить хранилище. Для этого закрываем директорию от просмотра в браузере в конфигах nginx или меняем пути хранилища логов — выносим хранилище из document_root.

Чтобы файлы логов было легко найти, модуль содержит функционал хранения по дням.

Например, все логи за 19 августа 2021 года можно найти в директории /logs/2021-08-19/. Название лог-файла совпадает с кодом логгера, который передается в конструктор класса ILog.

Уровни логирования

Уровень лога — это классификация проблемы. В модуле они подразделяются так:

• DEBUG,
• INFO,
• NOTICE,
• WARNING,
• ERROR,
• CRITICAL,
• ALERT,
• EMERGENCY.

Для каждого уровня лога действует одноименный метод, но с особенностями.

• log() — является алиасом для info().
• fatal() — является алиасом для alert().

Это наследие, с которым приходится жить 🙂

Уровни CRITICAL, ALERT, EMERGENCY, помимо записи данных в лог-файл, отправляют сообщение администратору сайта. Адрес электронной почты можно указать в настройках модуля.

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

Из чего состоят логи

Разбираем пример по частям.

Как использовать возможности модуля — на примерах

1. Пример инициализации логгера и демонстрация базовых методов.

// Подключение модуля
 BitrixMainLoader::includeModule('intensa.logger');

 // Инициализация объекта логгера
 // В конструктор передаем код логгера, которому будет соответствовать имя лог-файла
 $logger = new IntensaLoggerILog('logger_code');

 // Пример записи логов уровня INFO
 // Вторым параметром можно передать данные любого типа
 $context = ['яблоко', 'мандарин', 'банан'];

 $logger->info('сообщение', $context);

 // Пример записи логов уровня ERROR
 $logger->error('что-то пошло не так', $context);

 // Пример записи логов уровня ALERT
 // В данном случае будет отправлено письмо с информацией из лога
 $logger->alert('алярм! мы все сломали', $context);

Содержимое лог-файла:

[2021-11-24 01:24:30][:info][pid:2696] сообщение Array
 (
     [0] => яблоко
     [1] => мандарин
     [2] => банан
 )
 [2021-11-24 01:24:30][:error][pid:2696] что-то пошло не так Array
 (
     [0] => яблоко
     [1] => мандарин
     [2] => банан
 )
 [2021-11-24 01:24:30][:alert][pid:2696] алярм! мы все сломали Array
 (
     [0] => яблоко
     [1] => мандарин
     [2] => банан
 )

1. Пример вызова таймера.

// Подключение модуля
 BitrixMainLoader::includeModule('intensa.logger');

 // Инициализация объекта логгера
 // В конструктор передаем код логгера, ему будет соответствовать имя лог-файла
 $logger = new IntensaLoggerILog('logger_timer');

 $context = ['яблоко', 'мандарин', 'банан'];
 $logger->info('Логируем какие-то данные', $context);

 // Запуск таймера. Необходимо передать код таймера
 $logger->startTimer('timer_1');
 sleep(1);
 // Остановка таймера. Необходимо передать код таймера.
 $logger->stopTimer('timer_1');
 $logger->startTimer('timer_2');

 // Можно запускать один таймер внутри другого
 $logger->startTimer('timer_internal');
 sleep(2);
 $logger->stopTimer('timer_internal');

 sleep(3);
 $logger->stopTimer('timer_2');

 // Если у таймера не указана точка остановки, то время остановки определяется в дeструкторе класса
 $logger->startTimer('dont_stop');

Содержимое лог файла:

[2021-11-24 01:29:47][:info][pid:2704] Логируем какие-то данные Array
 (
     [0] => яблоко
     [1] => мандарин
     [2] => банан
 )
 [2021-11-24 01:29:48][:info][pid:2704] Timer timer_1 Array
 (
     [CODE] => timer_1
     [START_TIME] => 2021-11-24 01:29:47.000000
     [STOP_TIME] => 2021-11-24 01:29:48.000000
     [EXEC_TIME] => 1.000375032
 )
 [2021-11-24 01:29:50][:info][pid:2704] Timer timer_internal Array
 (
     [CODE] => timer_internal
     [START_TIME] => 2021-11-24 01:29:48.000000
     [STOP_TIME] => 2021-11-24 01:29:50.000000
     [EXEC_TIME] => 2.000512838
 )
 [2021-11-24 01:29:53][:info][pid:2704] Timer timer_2 Array
 (
     [CODE] => timer_2
     [START_TIME] => 2021-11-24 01:29:48.000000
     [STOP_TIME] => 2021-11-24 01:29:53.000000
     [EXEC_TIME] => 5.000887871
 )
 [2021-11-24 01:29:53][:info][pid:2704] Timer dont_stop Array
 (
     [CODE] => dont_stop
     [START_TIME] => 2021-11-24 01:29:53.000000
     [STOP_TIME] => 2021-11-24 01:29:53.000000
     [EXEC_TIME] => 0.010784864
     [STOP_POINT] => __destruct
 )

Формат логов таймера:

• CODE — код таймера, определяется разработчиком при вызове таймера.
• START_TIME — время запуска.
• STOP_TIME — время остановки.
• EXEC_POINT — время исполнения, т. е. разница между временем остановки и временем запуска.
• START_POINT — место определения точки запуска, вызов метода startTimer().
• STOP_POINT — место определения точки остановки, вызов метода через команду stopTimer().
• Значение «__destruct» означает, что для текущего счетчика не вызвали метод stopTimer() и остановка произошла в деструкторе класса.

1. Использование трекера SQL-запросов.

BitrixMainLoader::includeModule('intensa.logger');

 $logger = new IntensaLoggerILog('logger_sql');
 // Запускаем трекер-sql запросов
 $logger->startSqlTracker('get_users');
 // Пример кода, который делает запрос к базе данных
 $users = [];
 $result = BitrixMainUserTable::getList([
     'select' => ['ID','SHORT_NAME'],
     'order' => ['LAST_LOGIN'=>'DESC'],
     'limit' => 3
 ]);
 // Остановка трекера
 $logger->stopSqlTracker('get_users');

Содержимое лог-файла:

[2021-11-24 01:29:48][:info][pid:1138] SqlTracker get_users: Array
 (
     [0] => Array
         (
             [query] => 
                             SELECT main_user.ID AS ID,
                             CONCAT(main_user.LAST_NAME, ' ', UPPER(SUBSTR(main_user.NAME, 1, 1)), '.') AS SHORT_NAME
                             FROM b_user main_user
                             ORDER BY main_user.LAST_LOGIN DESC
                             LIMIT 0, 3
             [time] => 0.0076520442962646
         )
 )

Методы логгера

Доступные методы класса ILog помогут кастомизировать поведение каждого отдельного объекта логгера.

BitrixMainLoader::includeModule('intensa.logger');

 $logger = new IntensaLoggerILog('logger_sql');

 // Метод заставляет логгер перезаписывать файл при каждом новом вызове логирующего метода
 $logger->rewrite();

 // Через этот метод можно установить дополнительный email для получения алерт-сообщений на почту
 $logger->setAlertEmail('additional_admin@no-reply.com');
 $logger->setAlertEmail('additional_admin2@no-reply.com');

 // Позволяет отключить отладку для конкретного логгера
 // Данная настройка уберет из лог-файла информацию о месте вызова логгера
 // Рекомендуется использовать данную настройку для логгеров, записывающих большое кол-во данных при одном вызове
 // Снижает количество оперативной памяти, выделяемой php
 $logger->notUseBacktrace();

 // Включает отладку для конкретного логгера
 // Используется в случае, когда глобально в настройках модуля выключена настройка отладки
 $logger->useBacktrace();

Что нового в модуле

Конфигурация модуля

Полностью отказались от хранения настроек в файле конфигурации и перенесли все настройки в админ-панель Битрикс.

Внедрили ряд новых настроек и информирований. Теперь можно:

• менять права доступа к файлам и директориям логов,
• записывать логи в формате json,
• управлять ротацией логов,
• получать информацию о безопасности логов (логи недоступны в браузере),
• получать информацию о существовании корневой директории и делать в ней записи.

Отказоустойчивость и улучшение производительности

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

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

Переписали функционал записи логов в файл и протестировали его на серверах с 1 Гб оперативной памяти. Тестовые скрипты для записи большого количества данных больше не падали. Производительность увеличилась примерно на 50 %, если сравнивать с альфа-версией.

Удаление устаревших логов

Еще одна проблема, с которой столкнулись, — это громадный объем устаревших данных логирования. Ценности они не несли, а место на сервере занимали. Поэтому мы реализовали на агенте функционал, который очищает устаревшие файлы и директории. В настройках модуля можно указать, как часто нужно удалять устаревшие логи.

Ссылки на модуль

1. Маркетплейс 1С-Битрикс http://marketplace.1c-bitrix.ru/solutions/intensa.logger/
2. Репозиторий https://github.com/intensa/intensa.logger

Статью подготовили: