From 3c76ed9ad592b86599861917b3123b0621b650a2 Mon Sep 17 00:00:00 2001 From: seonwoo_jung <79202163+seonwooj0810@users.noreply.github.com> Date: Tue, 4 Aug 2026 10:14:28 +0900 Subject: [PATCH] Warn at config time when AsyncAppender suppresses caller data for a downstream layout MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit When AsyncAppender has includeCallerData=false (the default), caller data is extracted from the worker thread rather than the logging-call-site thread, yielding bogus '?' values for %C/%M/%L in any downstream layout. Detect this contradiction at dependency-analysis time via two new analysers: - CallerContradictionAnalyser (AppenderModel): records AsyncAppender instances with includeCallerData=false (or absent, the default) along with the appender names they reference, and records appenders whose layout pattern uses a caller-data converter (%C/%M/%L/%F/%l/%class/%method/%line/%file/%caller). - CallerContradictionWarnAnalyser (ConfigurationModel): in postHandle() — after all AppenderModels have been visited — performs the bi-directional check and emits a WARN for each async→child pair that forms a contradiction. Both analysers are registered in ModelClassToModelHandlerLinker. Three test cases cover: warning issued, no warning when includeCallerData=true, no warning when pattern has no caller-data converters. Fixes #1059 Signed-off-by: seonwoo_jung <79202163+seonwooj0810@users.noreply.github.com> --- .../joran/ModelClassToModelHandlerLinker.java | 5 + .../CallerContradictionAnalyser.java | 159 ++++++++++++++++++ .../CallerContradictionWarnAnalyser.java | 83 +++++++++ .../asyncNoCallerDataWrapsCallerPattern.xml | 38 +++++ .../asyncNoCallerDataWrapsNoCallerPattern.xml | 38 +++++ .../asyncWithCallerDataWrapsCallerPattern.xml | 39 +++++ .../CallerContradictionAnalyserTest.java | 59 +++++++ 7 files changed, 421 insertions(+) create mode 100644 logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionAnalyser.java create mode 100644 logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionWarnAnalyser.java create mode 100644 logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsCallerPattern.xml create mode 100644 logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsNoCallerPattern.xml create mode 100644 logback-classic/src/test/input/joran/callerContradiction/asyncWithCallerDataWrapsCallerPattern.xml create mode 100644 logback-classic/src/test/java/ch/qos/logback/classic/joran/CallerContradictionAnalyserTest.java diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/joran/ModelClassToModelHandlerLinker.java b/logback-classic/src/main/java/ch/qos/logback/classic/joran/ModelClassToModelHandlerLinker.java index e437c2da09..7d0586c8ac 100644 --- a/logback-classic/src/main/java/ch/qos/logback/classic/joran/ModelClassToModelHandlerLinker.java +++ b/logback-classic/src/main/java/ch/qos/logback/classic/joran/ModelClassToModelHandlerLinker.java @@ -72,6 +72,11 @@ public void link(DefaultProcessor defaultProcessor) { defaultProcessor.addAnalyser(AppenderModel.class, () -> new AppenderDeclarationAnalyser(context)); + defaultProcessor.addAnalyser(AppenderModel.class, + () -> new CallerContradictionAnalyser(context)); + defaultProcessor.addAnalyser(ConfigurationModel.class, + () -> new CallerContradictionWarnAnalyser(context)); + sealModelFilters(defaultProcessor); } diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionAnalyser.java b/logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionAnalyser.java new file mode 100644 index 0000000000..fbbfb23722 --- /dev/null +++ b/logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionAnalyser.java @@ -0,0 +1,159 @@ +/* + * Logback: the reliable, generic, fast and flexible logging framework. + * Copyright (C) 1999-2026, QOS.ch. All rights reserved. + * + * This program and the accompanying materials are dual-licensed under + * either the terms of the Eclipse Public License v2.0 as published by + * the Eclipse Foundation + * + * or (per the licensee's choosing) + * + * under the terms of the GNU Lesser General Public License version 2.1 + * as published by the Free Software Foundation. + */ +package ch.qos.logback.classic.model.processor; + +import java.util.LinkedHashMap; +import java.util.LinkedHashSet; +import java.util.Map; +import java.util.Set; +import java.util.regex.Pattern; + +import ch.qos.logback.classic.AsyncAppender; +import ch.qos.logback.core.Context; +import ch.qos.logback.core.model.AppenderModel; +import ch.qos.logback.core.model.AppenderRefModel; +import ch.qos.logback.core.model.ImplicitModel; +import ch.qos.logback.core.model.Model; +import ch.qos.logback.core.model.processor.ModelHandlerBase; +import ch.qos.logback.core.model.processor.ModelHandlerException; +import ch.qos.logback.core.model.processor.ModelInterpretationContext; +import ch.qos.logback.core.model.processor.PhaseIndicator; +import ch.qos.logback.core.model.processor.ProcessingPhase; + +/** + * Dependency-analysis pass over every {@link AppenderModel}: records which + * appenders suppress caller data (AsyncAppender with + * {@code includeCallerData=false} / default) and which appenders need it + * (pattern contains a caller-data converter). + * + *

The contradiction check is performed by {@link CallerContradictionWarnAnalyser} + * in its {@code postHandle()} on the enclosing {@code ConfigurationModel}, after + * all appender models have been visited.

+ * + * @since 1.6.2 + * @see CallerContradictionWarnAnalyser + */ +@PhaseIndicator(phase = ProcessingPhase.DEPENDENCY_ANALYSIS) +public class CallerContradictionAnalyser extends ModelHandlerBase { + + static final String ASYNC_SUPPRESSES_MAP_KEY = "ASYNC_SUPPRESSES_CALLER_DATA_MAP"; + static final String NEEDS_CALLER_DATA_SET_KEY = "NEEDS_CALLER_DATA_SET"; + + /** + * Matches caller-data converter words in a logback pattern string. + * Single-char forms (%C class, %M method, %L line, %F file, %l location) are + * case-sensitive; multi-char aliases (class, method, line, file, caller) are + * case-insensitive and unique enough to match without case sensitivity issues. + * Negative lookahead prevents partial matches like %Msg being flagged. + */ + static final Pattern CALLER_PATTERN = Pattern.compile( + "%([CMLFl]|caller|class|method|line|file)(?![a-zA-Z])"); + + public CallerContradictionAnalyser(Context context) { + super(context); + } + + @Override + protected Class getSupportedModelClass() { + return AppenderModel.class; + } + + @Override + public void handle(ModelInterpretationContext mic, Model model) throws ModelHandlerException { + AppenderModel appenderModel = (AppenderModel) model; + + String originalClassName = appenderModel.getClassName(); + String className = mic.getImport(originalClassName); + String appenderName = mic.subst(appenderModel.getName()); + + if (AsyncAppender.class.getName().equals(className)) { + if (isIncludeCallerDataAbsentOrFalse(mic, appenderModel)) { + Set refs = collectAppenderRefNames(mic, appenderModel); + getAsyncSuppressesMap(mic).put(appenderName, refs); + } + } + + if (hasCallerDataConverters(appenderModel)) { + getNeedsCallerDataSet(mic).add(appenderName); + } + } + + private boolean isIncludeCallerDataAbsentOrFalse(ModelInterpretationContext mic, + AppenderModel appenderModel) { + for (Model child : appenderModel.getSubModels()) { + if (child instanceof ImplicitModel + && "includeCallerData".equalsIgnoreCase(child.getTag())) { + String value = mic.subst(((ImplicitModel) child).getBodyText()); + return !"true".equalsIgnoreCase(value); + } + } + return true; // absent → default false in AsyncAppender + } + + private Set collectAppenderRefNames(ModelInterpretationContext mic, + AppenderModel appenderModel) { + Set refs = new LinkedHashSet<>(); + for (Model child : appenderModel.getSubModels()) { + if (child instanceof AppenderRefModel) { + String ref = mic.subst(((AppenderRefModel) child).getRef()); + refs.add(ref); + } + } + return refs; + } + + private boolean hasCallerDataConverters(AppenderModel appenderModel) { + return collectPatternBodyTexts(appenderModel).stream() + .anyMatch(p -> CALLER_PATTERN.matcher(p).find()); + } + + private Set collectPatternBodyTexts(Model model) { + Set patterns = new LinkedHashSet<>(); + collectPatternBodyTextsRecursive(model, patterns); + return patterns; + } + + private void collectPatternBodyTextsRecursive(Model model, Set out) { + if (model instanceof ImplicitModel && "pattern".equalsIgnoreCase(model.getTag())) { + String body = model.getBodyText(); + if (body != null) { + out.add(body); + } + } + for (Model child : model.getSubModels()) { + collectPatternBodyTextsRecursive(child, out); + } + } + + @SuppressWarnings("unchecked") + static Map> getAsyncSuppressesMap(ModelInterpretationContext mic) { + Map> map = + (Map>) mic.getObjectMap().get(ASYNC_SUPPRESSES_MAP_KEY); + if (map == null) { + map = new LinkedHashMap<>(); + mic.getObjectMap().put(ASYNC_SUPPRESSES_MAP_KEY, map); + } + return map; + } + + @SuppressWarnings("unchecked") + static Set getNeedsCallerDataSet(ModelInterpretationContext mic) { + Set set = (Set) mic.getObjectMap().get(NEEDS_CALLER_DATA_SET_KEY); + if (set == null) { + set = new LinkedHashSet<>(); + mic.getObjectMap().put(NEEDS_CALLER_DATA_SET_KEY, set); + } + return set; + } +} diff --git a/logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionWarnAnalyser.java b/logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionWarnAnalyser.java new file mode 100644 index 0000000000..33572b31eb --- /dev/null +++ b/logback-classic/src/main/java/ch/qos/logback/classic/model/processor/CallerContradictionWarnAnalyser.java @@ -0,0 +1,83 @@ +/* + * Logback: the reliable, generic, fast and flexible logging framework. + * Copyright (C) 1999-2026, QOS.ch. All rights reserved. + * + * This program and the accompanying materials are dual-licensed under + * either the terms of the Eclipse Public License v2.0 as published by + * the Eclipse Foundation + * + * or (per the licensee's choosing) + * + * under the terms of the GNU Lesser General Public License version 2.1 + * as published by the Free Software Foundation. + */ +package ch.qos.logback.classic.model.processor; + +import java.util.Map; +import java.util.Set; + +import ch.qos.logback.classic.model.ConfigurationModel; +import ch.qos.logback.core.Context; +import ch.qos.logback.core.model.Model; +import ch.qos.logback.core.model.processor.ModelHandlerBase; +import ch.qos.logback.core.model.processor.ModelHandlerException; +import ch.qos.logback.core.model.processor.ModelInterpretationContext; +import ch.qos.logback.core.model.processor.PhaseIndicator; +import ch.qos.logback.core.model.processor.ProcessingPhase; + +/** + * Dependency-analysis handler for {@link ConfigurationModel} that warns when a + * configuration contains an {@code AsyncAppender} with + * {@code includeCallerData=false} (the default) that wraps an appender whose + * pattern uses a caller-data converter ({@code %C}, {@code %M}, {@code %L}, + * {@code %F}, {@code %l}, {@code %class}, {@code %method}, {@code %line}, + * {@code %file}, {@code %caller}). + * + *

All work is done in {@link #postHandle} so that it runs after every child + * {@link ch.qos.logback.core.model.AppenderModel} has been visited by + * {@link CallerContradictionAnalyser}, regardless of declaration order.

+ * + * @since 1.6.2 + * @see CallerContradictionAnalyser + */ +@PhaseIndicator(phase = ProcessingPhase.DEPENDENCY_ANALYSIS) +public class CallerContradictionWarnAnalyser extends ModelHandlerBase { + + static final String CONTRADICTION_MESSAGE = + "AsyncAppender [%s] has includeCallerData=false (the default) but wraps appender [%s] " + + "whose pattern uses a caller-data converter (%%C/%%M/%%L/%%F/%%l/%%class/%%method/%%line/%%file/%%caller). " + + "Caller data will not be available for that appender. " + + "Consider setting true on AsyncAppender [%s]."; + + public CallerContradictionWarnAnalyser(Context context) { + super(context); + } + + @Override + protected Class getSupportedModelClass() { + return ConfigurationModel.class; + } + + @Override + public void handle(ModelInterpretationContext mic, Model model) throws ModelHandlerException { + // no-op; all work is in postHandle after children are visited + } + + @Override + public void postHandle(ModelInterpretationContext mic, Model model) throws ModelHandlerException { + Map> asyncSuppressesMap = + CallerContradictionAnalyser.getAsyncSuppressesMap(mic); + Set needsCallerDataSet = + CallerContradictionAnalyser.getNeedsCallerDataSet(mic); + + for (Map.Entry> entry : asyncSuppressesMap.entrySet()) { + String asyncName = entry.getKey(); + for (String referencedName : entry.getValue()) { + if (needsCallerDataSet.contains(referencedName)) { + addWarn(String.format(CONTRADICTION_MESSAGE, + asyncName, referencedName, asyncName)); + } + } + } + } +} diff --git a/logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsCallerPattern.xml b/logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsCallerPattern.xml new file mode 100644 index 0000000000..0239d8b49e --- /dev/null +++ b/logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsCallerPattern.xml @@ -0,0 +1,38 @@ + + + + + + + + + + + + + %d{HH:mm:ss.SSS} [%thread] %-5level %C.%M:%L - %msg%n + + + + + + + + + + + + diff --git a/logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsNoCallerPattern.xml b/logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsNoCallerPattern.xml new file mode 100644 index 0000000000..2b834cbb9f --- /dev/null +++ b/logback-classic/src/test/input/joran/callerContradiction/asyncNoCallerDataWrapsNoCallerPattern.xml @@ -0,0 +1,38 @@ + + + + + + + + + + + + + %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n + + + + + + + + + + + + diff --git a/logback-classic/src/test/input/joran/callerContradiction/asyncWithCallerDataWrapsCallerPattern.xml b/logback-classic/src/test/input/joran/callerContradiction/asyncWithCallerDataWrapsCallerPattern.xml new file mode 100644 index 0000000000..d713c0097e --- /dev/null +++ b/logback-classic/src/test/input/joran/callerContradiction/asyncWithCallerDataWrapsCallerPattern.xml @@ -0,0 +1,39 @@ + + + + + + + + + + + + + %d{HH:mm:ss.SSS} [%thread] %-5level %M - %msg%n + + + + + true + + + + + + + + diff --git a/logback-classic/src/test/java/ch/qos/logback/classic/joran/CallerContradictionAnalyserTest.java b/logback-classic/src/test/java/ch/qos/logback/classic/joran/CallerContradictionAnalyserTest.java new file mode 100644 index 0000000000..c4a6ecd7a0 --- /dev/null +++ b/logback-classic/src/test/java/ch/qos/logback/classic/joran/CallerContradictionAnalyserTest.java @@ -0,0 +1,59 @@ +/* + * Logback: the reliable, generic, fast and flexible logging framework. + * Copyright (C) 1999-2026, QOS.ch. All rights reserved. + * + * This program and the accompanying materials are dual-licensed under + * either the terms of the Eclipse Public License v2.0 as published by + * the Eclipse Foundation + * + * or (per the licensee's choosing) + * + * under the terms of the GNU Lesser General Public License version 2.1 + * as published by the Free Software Foundation. + */ +package ch.qos.logback.classic.joran; + +import ch.qos.logback.classic.ClassicTestConstants; +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.util.LogbackMDCAdapter; +import ch.qos.logback.core.joran.spi.JoranException; +import ch.qos.logback.core.status.Status; +import ch.qos.logback.core.status.testUtil.StatusChecker; +import org.junit.jupiter.api.Test; +import org.slf4j.spi.MDCAdapter; + +public class CallerContradictionAnalyserTest { + + private static final String INPUT_DIR = + ClassicTestConstants.JORAN_INPUT_PREFIX + "callerContradiction/"; + + LoggerContext loggerContext = new LoggerContext(); + MDCAdapter mdcAdapter = new LogbackMDCAdapter(); + StatusChecker checker = new StatusChecker(loggerContext); + + void configure(String file) throws JoranException { + loggerContext.setMDCAdapter(mdcAdapter); + JoranConfigurator jc = new JoranConfigurator(); + jc.setContext(loggerContext); + jc.doConfigure(file); + } + + @Test + public void asyncDefaultIncludeCallerDataWrapsCallerPatternTriggersWarn() throws JoranException { + configure(INPUT_DIR + "asyncNoCallerDataWrapsCallerPattern.xml"); + checker.assertContainsMatch(Status.WARN, + ".*AsyncAppender \\[ASYNC\\] has includeCallerData=false.*CONSOLE.*"); + } + + @Test + public void asyncIncludeCallerDataTrueWrapsCallerPatternNoWarn() throws JoranException { + configure(INPUT_DIR + "asyncWithCallerDataWrapsCallerPattern.xml"); + checker.assertMatchCount(".*includeCallerData=false.*", 0); + } + + @Test + public void asyncDefaultIncludeCallerDataWrapsNonCallerPatternNoWarn() throws JoranException { + configure(INPUT_DIR + "asyncNoCallerDataWrapsNoCallerPattern.xml"); + checker.assertMatchCount(".*includeCallerData=false.*", 0); + } +}