Логирование
Модуль декларативного логирования позволяет описывать логирование метода с помощью аннотаций @Log, @Mask и @Mdc.
На этапе компиляции Kora создает аспект-обертку для метода; обертка логирует вход в метод, выход из метода, результат, ошибку и значения MDC без ручного кода в бизнес-логике.
Это удобно для единообразной диагностики вызовов, особенно когда нужно быстро понять, какой метод был вызван, с какими аргументами и как он завершился.
Пошаговый разбор перед справочным описанием смотрите в разделе Наблюдаемость.
Подключение¶
Аннотации и вспомогательные классы предоставляются зависимостью logging-common.
Обычно она уже приходит через другие модули Kora или через Logback, но при использовании аннотаций напрямую зависимость можно добавить явно:
Зависимость build.gradle:
Модуль:
Зависимость build.gradle.kts:
Модуль:
LogbackModule уже наследует LoggingModule, поэтому приложению с Logback объявлять LoggingModule отдельно не нужно.
Для генерации аспектов также должны быть подключены общие обработчики аннотаций или KSP-обработчики.
В обычном приложении Kora они уже подключены как часть базовой настройки проекта.
Логирование¶
Логирование метода настраивается комбинациями аннотаций:
@Log- логирует вход и выход метода (по умолчанию:INFO).@Log.in- логирует только вход в метод (по умолчанию:INFO).@Log.out- логирует только выход из метода (по умолчанию:INFO).@Log.result- задает уровень, начиная с которого в лог добавляется значение результата (по умолчанию:DEBUG).@Log.off- отключает логирование результата метода или отдельного параметра.@Log(Level)на параметре - задает уровень, начиная с которого параметр попадает в структурированные данные (по умолчанию:DEBUGдля параметра без отдельной аннотации).
Уровень — это org.slf4j.event.Level.
Само событие входа или выхода пишется на уровне, указанном в @Log, @Log.in или @Log.out.
Значения аргументов и результата добавляются в структурированные данные только если включен соответствующий уровень детализации.
Уровень детализации никогда не бывает менее подробным, чем уровень самого события: если событие пишется на DEBUG, то параметр, объявленный как @Log(Level.INFO), все равно попадет в лог на DEBUG — описывать событие, которое не пишется, смысла нет.
Какой уровень детализации активен, зависит от эффективного уровня логгера, настроенного через logging.levels — смотрите настройку уровней логирования.
Значения пишутся в структурированный маркер data; энкодер ConsoleTextRecordEncoder из Logback выводит его отдельной строкой после сообщения.
Аргументов¶
| Уровень логирования | Лог |
|---|---|
| DEBUG |
INFO [main] io.koraframework.example.Example.doWork - > data={"numParam":"4"} |
| TRACE |
INFO [main] io.koraframework.example.Example.doWork - > data={"numParam":"4"} |
| INFO |
INFO [main] io.koraframework.example.Example.doWork - > |
Аргументы, для которых не задан отдельный конвертер, пишутся через String.valueOf(...), поэтому в JSON они всегда выглядят как строки.
Результата¶
| Уровень логирования | Лог |
|---|---|
| DEBUG |
INFO [main] io.koraframework.example.Example.doWork - < data={"out":"testResult"} |
| TRACE |
INFO [main] io.koraframework.example.Example.doWork - < data={"out":"testResult"} |
| INFO |
INFO [main] io.koraframework.example.Example.doWork - < |
Аргументов и результата¶
| Уровень логирования | Лог |
|---|---|
| DEBUG |
INFO [main] io.koraframework.example.Example.doWork - > data={"strParam":"s","numParam":"4"} INFO [main] io.koraframework.example.Example.doWork - < data={"out":"testResult"} |
| TRACE |
INFO [main] io.koraframework.example.Example.doWork - > data={"strParam":"s","numParam":"4"} INFO [main] io.koraframework.example.Example.doWork - < data={"out":"testResult"} |
| INFO |
INFO [main] io.koraframework.example.Example.doWork - > INFO [main] io.koraframework.example.Example.doWork - < |
Если метод завершается ошибкой, аспект пишет выход из метода на уровне WARN с данными об ошибке errorType и errorMessage, после чего пробрасывает исключение дальше без изменений.
При включенном DEBUG в лог также передается объект исключения, поэтому печатается стектрейс.
Логирование ошибки выполняется для любой из аннотаций @Log, @Log.in и @Log.out — метод, помеченный только @Log.in, тоже сообщает о своих падениях.
WARN [main] io.koraframework.example.Example.doWork - <
data={"errorType":"java.lang.IllegalStateException","errorMessage":"OPS"}
Выборочное логирование¶
| Уровень логирования | Лог |
|---|---|
| TRACE, DEBUG |
INFO [main] io.koraframework.example.Example.doWork - < |
| INFO |
INFO [main] io.koraframework.example.Example.doWork - < |
В этом примере @Log.off на методе отключает запись значения результата, но не отключает само событие выхода из метода.
Чтобы исключить из лога отдельный аргумент, @Log.off ставится на параметр.
Уровень детализации параметров можно задавать отдельно:
При уровне INFO в структурированные данные попадет только id, а payload появится только при включенном TRACE.
Значение результата можно вывести уже на уровне INFO, если явно указать @Log.result(Level.INFO):
Структурированный параметр¶
Если строковое представление параметра не подходит для лога, пометьте параметр аннотацией @Json.
Тогда аспект возьмет JSON-писатель, сгенерированный для типа модулем JSON, и запишет значение вложенным JSON-объектом, а не строкой.
| Уровень логирования | Лог |
|---|---|
| DEBUG, TRACE |
INFO [main] io.koraframework.example.Example.doWork - > data={"entity":{"name":"Bob","code":"42"}} |
| INFO |
INFO [main] io.koraframework.example.Example.doWork - > |
@Json ставится именно на логируемый элемент — на параметр либо на метод, если структурированным должен быть результат:
Для значений, которые формируются в месте вызова, а не приходят аргументами метода, интерфейс StructuredArgument предоставляет статические фабрики:
arg(fieldName, value)— создает структурированное значение; перегрузки принимаютString,Integer,Long,Boolean,Map<String, String>,JsonWriter<T>вместе со значением или произвольныйStructuredArgumentWriter.marker(fieldName, value)— создаетorg.slf4j.Markerс тем же набором перегрузок, чтобы прикрепить структурированные данные к одной записи лога.
Любой StructuredArgumentWriter можно отрендерить вручную методом writeToString() — это удобно в тестах.
Конвертация параметров¶
Если тип параметра нельзя пометить @Json или представление в логе должно отличаться от представления на проводе, опишите внешний StructuredArgumentMapper и укажите его через @Mapping у нужного аргумента.
Маппер получает исходное значение параметра и пишет структурированное значение в JsonGenerator.
public record Entity(String name, String code) { }
public final class EntityLogMapper implements StructuredArgumentMapper<Entity> {
@Override
public void write(JsonGenerator gen, Entity value) {
gen.writeString(value.name());
}
}
@Log.in
public String doWork(@Mapping(EntityLogMapper.class) Entity entity) {
return "testResult";
}
data class Entity(val name: String, val code: String)
class EntityLogMapper : StructuredArgumentMapper<Entity> {
override fun write(gen: JsonGenerator, value: Entity) = gen.writeString(value.name)
}
@Log.`in`
fun doWork(@Mapping(EntityLogMapper::class) entity: Entity): String {
return "testResult"
}
| Уровень логирования | Лог |
|---|---|
| DEBUG, TRACE |
INFO [main] io.koraframework.example.Example.doWork - > data={"entity":"Bob"} |
| INFO |
INFO [main] io.koraframework.example.Example.doWork - > |
JsonGenerator здесь — это tools.jackson.core.JsonGenerator; его методы записи бросают непроверяемое JacksonException, поэтому методы мапперов не объявляют проверяемых исключений.
Тот же @Mapping можно повесить на сам метод, чтобы сконвертировать результат.
Обобщенный маппер вида MyMapper<T> implements StructuredArgumentMapper<T> тоже поддерживается — аспект параметризует его типом значения.
Маппер и контейнер зависимостей
Маппер с зависимостями в конструкторе должен быть компонентом графа и помечаться @Component.
Маппер без зависимостей помечать @Component нельзя — Kora создает его сама, а лишний компонент приводит к ошибке сборки графа Multiple components match.
Маскирование¶
Чувствительные значения можно замаскировать до попадания в лог с помощью аннотации @Mask.
Маскирование работает поверх JSON-представления значения: вывод писателя пропускается через делегирующий генератор, который подменяет совпавшие поля значением от MaskingStrategy.
У @Mask есть единственный атрибут value() — реализация MaskingStrategy (по умолчанию: MaskingFull.class). Аннотацию можно ставить на:
- класс или запись (не абстрактные) — включает генерацию правил маскирования для типа и задает стратегию по умолчанию для его полей;
- поле или компонент записи — помечает соответствующее поле
JSONкак маскируемое; - логируемый параметр или метод — указывает аспекту
@Logписать значение через маскирующий маппер.
INFO [main] io.koraframework.example.Example.register - >
data={"user":{"name":"Bob","credentials":{"password":"s3cr***","cardNumber":"***3456","login":"bob"}}}
Маскируются только поля, помеченные @Mask — @Mask на типе не маскирует всё подряд, а объявляет, что для этого типа нужно сгенерировать правила, и задает стратегию по умолчанию для его маскируемых полей.
Стратегия поля выбирается в таком порядке: стратегия, указанная на самом поле, затем указанная на объемлющем типе, затем MaskingFull.
Имена полей берутся из JSON-представления, поэтому переименования @JsonField и стратегии именования учитываются, а поля @JsonSkip игнорируются.
Вложенные типы, помеченные @Json или @Mask, обходятся рекурсивно, в том числе через коллекции, массивы и словари, поэтому @Mask на листовом поле действует везде, куда до этого поля можно добраться от логируемого объекта.
@Mask и @Json на логируемом элементе независимы:
@Mask @Json- значение пишется вложеннымJSON-объектом с подмененными полями (рекомендуемый вариант).@Maskбез@Json- значение пишется однойJSON-строкой, внутри которой лежит замаскированный документ.
Стратегии маскирования¶
Стратегия — это реализация MaskingStrategy с единственным методом String mask(Object value).
В модуле есть три реализации, и все они зарегистрированы как компоненты по умолчанию с настройками по умолчанию:
MaskingFull- заменяет значение целиком строкой-заменителем (по умолчанию:***).MaskingKeepFirst- оставляет первыеkeepсимволов (по умолчанию:4) и дописывает заменитель (по умолчанию:***). Если значение не длиннееkeep, пишется только заменитель.MaskingKeepLast- пишет заменитель (по умолчанию:***) и дописывает последниеkeepсимволов (по умолчанию:4).
Чтобы изменить строку-заменитель или количество сохраняемых символов, объявите стратегию своим компонентом — он перекроет компонент по умолчанию:
Собственная стратегия — это обычный класс, реализующий MaskingStrategy.
Сгенерированные правила получают его из контейнера зависимостей, поэтому действует то же правило, что и для мапперов: помечайте класс @Component, только если у него есть зависимости в конструкторе.
public final class EmailMaskingStrategy implements MaskingStrategy {
@Override
public String mask(Object value) {
var email = String.valueOf(value);
var at = email.indexOf('@');
return at > 0 ? "***" + email.substring(at) : "***";
}
}
@Mask
@Json
public record User(String name, @Mask(EmailMaskingStrategy.class) String email) { }
class EmailMaskingStrategy : MaskingStrategy {
override fun mask(value: Any?): String {
val email = value.toString()
val at = email.indexOf('@')
return if (at > 0) "***" + email.substring(at) else "***"
}
}
@Mask
@Json
data class User(val name: String, @Mask(EmailMaskingStrategy::class) val email: String)
В mask(...) приходит исходное значение JSON: String, Boolean, Number, BigInteger, BigDecimal либо byte[] для бинарных значений.
Значения null не маскируются и метод для них не вызывается, ключи словарей как значения тоже не маскируются.
Правила маскирования¶
Для каждого типа с аннотацией @Mask обработчик генерирует модуль, который поставляет компонент MaskingRules<T> с описанием того, какие поля JSON и какой стратегией подменять.
Сгенерированный модуль подхватывается контейнером зависимостей автоматически, регистрировать его вручную не нужно.
Когда правила нужно собрать динамически — например, для типа, исходники которого вам не принадлежат — унаследуйтесь от MaskingRules<T> и укажите класс на логируемом элементе через @Mapping:
Ключ правила — это либо имя поля, либо путь от корня логируемого объекта через точку:
password- маскирует любое полеJSONс именемpassword, где бы оно ни встретилось;credentials.cardNumber- маскируетcardNumberтолько тогда, когда до него добрались через полеcredentials;payments.*.cardNumber-*соответствует ровно одному динамическому сегменту пути, что как раз дают ключи словарей.
Те же правила можно собрать билдером: MaskingRules.builder(User.class).mask("password", new MaskingFull()).build().
MDC (Mapped Diagnostic Context)¶
Аннотация @Mdc добавляет пары ключ-значение в MDC (Mapped Diagnostic Context).
MDC хранит контекст выполнения и позволяет добавлять его в сообщения лога: например, идентификаторы запроса, пользователя или операции.
Аннотацию можно применять к методам и параметрам методов.
На методах поддерживается повторное использование @Mdc.
Значения, добавленные без global = true, восстанавливаются после выполнения метода.
Параметры аннотации @Mdc:
key()- ключ записиMDC(по умолчанию:"").value()- значение записиMDC(по умолчанию:"").global()- оставить значение вMDCпосле выхода из метода (по умолчанию:false).
Для @Mdc на методе требуются непустые key и value, иначе компиляция завершится ошибкой.
Для @Mdc на параметре ключ берется из key, затем из value; если оба значения пустые, используется имя параметра.
Значением записи становится значение параметра.
Параметры типов String, Integer/Int, Long, Boolean и StructuredArgumentWriter сохраняют свой тип в JSON, остальные примитивы пишутся через String.valueOf(...), а любой другой тип — через toString().
Если значение непримитивного параметра равно null, запись в MDC просто не добавляется.
Аннотация параметра¶
В этом случае ключ MDC совпадает с именем параметра s, а значением становится значение параметра.
Аннотация параметра с ключом¶
Здесь ключ MDC — 123, а значение — значение параметра s.
Аннотация метода¶
В этом примере перед вызовом метода в MDC добавляется запись key1=value2.
После завершения метода предыдущее значение key1 восстанавливается.
Комбинированное¶
В этом примере к методу применены две аннотации @Mdc, и одна — к параметру.
Запись key=value остается в MDC после выполнения метода из-за global = true; остальные записи восстанавливаются или удаляются.
Под капотом неглобальные записи снимаются слепком до вызова и восстанавливаются в блоке finally при возврате из метода, поэтому за границы метода они не утекают.
Записи с global = true — как на аннотации метода, так и на аннотации параметра — и любые значения, выставленные императивным MDC.put, остаются в текущей области MDC и потому видны во всех последующих строках лога этого запроса, сообщения или задания.
Генерация значения из кода¶
При вызове метода в MDC добавляется запись с ключом key, значением которой будет случайный UUID.
Значение в формате ${...} вставляется в сгенерированный код как выражение, поэтому оно должно быть корректным кодом на языке аннотированного класса.
Пример лога с MDC:
INFO [main] io.koraframework.example.Example.test - key="ee1a1a0e-3fdf-4e46-8b6e-2f16d2f0f0a1" key1="value2" 123="testValue" >
data={"s":"testValue"}
@Mdc не поддерживается для методов, возвращающих CompletionStage, CompletableFuture, Future, Mono или Flux.
Для Kotlin поддерживаются обычные и suspend методы, но в suspend методах нельзя использовать global = true.
Императивный MDC¶
Там, где аннотация не подходит — внутри перехватчиков, фильтров или обычного кода сервиса — используйте императивный API io.koraframework.logging.common.MDC.
Это программный аналог @Mdc: записи попадают в MDC, привязанный к текущей области, и появляются во всех строках лога до конца этой области.
Kora создает новый MDC в начале каждой единицы работы — HTTP-запроса, записи Kafka, вызова gRPC, запуска задания планировщика, сообщения JMS — поэтому записи одного запроса не протекают в другой.
У статического метода put есть перегрузки для значений String, Integer, Long и Boolean, а также перегрузка с StructuredArgumentWriter для структурированных значений.
remove(key) удаляет одну запись, а get().values() возвращает текущие записи неизменяемой картой Map<String, StructuredArgumentWriter>.
import io.koraframework.logging.common.MDC;
@Component
public final class OrderService {
public void process(String orderId) {
MDC.put("orderId", orderId); // String
MDC.put("attempt", 1); // Integer
MDC.put("bytes", 1024L); // Long
MDC.put("retryable", true); // Boolean
MDC.put("payload", gen -> gen.writeString(orderId)); // StructuredArgumentWriter
// ... business logic; every log line in this scope now carries the keys
MDC.remove("attempt"); // drop a single key
var current = MDC.get().values(); // read current entries
}
}
import io.koraframework.logging.common.MDC
@Component
class OrderService {
fun process(orderId: String) {
MDC.put("orderId", orderId) // String
MDC.put("attempt", 1) // Integer
MDC.put("bytes", 1024L) // Long
MDC.put("retryable", true) // Boolean
MDC.put("payload") { gen -> gen.writeString(orderId) } // StructuredArgumentWriter
// ... business logic; every log line in this scope now carries the keys
MDC.remove("attempt") // drop a single key
val current = MDC.get().values() // read current entries
}
}
В отличие от @Mdc, у императивного API нет ограничений на сигнатуру метода, потому что он пишет в текущую область, а не оборачивает вызов метода.
MDC доступен как ScopedValue с именем MDC.VALUE.
Вне области запроса, сообщения или задания — во время инициализации графа, в shutdown hook или в обычном юнит-тесте — ничего не привязано и MDC.get() падает, поэтому такой код нужно защищать:
Чтобы выполнить собственный код в новой области MDC, привяжите значение явно через ScopedValue.where(MDC.VALUE, new MDC()); MDC.fork() создает независимую копию текущих записей — именно так Kora поступает, когда передает работу во вложенную область.
Используйте MDC от Kora, а не от SLF4J
Всегда импортируйте io.koraframework.logging.common.MDC, но не org.slf4j.MDC.
Класс SLF4J пишет в обычный ThreadLocal, не связанный с областью, которую Kora открывает на запрос, сообщение или задание: такие значения не очищаются между единицами работы, теряются при передаче работы другому потоку и умеют хранить только строки.
MDC от Kora ограничен областью, распространяется самим фреймворком и хранит структурированные значения JSON.
Асинхронное логирование должно идти через KoraAsyncAppender — он снимает слепок текущего MDC в вызывающем потоке до того, как событие уйдет в поток аппендера. Смотрите Logback.
Сигнатуры¶
Поддерживаемые сигнатуры методов для аспектов логирования:
Класс не должен быть final, чтобы аспект мог создать наследника, метод не должен быть final или private, а у класса должен быть конструктор, видимый сгенерированному прокси.
T — тип возвращаемого значения либо void.
T myMethod()Optional<T> myMethod()CompletionStage<T> myMethod()CompletionStage (только для@Log, вход логируется при вызове, а выход — при завершении)CompletableFuture<T> myMethod()(только для@Log, вход логируется при вызове, а выход — при завершении)
Mono<T> и Flux<T> из Project Reactor, как и обычный Future<T>, не являющийся CompletionStage, не поддерживаются — компиляция завершится явной ошибкой.
Класс должен быть open и не абстрактным, чтобы аспект мог создать наследника, а функция должна быть open и членом этого класса — функции верхнего уровня проксировать нельзя.
T — тип возвращаемого значения, T? либо Unit.
myMethod(): Tsuspend myMethod(): TKotlin Coroutines (требуется зависимость какimplementation)myMethod(): Flow<T>Kotlin Coroutines (только для@Log, требуется зависимость какimplementation)
Для Flow<T> событие входа логируется при старте потока, каждый выданный элемент логируется сообщением <<<, а сообщение < пишется при завершении потока.
Mono<T> и Flux<T> из Project Reactor не поддерживаются — компиляция завершится явной ошибкой.
@Mdc строже @Log: он принимает только синхронные методы и, в Kotlin, suspend функции.