Make LoggingEmitter more useful by using Markers (#14121)

* Make LoggingEmitter more useful

* Skip code coverage for facade classes

* fix spellcheck

* code review

* fix dependency

* logging.md

* fix checkstyle

* Add back jacoco version to main pom
This commit is contained in:
Suneet Saldanha 2023-04-27 15:06:06 -07:00 committed by GitHub
parent d4e478c909
commit 84c11df980
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
18 changed files with 81 additions and 31 deletions

View File

@ -422,9 +422,14 @@ There are several emitters available:
##### Logging Emitter Module ##### Logging Emitter Module
|Property|Description|Default| The use this emitter module, set `druid.emitter=logging`. The `logging` emitter uses a Log4j2 logger named
|--------|-----------|-------| `druid.emitter.logging.loggerClass` to emit events. Each event is logged as a single `json` object with a
|`druid.emitter.logging.loggerClass`|Choices: HttpPostEmitter, LoggingEmitter, NoopServiceEmitter, ServiceEmitter. The class used for logging.|LoggingEmitter| [Marker](https://logging.apache.org/log4j/2.x/manual/markers.html) as the feed of the event. Users may wish to edit the
log4j config to route these logs to different sources based on the feed of the event.
|Property|Description| Default |
|--------|-----------|-----------------------------------------------------|
|`druid.emitter.logging.loggerClass`|The class used for logging.|`org.apache.druid.java.util.emitter.core.LoggingEmitter`|
|`druid.emitter.logging.logLevel`|Choices: debug, info, warn, error. The log level at which message are logged.|info| |`druid.emitter.logging.logLevel`|Choices: debug, info, warn, error. The log level at which message are logged.|info|
##### HTTP Emitter Module ##### HTTP Emitter Module

View File

@ -45,14 +45,14 @@ The following example log4j2.xml is based upon the micro quickstart:
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>
@ -157,7 +157,7 @@ The following example shows a `log4j2.xml` that configures some of the more chat
<Configuration status="WARN"> <Configuration status="WARN">
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
</Appenders> </Appenders>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -26,14 +26,14 @@
<Appenders> <Appenders>
<Console name="Console" target="SYSTEM_OUT"> <Console name="Console" target="SYSTEM_OUT">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
</Console> </Console>
<!-- Rolling Files--> <!-- Rolling Files-->
<RollingRandomAccessFile name="FileAppender" <RollingRandomAccessFile name="FileAppender"
fileName="${sys:druid.log.path}/${sys:druid.node.type}.log" fileName="${sys:druid.log.path}/${sys:druid.node.type}.log"
filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log"> filePattern="${sys:druid.log.path}/${sys:druid.node.type}.%d{yyyyMMdd}.log">
<PatternLayout pattern="%d{ISO8601} %p [%t] %c - %m%n"/> <PatternLayout pattern="%d{ISO8601} %p [%t] %c -%notEmpty{ [%markerSimpleName]} %m%n"/>
<Policies> <Policies>
<TimeBasedTriggeringPolicy interval="1" modulate="true"/> <TimeBasedTriggeringPolicy interval="1" modulate="true"/>
</Policies> </Policies>

View File

@ -159,7 +159,6 @@
<plugin> <plugin>
<groupId>org.jacoco</groupId> <groupId>org.jacoco</groupId>
<artifactId>jacoco-maven-plugin</artifactId> <artifactId>jacoco-maven-plugin</artifactId>
<version>0.8.4</version>
<configuration> <configuration>
<excludes> <excludes>
<!-- Ignore firehose code --> <!-- Ignore firehose code -->

View File

@ -465,6 +465,11 @@
<version>1.2.17</version> <version>1.2.17</version>
<scope>test</scope> <scope>test</scope>
</dependency> </dependency>
<dependency>
<groupId>org.slf4j</groupId>
<artifactId>slf4j-api</artifactId>
<scope>provided</scope>
</dependency>
</dependencies> </dependencies>
</profile> </profile>
</profiles> </profiles>

View File

@ -143,7 +143,6 @@
<plugin> <plugin>
<groupId>org.jacoco</groupId> <groupId>org.jacoco</groupId>
<artifactId>jacoco-maven-plugin</artifactId> <artifactId>jacoco-maven-plugin</artifactId>
<version>0.8.5</version>
<configuration> <configuration>
<excludes> <excludes>
<!-- Initialization code --> <!-- Initialization code -->

View File

@ -369,7 +369,6 @@
<plugin> <plugin>
<groupId>org.jacoco</groupId> <groupId>org.jacoco</groupId>
<artifactId>jacoco-maven-plugin</artifactId> <artifactId>jacoco-maven-plugin</artifactId>
<version>${jacoco.version}</version>
<configuration> <configuration>
<excludes> <excludes>
<!-- Tested in integration tests, but we lack unit tests. <!-- Tested in integration tests, but we lack unit tests.

View File

@ -511,6 +511,18 @@
<useManifestOnlyJar>false</useManifestOnlyJar> <useManifestOnlyJar>false</useManifestOnlyJar>
</configuration> </configuration>
</plugin> </plugin>
<plugin>
<groupId>org.jacoco</groupId>
<artifactId>jacoco-maven-plugin</artifactId>
<configuration>
<excludes>
<!-- LoggingEmitter is a delegating class. Skip tests. -->
<exclude>org/apache/druid/java/util/emitter/core/LoggingEmitter.class</exclude>
<!-- Logger is a facade to the slf4j Logger. No tests needed. -->
<exclude>org/apache/druid/java/util/common/logger/Logger.class</exclude>
</excludes>
</configuration>
</plugin>
</plugins> </plugins>
<resources> <resources>

View File

@ -25,6 +25,7 @@ import org.apache.druid.java.util.common.StringUtils;
import org.apache.druid.timeline.DataSegment; import org.apache.druid.timeline.DataSegment;
import org.apache.druid.timeline.SegmentId; import org.apache.druid.timeline.SegmentId;
import org.slf4j.LoggerFactory; import org.slf4j.LoggerFactory;
import org.slf4j.Marker;
import javax.annotation.Nullable; import javax.annotation.Nullable;
import java.util.Collection; import java.util.Collection;
@ -86,6 +87,13 @@ public class Logger
} }
} }
public void trace(Marker marker, String message, Object... formatArgs)
{
if (log.isTraceEnabled()) {
log.trace(marker, StringUtils.nonStrictFormat(message, formatArgs));
}
}
public void debug(String message, Object... formatArgs) public void debug(String message, Object... formatArgs)
{ {
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
@ -93,6 +101,12 @@ public class Logger
} }
} }
public void debug(Marker marker, String message, Object... formatArgs)
{
if (log.isDebugEnabled()) {
log.debug(marker, StringUtils.nonStrictFormat(message, formatArgs));
}
}
public void debug(Throwable t, String message, Object... formatArgs) public void debug(Throwable t, String message, Object... formatArgs)
{ {
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
@ -107,6 +121,13 @@ public class Logger
} }
} }
public void info(Marker marker, String message, Object... formatArgs)
{
if (log.isInfoEnabled()) {
log.info(marker, StringUtils.nonStrictFormat(message, formatArgs));
}
}
public void info(Throwable t, String message, Object... formatArgs) public void info(Throwable t, String message, Object... formatArgs)
{ {
if (log.isInfoEnabled()) { if (log.isInfoEnabled()) {
@ -131,6 +152,11 @@ public class Logger
log.warn(StringUtils.nonStrictFormat(message, formatArgs)); log.warn(StringUtils.nonStrictFormat(message, formatArgs));
} }
public void warn(Marker marker, String message, Object... formatArgs)
{
log.warn(marker, StringUtils.nonStrictFormat(message, formatArgs));
}
public void warn(Throwable t, String message, Object... formatArgs) public void warn(Throwable t, String message, Object... formatArgs)
{ {
logException(log::warn, t, StringUtils.nonStrictFormat(message, formatArgs)); logException(log::warn, t, StringUtils.nonStrictFormat(message, formatArgs));
@ -141,6 +167,11 @@ public class Logger
log.error(StringUtils.nonStrictFormat(message, formatArgs)); log.error(StringUtils.nonStrictFormat(message, formatArgs));
} }
public void error(Marker marker, String message, Object... formatArgs)
{
log.error(marker, StringUtils.nonStrictFormat(message, formatArgs));
}
/** /**
* Protect against assuming slf4j convention. use `error(Throwable t, String message, Object... formatArgs)` instead * Protect against assuming slf4j convention. use `error(Throwable t, String message, Object... formatArgs)` instead
* *

View File

@ -27,6 +27,7 @@ import org.apache.druid.java.util.common.StringUtils;
import org.apache.druid.java.util.common.lifecycle.LifecycleStart; import org.apache.druid.java.util.common.lifecycle.LifecycleStart;
import org.apache.druid.java.util.common.lifecycle.LifecycleStop; import org.apache.druid.java.util.common.lifecycle.LifecycleStop;
import org.apache.druid.java.util.common.logger.Logger; import org.apache.druid.java.util.common.logger.Logger;
import org.slf4j.MarkerFactory;
import java.util.concurrent.RejectedExecutionException; import java.util.concurrent.RejectedExecutionException;
import java.util.concurrent.atomic.AtomicBoolean; import java.util.concurrent.atomic.AtomicBoolean;
@ -98,24 +99,24 @@ public class LoggingEmitter implements Emitter
switch (level) { switch (level) {
case TRACE: case TRACE:
if (log.isTraceEnabled()) { if (log.isTraceEnabled()) {
log.trace(jsonMapper.writeValueAsString(event)); log.trace(MarkerFactory.getMarker(event.getFeed()), jsonMapper.writeValueAsString(event));
} }
break; break;
case DEBUG: case DEBUG:
if (log.isDebugEnabled()) { if (log.isDebugEnabled()) {
log.debug(jsonMapper.writeValueAsString(event)); log.debug(MarkerFactory.getMarker(event.getFeed()), jsonMapper.writeValueAsString(event));
} }
break; break;
case INFO: case INFO:
if (log.isInfoEnabled()) { if (log.isInfoEnabled()) {
log.info(jsonMapper.writeValueAsString(event)); log.info(MarkerFactory.getMarker(event.getFeed()), jsonMapper.writeValueAsString(event));
} }
break; break;
case WARN: case WARN:
log.warn(jsonMapper.writeValueAsString(event)); log.warn(MarkerFactory.getMarker(event.getFeed()), jsonMapper.writeValueAsString(event));
break; break;
case ERROR: case ERROR:
log.error(jsonMapper.writeValueAsString(event)); log.error(MarkerFactory.getMarker(event.getFeed()), jsonMapper.writeValueAsString(event));
break; break;
} }
} }

View File

@ -436,7 +436,6 @@
<plugin> <plugin>
<groupId>org.jacoco</groupId> <groupId>org.jacoco</groupId>
<artifactId>jacoco-maven-plugin</artifactId> <artifactId>jacoco-maven-plugin</artifactId>
<version>${jacoco.version}</version>
<configuration> <configuration>
<excludes> <excludes>
<!-- There are UTs for this class but it is very difficult to get required branch coverage --> <!-- There are UTs for this class but it is very difficult to get required branch coverage -->