Что может быть сложного в логировании? Создал инстанс какого-нибудь Monolog’а, навтыкал $logger->info() под каждой строчкой, выполнение которой хотелось бы запечатлить в истории, и сиди себе посматривай в журнал. А вдруг где-то будет ошибка, лог не сохранится, а логируем мы данные банковских операций?

Я не нашёл информации об этом паттерне на русском (хотя, насколько я слышал, в некоторых книгах его описывают), поэтому думаю, что эта статья имеет право на жизнь.
Задача
Нас попросили залогировать все действия пользователя. Пользователей у нас много, проект большой, поэтому логи должны храниться в ClickHouse (на самом деле тут может быть любое другое хранилище, отличное от основной базы приложения).
Проблема
Какие действия мы обычно логируем? Как правило — это взаимодействие пользователя с базой данных: изменение настроек в личном кабинете, написание комментариев, … . Что может пойти не так?
Представим, что пользователь отправил запрос в контроллер, создающий новый комментарий:
...
$comment = new Comment();
$comment->text("Новый комментарий");
...
$entityManeger->persist($comment);
$entityManager->flush();
$logger->info("Новый комметарий от пользователя {$user->getName()}");
Допустим, что мы молодцы и написали для $logger, который является экземпляром Monolog, обработчик, который записывает сразу в ClickHouse. Такой подход в лоб — плохой подход. Если процесс упадёт на моменте persist’а или на моменте записи в базу — лог не запишется. Напрашивается очевидное решение — обернуть цепочку запросов в транзакцию, и в случае её успешного выполнения писать лог. Если мы используем ORM Doctrine — транзакция откатится автоматически, ничего дополнительного писать не нужно. Если используем что-то иное, например Eloquent, то код будет выглядеть примерно так:
use Illuminate\Support\Facades\DB;
...
...
try {
DB::beginTransaction();
$comment = new Comment();
$comment->text("Новый комментарий");
...
$entityManeger->persist($comment);
$entityManager->flush();
DB::commit();
$logger->info("Новый комметарий от пользователя {$user->getName()}");
} catch (Exception $e) {
DB::rollback();
}
Отлично. Теперь-то всё сработает? Спешу тебя огорчить — если на моменте записи в ClickHouse тот самый ClickHouse упадёт — мы не получим лог, но получим данные, которые нигде не зафиксированы. Или, если отвалится Monolog — опять же, данные выйдут не консистентными. Чёрт с ним, если это логи о комментариях или иной не особо важной активности пользователя. А вот если это данные о транзакциях оплаты, или чеки фискальных накопителей — тут уже дело плохо.
Мы немного подумали и придумали не писать данные напрямую в ClickHouse, а забросить их куда-то, что с большей вероятностью гарантирует нам сохранение сообщения — например в брокер сообщения. Тот же RabbitMQ, с включённой ротацией, гарантирует доставку сообщения даже в случае падения самого кролика.
В этом случае действия выглядит так:
- Сохранение цепочки запросов
- Отправка сообщения с логом в брокер, гарантирующий высокий процент доставки
- Запись сообщения из брокера в ClickHouse
Последний шаг — зависит от брокера и от получателя данных. Либо пишем консольную команду, которая разворачиваем consumer’a и делает запись, и только после записи кидает в брокер ask-подтверждение для удаления из него сообщения. Либо берём какую-нибудь Kafka, для которой есть десятки адаптеров, и если находим адаптер для ClickHouse — Kafka всё сделаем за нас и команду можно не писать.
Выглядит надёжно. Но, у нас всё ещё осталось уязвимое место — если на моменте отправки сообщения в кролик процесс падает, а кролик не успевает его поймать, то мы теряем лог.
Решение
Решение — добавить ещё один этап — запись лога в базу, с которой взаимодействует пользователь.
Мы создаём таблицу, например user_log_outbox:

Первоначальная запись лога включается в ту же транзакцию, что и действия пользователя. Этим мы гарантируем, что консистентность данных будет соблюдена. Дело остаётся за малым — переслать лог через брокер в базу с логами.
Пишем консольную команду, задача которой — опрашивать эту таблицу на наличие новых данных:
...
public function handle()
{
$userLogs = $userLogOutboxRepository->getNewLogs();
if (count($userLogs) === 0) return;
array_map(function ($userLog) {
try {
$messageBus->send($userLog);
$userLog->delete();
} catch (Exception $e) {
}
}, $userLogs);
}
...
Весь код выше — абстрактное представление типичных репозиториев и мессадж-басов. Нашли новый лог? Отправили в брокер.
Далее либо брокер сам доставит сообщение до хранилища, либо развернём consumer’а, который забросит сообщение туда, куда нужно, отправив после этого acknowledge в брокер, тем самым гарантировав, что сообщение записано.
Ссылочки:
twitter — https://twitter.com/SeniorJun
для связи — @publicjunsenior
чатик — https://t.me/junsenior_chat