Отладка PHP скриптов с помощью системных логов

Расширенные примеры логирования

Monolog с несколькими обработчиками и форматированием

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

require 'vendor/autoload.php';

use Monolog\Logger;
use Monolog\Handler\StreamHandler;
use Monolog\Handler\NativeMailerHandler;
use Monolog\Formatter\LineFormatter;

$log = new Logger('production');

// Обработчик для файла с ротацией даты
$fileHandler = new StreamHandler(__DIR__ . '/logs/app_'.date('Y-m-d').'.log', Logger::DEBUG);
$fileHandler->setFormatter(new LineFormatter("[%datetime%] %channel%.%level_name%: %message% %context% %extra%\n"));
$log->pushHandler($fileHandler);

// Обработчик для email – только ошибки и выше
$mailHandler = new NativeMailerHandler(
    'admin@example.com',
    'Критическая ошибка в приложении',
    'errors@example.com',
    Logger::ERROR
);
$log->pushHandler($mailHandler);

// Логирование с контекстом
$log->info('Разработчик запросил страницу', ['uri' => $_SERVER['REQUEST_URI']]);
$log->error('Исключение в модуле', ['exception' => $e->getMessage()]);

Результат в файле (pre.ex_r):

[2025-02-24 14:30:01] production.INFO: Разработчик запросил страницу {"uri":"/index.php"} []
[2025-02-24 14:30:02] production.ERROR: Исключение в модуле {"exception":"Connection refused"} []

Логирование с использованием процессоров для добавления данных

Processors позволяют обогащать каждую запись, например, IP-адресом или идентификатором пользователя.

use Monolog\Processor\WebProcessor;
use Monolog\Processor\IntrospectionProcessor;

$log->pushProcessor(new WebProcessor());
$log->pushProcessor(new IntrospectionProcessor(Logger::WARNING)); // добавляет имя класса и строку

$log->warning('Время выполнения превысило 2 секунды');

Вывод (pre.ex_r):

[2025-02-24 14:32:10] production.WARNING: Время выполнения превысило 2 секунды {"ip":"192.168.1.1","method":"GET","url":"/slow.php"} {"class":"App\\Controller\\IndexController","function":"index","line":45}

Логирование исключений в Monolog

Monolog умеет форматировать объекты Throwable как строку.

try {
    throw new \InvalidArgumentException('Неверный ID пользователя');
} catch (\Throwable $e) {
    $log->error($e->getMessage(), ['exception' => $e]);
}

В файле появится полное исключение с трейсом (pre.ex_r):

[2025-02-24 14:35:00] production.ERROR: Неверный ID пользователя {"exception":"[object] (InvalidArgumentException(code: 0): Неверный ID пользователя at /var/www/index.php:15)"} []

Собственный обработчик ошибок с захватом фатальных

Пример более полной реализации, которая ловит и фатальные ошибки через shutdown.

set_error_handler(function($severity, $message, $file, $line) {
    $logLine = "[$severity] $message в файле $file на строке $line";
    file_put_contents('/var/log/errors.txt', $logLine . PHP_EOL, FILE_APPEND | LOCK_EX);
});

register_shutdown_function(function() {
    $lastError = error_get_last();
    if ($lastError !== null && in_array($lastError['type'], [E_ERROR, E_PARSE, E_CORE_ERROR, E_COMPILE_ERROR])) {
        $logLine = "[FATAL] {$lastError['message']} в файле {$lastError['file']} на строке {$lastError['line']}";
        file_put_contents('/var/log/errors.txt', $logLine . PHP_EOL, FILE_APPEND | LOCK_EX);
    }
});

При ошибке типа 'Call to undefined function' будет записано (pre.ex_r):

[FATAL] Call to undefined function undefinedFunction() в файле /var/www/fatal.php на строке 3

Сравнение производительности: file_put_contents vs Monolog

Для оценки быстродействия можно провести микро-тест. Monolog с одним обработчиком показывает сопоставимую скорость, но при большом количестве запросов (10000+) накладные расходы на классы и автозагрузку становятся заметными. Однако для реальных приложений гибкость и структурированность Monolog оправдывают затраты.

$start = microtime(true);
for ($i=0; $i<1000; $i++) {
    file_put_contents('/dev/null', "$i", FILE_APPEND | LOCK_EX);
}
echo 'Время file_put_contents: ' . (microtime(true) - $start) . ' сек.';

Время file_put_contents: 0.045 сек.

$log->pushHandler(new StreamHandler('/dev/null', Logger::DEBUG));
$start = microtime(true);
for ($i=0; $i<1000; $i++) {
    $log->addRecord(Logger::DEBUG, $i);
}
echo 'Время Monolog: ' . (microtime(true) - $start) . ' сек.';

Время Monolog: 0.067 сек.