This is an automated email from the ASF dual-hosted git repository.
hansva pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/hop.git
The following commit(s) were added to refs/heads/main by this push:
new 355da0fd56 Issue #8321 : Use the real Log4j2 SLF4J binding with a
default config and publish Hop context as MDC (#8374)
355da0fd56 is described below
commit 355da0fd5640f6dfcf8e0d8d246780f26994cafa
Author: Romain Manni-Bucau <[email protected]>
AuthorDate: Wed Sep 16 11:38:56 2026 +0200
Issue #8321 : Use the real Log4j2 SLF4J binding with a default config and
publish Hop context as MDC (#8374)
* Issue #8321 : Use the real Log4j2 SLF4J binding with a default config and
publish Hop context as MDC
* avoid duplicate logging by default and update docs
---------
Co-authored-by: Hans Van Akelyen <[email protected]>
---
core/pom.xml | 10 +-
.../core/logging/Slf4jLoggingEventListener.java | 59 ++++++++----
core/src/main/resources/log4j2.xml | 49 ++++++++++
.../logging/DefaultLog4j2ConfigurationTest.java | 107 +++++++++++++++++++++
.../logging/Slf4jLoggingEventListenerTest.java | 42 ++++++++
.../pages/architecture/logging-and-debugging.adoc | 37 +++++++
lib/pom.xml | 6 +-
7 files changed, 285 insertions(+), 25 deletions(-)
diff --git a/core/pom.xml b/core/pom.xml
index 8d65652b9a..fb53a04ead 100644
--- a/core/pom.xml
+++ b/core/pom.xml
@@ -239,6 +239,11 @@
<groupId>org.apache.logging.log4j</groupId>
<artifactId>log4j-core</artifactId>
</dependency>
+ <dependency>
+ <groupId>org.apache.logging.log4j</groupId>
+ <artifactId>log4j-slf4j2-impl</artifactId>
+ <scope>compile</scope>
+ </dependency>
<dependency>
<groupId>org.apache.xmlgraphics</groupId>
<artifactId>batik-anim</artifactId>
@@ -449,11 +454,6 @@
<artifactId>slf4j-api</artifactId>
<scope>compile</scope>
</dependency>
- <dependency>
- <groupId>org.slf4j</groupId>
- <artifactId>slf4j-nop</artifactId>
- <scope>compile</scope>
- </dependency>
<dependency>
<groupId>xml-apis</groupId>
<artifactId>xml-apis-ext</artifactId>
diff --git
a/core/src/main/java/org/apache/hop/core/logging/Slf4jLoggingEventListener.java
b/core/src/main/java/org/apache/hop/core/logging/Slf4jLoggingEventListener.java
index 3fe8340eec..51612cc279 100644
---
a/core/src/main/java/org/apache/hop/core/logging/Slf4jLoggingEventListener.java
+++
b/core/src/main/java/org/apache/hop/core/logging/Slf4jLoggingEventListener.java
@@ -31,9 +31,19 @@ import java.util.function.Function;
import org.apache.hop.core.util.Utils;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
public class Slf4jLoggingEventListener implements IHopLoggingEventListener {
+ /** MDC key holding the Hop channel id associated with the log record. */
+ public static final String MDC_CHANNEL_ID = "hop.logChannelId";
+
+ /** MDC key holding the Hop log level code associated with the log record. */
+ public static final String MDC_LOG_LEVEL = "hop.logLevel";
+
+ /** MDC key holding the (detailed) subject associated with the log record. */
+ public static final String MDC_SUBJECT = "hop.subject";
+
@VisibleForTesting
Logger pipelineLogger =
LoggerFactory.getLogger("org.apache.hop.pipeline.Pipeline");
@@ -56,27 +66,42 @@ public class Slf4jLoggingEventListener implements
IHopLoggingEventListener {
checkNotNull(messageObject, "Expected log message to be defined.");
if (messageObject instanceof LogMessage message) {
ILoggingObject loggingObject =
logObjProvider.apply(message.getLogChannelId());
-
- if (loggingObject == null) {
- // this can happen if logObject has been discarded while log events
are still in flight.
- logToLogger(
- hopLogger,
- message.getLevel(),
- message.getSubject() + " " + message.getMessage(),
- message.getThrowable());
- } else if (loggingObject.getObjectType() == PIPELINE
- || loggingObject.getObjectType() == TRANSFORM
- || loggingObject.getObjectType() == DATABASE) {
- logToLogger(pipelineLogger, message.getLevel(), loggingObject,
message);
- } else if (loggingObject.getObjectType() == WORKFLOW
- || loggingObject.getObjectType() == ACTION) {
- logToLogger(workflowLogger, message.getLevel(), loggingObject,
message);
- } else {
- logToLogger(hopLogger, message.getLevel(), loggingObject, message);
+ String subject = subjectOf(loggingObject, message);
+
+ // Publish the Hop context as MDC so custom log4j2 appenders (agent,
collector, Kafka, ...)
+ // can correlate records and preserve the 7 native Hop levels regardless
of how many SLF4J
+ // levels the backing provider exposes.
+ try (MDC.MDCCloseable channel = MDC.putCloseable(MDC_CHANNEL_ID,
message.getLogChannelId());
+ MDC.MDCCloseable level = MDC.putCloseable(MDC_LOG_LEVEL,
message.getLevel().getCode());
+ MDC.MDCCloseable ignored = MDC.putCloseable(MDC_SUBJECT, subject)) {
+ if (loggingObject == null) {
+ // this can happen if logObject has been discarded while log events
are still in flight.
+ logToLogger(
+ hopLogger,
+ message.getLevel(),
+ message.getSubject() + " " + message.getMessage(),
+ message.getThrowable());
+ } else if (loggingObject.getObjectType() == PIPELINE
+ || loggingObject.getObjectType() == TRANSFORM
+ || loggingObject.getObjectType() == DATABASE) {
+ logToLogger(pipelineLogger, message.getLevel(), loggingObject,
message);
+ } else if (loggingObject.getObjectType() == WORKFLOW
+ || loggingObject.getObjectType() == ACTION) {
+ logToLogger(workflowLogger, message.getLevel(), loggingObject,
message);
+ } else {
+ logToLogger(hopLogger, message.getLevel(), loggingObject, message);
+ }
}
}
}
+ private String subjectOf(ILoggingObject loggingObject, LogMessage message) {
+ if (loggingObject == null) {
+ return message.getSubject();
+ }
+ return getDetailedSubject(loggingObject);
+ }
+
private void logToLogger(
Logger logger, LogLevel logLevel, ILoggingObject loggingObject,
LogMessage message) {
logToLogger(
diff --git a/core/src/main/resources/log4j2.xml
b/core/src/main/resources/log4j2.xml
new file mode 100644
index 0000000000..4c7e8769c2
--- /dev/null
+++ b/core/src/main/resources/log4j2.xml
@@ -0,0 +1,49 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<!--
+ Licensed to the Apache Software Foundation (ASF) under one or more
+ contributor license agreements. See the NOTICE file distributed with
+ this work for additional information regarding copyright ownership.
+ The ASF licenses this file to You under the Apache License, Version 2.0
+ (the "License"); you may not use this file except in compliance with
+ the License. You may obtain a copy of the License at
+
+ http://www.apache.org/licenses/LICENSE-2.0
+
+ Unless required by applicable law or agreed to in writing, software
+ distributed under the License is distributed on an "AS IS" BASIS,
+ WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ See the License for the specific language governing permissions and
+ limitations under the License.
+ -->
+<!--
+ Default Log4j2 configuration for Apache Hop.
+
+ Hop's in-memory ``LoggingBuffer`` is always fed synchronously by
``LogChannel`` through
+ ``HopLogStore``; ``Slf4jLoggingEventListener`` forwards those events to
SLF4J. This file turns the
+ SLF4J output into something the operator can see once ``log4j-slf4j2-impl``
provides the binding.
+
+ Hop's own log lines already reach the console through Hop's console writer
+ (``ConsoleLoggingEventListener``), so the ``org.apache.hop`` logger is
deliberately left without an
+ appender and is not additive: the lines are available to Log4j2 but are not
printed a second time.
+ Third-party libraries (WARN and above) go to the console through the root
logger.
+
+ To route Hop's own lines through Log4j2 instead (JSON layout, Kafka,
OpenTelemetry, ...), supply a
+ custom ``log4j2.xml`` (``-Dlog4j2.configurationFile=...`` in
``HOP_OPTIONS``) that adds an
+ ``AppenderRef`` to the ``org.apache.hop`` logger, and set
``HOP_DISABLE_CONSOLE_LOGGING=Y`` to
+ switch off Hop's own console writer so the lines are not duplicated. The Hop
buffer is independent
+ of this file, so no Log4j2 configuration can empty the GUI or the hop-server
log views.
+ -->
+<Configuration status="WARN">
+ <Appenders>
+ <Console name="hopConsole" target="SYSTEM_OUT">
+ <PatternLayout pattern="%d{ISO8601} %-5p [%logger{40}] - %m%n"/>
+ </Console>
+ </Appenders>
+ <Loggers>
+ <!-- Hop's own lines: forwarded at every level, printed by Hop's console
writer, not by Log4j2. -->
+ <Logger name="org.apache.hop" level="trace" additivity="false"/>
+ <Root level="warn">
+ <AppenderRef ref="hopConsole"/>
+ </Root>
+ </Loggers>
+</Configuration>
diff --git
a/core/src/test/java/org/apache/hop/core/logging/DefaultLog4j2ConfigurationTest.java
b/core/src/test/java/org/apache/hop/core/logging/DefaultLog4j2ConfigurationTest.java
new file mode 100644
index 0000000000..629a26f5d5
--- /dev/null
+++
b/core/src/test/java/org/apache/hop/core/logging/DefaultLog4j2ConfigurationTest.java
@@ -0,0 +1,107 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache License, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+package org.apache.hop.core.logging;
+
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertFalse;
+import static org.junit.jupiter.api.Assertions.assertNotNull;
+import static org.junit.jupiter.api.Assertions.assertTrue;
+
+import java.io.InputStream;
+import java.util.List;
+import java.util.concurrent.CopyOnWriteArrayList;
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.core.LogEvent;
+import org.apache.logging.log4j.core.LoggerContext;
+import org.apache.logging.log4j.core.appender.AbstractAppender;
+import org.apache.logging.log4j.core.config.Configuration;
+import org.apache.logging.log4j.core.config.ConfigurationSource;
+import org.apache.logging.log4j.core.config.LoggerConfig;
+import org.apache.logging.log4j.core.config.xml.XmlConfiguration;
+import org.junit.jupiter.api.AfterEach;
+import org.junit.jupiter.api.BeforeEach;
+import org.junit.jupiter.api.Test;
+
+/**
+ * Guards the shape of the {@code log4j2.xml} shipped in hop-core: Hop's own
log lines are already
+ * printed by {@link ConsoleLoggingEventListener}, so the {@code
org.apache.hop} logger must not
+ * reach the root console appender or every line shows up twice. Third-party
warnings do go to the
+ * console through the root logger.
+ */
+class DefaultLog4j2ConfigurationTest {
+
+ private static final String HOP_LOGGER = "org.apache.hop";
+
+ private LoggerContext context;
+ private CapturingAppender rootAppender;
+
+ @BeforeEach
+ void loadShippedConfiguration() throws Exception {
+ InputStream stream =
getClass().getClassLoader().getResourceAsStream("log4j2.xml");
+ assertNotNull(stream, "hop-core must ship a default log4j2.xml");
+
+ context = new LoggerContext(getClass().getSimpleName());
+ Configuration configuration = new XmlConfiguration(context, new
ConfigurationSource(stream));
+ context.start(configuration);
+
+ rootAppender = new CapturingAppender();
+ rootAppender.start();
+ context.getConfiguration().getRootLogger().addAppender(rootAppender, null,
null);
+ context.updateLoggers();
+ }
+
+ @AfterEach
+ void stopContext() {
+ context.stop();
+ }
+
+ @Test
+ void hopLoggerIsNotAdditiveAndHasNoAppender() {
+ LoggerConfig hop = context.getConfiguration().getLoggerConfig(HOP_LOGGER);
+
+ assertEquals(HOP_LOGGER, hop.getName(), "an explicit org.apache.hop logger
must be declared");
+ assertFalse(hop.isAdditive(), "org.apache.hop must not bubble up to the
root console appender");
+ assertTrue(hop.getAppenders().isEmpty(), "org.apache.hop must not print by
default");
+ assertEquals(Level.TRACE, hop.getLevel(), "all forwarded Hop levels must
be available");
+ }
+
+ @Test
+ void hopLinesAreNotPrintedTwiceButThirdPartyWarningsReachTheConsole() {
+ context.getLogger("org.apache.hop.pipeline.Pipeline").info("a pipeline
line");
+ context.getLogger("org.apache.hop.workflow.Workflow").error("a workflow
error");
+ context.getLogger("org.eclipse.jetty.server.Server").warn("a third-party
warning");
+ context.getLogger("org.eclipse.jetty.server.Server").info("a third-party
info line");
+
+ assertEquals(1, rootAppender.events.size(), "only the third-party warning
reaches the console");
+ assertEquals(
+ "a third-party warning",
rootAppender.events.get(0).getMessage().getFormattedMessage());
+ }
+
+ private static final class CapturingAppender extends AbstractAppender {
+ private final List<LogEvent> events = new CopyOnWriteArrayList<>();
+
+ private CapturingAppender() {
+ super("capture", null, null, true, null);
+ }
+
+ @Override
+ public void append(LogEvent event) {
+ events.add(event.toImmutable());
+ }
+ }
+}
diff --git
a/core/src/test/java/org/apache/hop/core/logging/Slf4jLoggingEventListenerTest.java
b/core/src/test/java/org/apache/hop/core/logging/Slf4jLoggingEventListenerTest.java
index 2dc27cdf82..5a60ed70de 100644
---
a/core/src/test/java/org/apache/hop/core/logging/Slf4jLoggingEventListenerTest.java
+++
b/core/src/test/java/org/apache/hop/core/logging/Slf4jLoggingEventListenerTest.java
@@ -19,6 +19,10 @@ package org.apache.hop.core.logging;
import static org.apache.hop.core.logging.LogLevel.BASIC;
import static org.apache.hop.core.logging.LogLevel.ERROR;
+import static org.junit.jupiter.api.Assertions.assertEquals;
+import static org.junit.jupiter.api.Assertions.assertNull;
+import static org.mockito.Mockito.anyString;
+import static org.mockito.Mockito.doAnswer;
import static org.mockito.Mockito.lenient;
import static org.mockito.Mockito.verify;
import static org.mockito.Mockito.verifyNoInteractions;
@@ -31,6 +35,7 @@ import org.junit.jupiter.api.extension.ExtendWith;
import org.mockito.Mock;
import org.mockito.junit.jupiter.MockitoExtension;
import org.slf4j.Logger;
+import org.slf4j.MDC;
@ExtendWith(MockitoExtension.class)
class Slf4jLoggingEventListenerTest {
@@ -105,4 +110,41 @@ class Slf4jLoggingEventListenerTest {
verifyNoInteractions(hopLogger);
verifyNoInteractions(pipelineLogger);
}
+
+ @Test
+ void testAddLogEventPublishesHopContextToMdc() {
+ when(logObjProvider.apply(logChannelId)).thenReturn(loggingObject);
+ when(loggingObject.getObjectType()).thenReturn(LoggingObjectType.PIPELINE);
+ when(loggingObject.getFilename()).thenReturn("filename");
+ when(message.getLevel()).thenReturn(LogLevel.DEBUG);
+
+ assertNull(MDC.get(Slf4jLoggingEventListener.MDC_CHANNEL_ID), "MDC must
start clean");
+ assertNull(MDC.get(Slf4jLoggingEventListener.MDC_LOG_LEVEL), "MDC must
start clean");
+ assertNull(MDC.get(Slf4jLoggingEventListener.MDC_SUBJECT), "MDC must start
clean");
+
+ StringBuilder channelId = new StringBuilder();
+ StringBuilder logLevel = new StringBuilder();
+ StringBuilder subject = new StringBuilder();
+ doAnswer(
+ invocation -> {
+ // Capture the Hop context at the exact moment the record
reaches SLF4J.
+
channelId.append(MDC.get(Slf4jLoggingEventListener.MDC_CHANNEL_ID));
+
logLevel.append(MDC.get(Slf4jLoggingEventListener.MDC_LOG_LEVEL));
+ subject.append(MDC.get(Slf4jLoggingEventListener.MDC_SUBJECT));
+ return null;
+ })
+ .when(pipelineLogger)
+ .debug(anyString());
+
+ listener.eventAdded(logEvent);
+
+ assertEquals(logChannelId, channelId.toString());
+ assertEquals(LogLevel.DEBUG.getCode(), logLevel.toString());
+ assertEquals("filename", subject.toString());
+
+ // MDC is scoped to the dispatch and must not leak to the caller.
+ assertNull(MDC.get(Slf4jLoggingEventListener.MDC_CHANNEL_ID), "MDC must be
cleared after");
+ assertNull(MDC.get(Slf4jLoggingEventListener.MDC_LOG_LEVEL), "MDC must be
cleared after");
+ assertNull(MDC.get(Slf4jLoggingEventListener.MDC_SUBJECT), "MDC must be
cleared after");
+ }
}
diff --git
a/docs/hop-dev-manual/modules/ROOT/pages/architecture/logging-and-debugging.adoc
b/docs/hop-dev-manual/modules/ROOT/pages/architecture/logging-and-debugging.adoc
index 6ea4105a9d..1eb1a556bf 100644
---
a/docs/hop-dev-manual/modules/ROOT/pages/architecture/logging-and-debugging.adoc
+++
b/docs/hop-dev-manual/modules/ROOT/pages/architecture/logging-and-debugging.adoc
@@ -49,6 +49,43 @@ String logText =
The second argument clears the buffer as it is read.
This is the same path a `logBasic()` call from a
xref:manual::pipeline/transforms/userdefinedjavaclass.adoc[User Defined Java
Class] takes: the transform's own channel, the same store.
+=== SLF4J and the Log4j2 binding
+
+The log records hop writes to the store are mirrored to SLF4J by
`Slf4jLoggingEventListener` and, in turn, to Log4j2 through the
`log4j-slf4j2-impl` binding.
+The binding is a configuration concern, not a Hop one: bring your own
`log4j2.xml` (or `logback.xml`, or JUL) on the classpath and the stack emits
whatever the provider expects, without touching Hop code.
+A minimal `log4j2.xml` is shipped in `hop-core.jar`. Hop's own log lines are
already printed by Hop's console writer (`ConsoleLoggingEventListener`), so in
that default configuration the `org.apache.hop` logger has no appender and is
not additive: nothing is printed twice. Warnings and errors from third-party
libraries reach the console through the root logger.
+
+To route Hop's own lines through Log4j2 instead (a JSON layout, a Kafka
appender, an OpenTelemetry appender, ...):
+
+. Supply your own configuration, for example
`HOP_OPTIONS="-Dlog4j2.configurationFile=/path/to/log4j2.xml"`, and add an
`AppenderRef` to the `org.apache.hop` logger.
+. Set `HOP_DISABLE_CONSOLE_LOGGING=Y` to switch off Hop's own console writer,
otherwise every line is printed both by Hop and by Log4j2.
+
+`LogChannel` keeps feeding `HopLogStore` synchronously regardless of the
binding, so the GUI, the execution information location and the server keep
working even when the external logger is reconfigured, and no Log4j2
configuration can empty those log views.
+
+==== Hop context as MDC
+
+While dispatching a record, the listener publishes the Hop execution context
to the SLF4J MDC so custom appenders (agent, collector, Kafka, OpenTelemetry)
can correlate records without parsing the message text.
+
+[opts="header",cols="2,2,6"]
+|===
+|MDC key |Example |Meaning
+
+|`hop.logChannelId`
+|`04f3…`
+|The Hop channel id of the record, the same key used to look the line up in
`HopLogStore`.
+
+|`hop.logLevel`
+|`7`
+|The native Hop log level code of the record, preserving all seven Hop levels
even though SLF4J exposes five.
+
+|`hop.subject`
+|`/opt/import/pipeline.hpl`
+|The detailed subject of the log object, normally the pipeline or workflow
filename.
+|===
+
+The keys are also exposed as constants on `Slf4jLoggingEventListener`:
`MDC_CHANNEL_ID`, `MDC_LOG_LEVEL` and `MDC_SUBJECT`.
+MDC is scoped to a single dispatch and is cleared once the record is handed to
SLF4J, so it never leaks to another thread.
+
== Attaching a debugger
The launcher scripts in the distribution read `HOP_OPTIONS`, and each ships
with a commented-out JDWP line:
diff --git a/lib/pom.xml b/lib/pom.xml
index 2fb683fd58..5641177dce 100644
--- a/lib/pom.xml
+++ b/lib/pom.xml
@@ -831,9 +831,9 @@
<version>${slf4j.version}</version>
</dependency>
<dependency>
- <groupId>org.slf4j</groupId>
- <artifactId>slf4j-nop</artifactId>
- <version>${slf4j.version}</version>
+ <groupId>org.apache.logging.log4j</groupId>
+ <artifactId>log4j-slf4j2-impl</artifactId>
+ <version>${log4j.version}</version>
</dependency>
<dependency>
<groupId>org.yaml</groupId>