Skip to content

Commit

Permalink
Enable kv logs in log4j configuration (#3986)
Browse files Browse the repository at this point in the history
### Motivation
We introduced DirectIO since BookKeeper 4.16.0, and the DirectIO classes use KV-based Slf4jSlogger. https://github.com/apache/bookkeeper/blob/master/bookkeeper-slogger/slf4j/src/main/java/org/apache/bookkeeper/slogger/slf4j/Slf4jSlogger.java 

In order to print the KV out, we need to add `%X` flag in log4j2.yaml, otherwise the log will miss the detailed key and values.

<!-- Explain here the context, and why you're making that change. What is the problem you're trying to solve. -->

### Modifications
In order to reduce the impact on current logger appenders, I add MDC-based appenders for `CONSOLE`, `TRACEFILE`, and `ROLLINGFILE` by adding `%X` for log4j2.yaml Appender PatternLayout. 
Only classes under `org.apache.bookkeeper.bookie.storage.directentrylogger` will enable MDC-based appender logger.

If the key value has items, the log will look like:
```
2023-06-19T16:01:56,685+0800 [main] INFO  org.apache.bookkeeper.bookie.storage.directentrylogger.EntryLogIdsImpl {dirs=[data/bookkeeper/ledgers/current], durationMs=0, event=ENTRYLOG_IDS_CANDIDATES_SELECTED, maxId=21474836
47, nextId=0} - ENTRYLOG_IDS_CANDIDATES_SELECTED
2023-06-19T16:01:56,721+0800 [main] INFO  org.apache.bookkeeper.bookie.storage.directentrylogger.DirectEntryLogger {directory=data/bookkeeper/ledgers/current, event=ENTRYLOGGER_CREATED, maxCachedReaders=32, maxCachedReader
sPerThread=4, maxFileSize=1073741824, maxSaneEntrySize=5252620, perThreadBufferSize=33554432, readBufferSize=8388608, singleWriteBufferSize=33554432, totalReadBufferSize=268435456, totalWriteBufferSize=268435456} - ENTRYLO
GGER_CREATED
```
  • Loading branch information
hangc0276 committed Aug 29, 2023
1 parent 5a47c1d commit da1d8eb
Showing 1 changed file with 16 additions and 0 deletions.
16 changes: 16 additions & 0 deletions conf/log4j2.xml
Original file line number Diff line number Diff line change
Expand Up @@ -30,20 +30,36 @@
<Console name="CONSOLE" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} - %-5p - [%t:%C{1}@%L] - %m%n"/>
</Console>
<Console name="CONSOLEMDC" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} - %-5p - [%t:%C{1}@%L] %X - %m%n"/>
</Console>
<File name="TRACEFILE" fileName="${sys:bookkeeper.log.dir}/bookkeeper-trace.log">
<PatternLayout pattern="%d{ISO8601} - %-5p [%t:%C{1}@%L][%ndc] - %m%n"/>
</File>
<File name="TRACEFILEMDC" fileName="${sys:bookkeeper.log.dir}/bookkeeper-trace.log">
<PatternLayout pattern="%d{ISO8601} - %-5p [%t:%C{1}@%L][%ndc] %X - %m%n"/>
</File>
<RollingFile name="ROLLINGFILE" fileName="${sys:bookkeeper.log.dir}/${sys:bookkeeper.log.file}" filePattern="${sys:bookkeeper.log.dir}/${sys:bookkeeper.log.file}%d{.yyyy-MM-dd}">
<PatternLayout pattern="%d{ISO8601} - %-5p [%t:%C{1}@%L] - %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy modulate="true"/>
</Policies>
<DefaultRolloverStrategy max="100"/>
</RollingFile>
<RollingFile name="ROLLINGFILEMDC" fileName="${sys:bookkeeper.log.dir}/${sys:bookkeeper.log.file}" filePattern="${sys:bookkeeper.log.dir}/${sys:bookkeeper.log.file}%d{.yyyy-MM-dd}">
<PatternLayout pattern="%d{ISO8601} - %-5p [%t:%C{1}@%L] %X - %m%n"/>
<Policies>
<TimeBasedTriggeringPolicy modulate="true"/>
</Policies>
<DefaultRolloverStrategy max="100"/>
</RollingFile>
</Appenders>
<Loggers>
<Root level="${sys:bookkeeper.log.root.level}">
<AppenderRef ref="${sys:bookkeeper.log.root.appender}"/>
</Root>
<Logger name="org.apache.bookkeeper.bookie.storage.directentrylogger" level="INFO">
<AppenderRef ref="${sys:bookkeeper.log.root.appender}MDC"/>
</Logger>
</Loggers>
</Configuration>

0 comments on commit da1d8eb

Please sign in to comment.