Skip to content

Commit 8fb7bd5

Browse files
tombentleytombentley
authored
Structured logging with optional JSON output (kroxylicious#3588)
Refactor all logging throughout Kroxylicious to use SLF4J's fluent API with structured key-value pairs, replacing string concatenation and placeholder-based logging. Changes include: - Configure Log4j2 with routing appender supporting both text and JSON formats via `KROXYLICIOUS_LOG_FORMAT` environment variable - Update pattern layout to display structured context with `%K{ctx}` - Refactor logging across all modules (runtime, filters, KMS providers, operator, app) to fluent style with addKeyValue() calls - Fix conditional logging to avoid unnecessary string construction - Standardise logger naming across modules - Update tests for structured logging assertions The new logging format supports both human-readable text output (default) and structured JSON output for log aggregation systems. Assisted-by: Claude Sonnet 4.5 <noreply@anthropic.com> Signed-off-by: Tom Bentley <tbentley@redhat.com>
1 parent 642768b commit 8fb7bd5

117 files changed

Lines changed: 1437 additions & 654 deletions

File tree

Some content is hidden

Large Commits have some content hidden by default. Use the searchbox below for content that may be hidden.

‎etc/checkstyle-custom_checks.xml‎

Lines changed: 14 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -95,6 +95,20 @@
9595
<property name="classes" value="java.lang.Boolean"/>
9696
</module>
9797

98+
<!-- Enforce structured logging with addKeyValue instead of parameterized logging -->
99+
<module name="RegexpSinglelineJava">
100+
<property name="format" value="(LOGGER|LOG)\.(info|debug|warn|error|trace)\([^)]*\{[^\}]*\}" />
101+
<property name="message" value="Use fluent API with addKeyValue() instead of parameterized logging with '{''}'. Example: LOGGER.atInfo().addKeyValue(&quot;key&quot;, value).log(&quot;message&quot;). [not required for tests]" />
102+
<property name="ignoreComments" value="true" />
103+
</module>
104+
105+
<!-- Standardize logger naming to LOGGER (not LOG) -->
106+
<module name="RegexpSinglelineJava">
107+
<property name="format" value="^\s*(private\s+)?static\s+final\s+Logger\s+LOG\s*=" />
108+
<property name="message" value="Logger should be named LOGGER (not LOG) for consistency. [not required for tests]" />
109+
<property name="ignoreComments" value="true" />
110+
</module>
111+
98112
<module name="IllegalImport">
99113
<!-- we shouldn't be relying on class shaded into TC for dependencies -->
100114
<property name="illegalPkgs" value="org.testcontainers.shaded"/>

‎etc/checkstyle-suppressions.xml‎

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -23,4 +23,26 @@
2323

2424
<suppress checks=".*"
2525
files="generated-sources/antlr4/.*"/>
26+
27+
<!-- Exclude structured logging checks from test code (src/test) -->
28+
<suppress checks="RegexpSinglelineJava"
29+
message="Use fluent API with addKeyValue"
30+
files=".*[/\\]src[/\\]test[/\\].*"/>
31+
<suppress checks="RegexpSinglelineJava"
32+
message="Logger should be named LOGGER"
33+
files=".*[/\\]src[/\\]test[/\\].*"/>
34+
35+
<!-- Exclude structured logging checks from test infrastructure modules (src/main) -->
36+
<suppress checks="RegexpSinglelineJava"
37+
message="Use fluent API with addKeyValue"
38+
files=".*systemtests[/\\]src[/\\]main[/\\].*"/>
39+
<suppress checks="RegexpSinglelineJava"
40+
message="Use fluent API with addKeyValue"
41+
files=".*test-support[/\\]src[/\\]main[/\\].*"/>
42+
<suppress checks="RegexpSinglelineJava"
43+
message="Logger should be named LOGGER"
44+
files=".*systemtests[/\\]src[/\\]main[/\\].*"/>
45+
<suppress checks="RegexpSinglelineJava"
46+
message="Logger should be named LOGGER"
47+
files=".*test-support[/\\]src[/\\]main[/\\].*"/>
2648
</suppressions>

‎kroxylicious-api/src/test/resources/log4j2-test.properties‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@ appender.null.name = NullAppender
1212
appender.console.type = Console
1313
appender.console.name = STDOUT
1414
appender.console.layout.type = PatternLayout
15-
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} <%t> %-5p %c:%L - %m%n
15+
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} <%t> %-5p %c:%L - %m%replace{ %K{ctx}}{' $'}{}%n
1616

1717
rootLogger.level = TRACE
1818
rootLogger.appenderRefs = null,console

‎kroxylicious-app/pom.xml‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -90,6 +90,11 @@
9090
<artifactId>log4j-slf4j2-impl</artifactId>
9191
<scope>runtime</scope>
9292
</dependency>
93+
<dependency>
94+
<groupId>org.apache.logging.log4j</groupId>
95+
<artifactId>log4j-layout-template-json</artifactId>
96+
<scope>runtime</scope>
97+
</dependency>
9398
<dependency>
9499
<groupId>com.lmax</groupId>
95100
<artifactId>disruptor</artifactId>

‎kroxylicious-app/src/main/java/io/kroxylicious/app/Kroxylicious.java‎

Lines changed: 12 additions & 9 deletions
Original file line numberDiff line numberDiff line change
@@ -80,7 +80,9 @@ public Integer call() throws Exception {
8080
}
8181
}
8282
catch (Exception e) {
83-
LOGGER.error("Exception on startup", e);
83+
LOGGER.atError()
84+
.setCause(e)
85+
.log("Exception on startup");
8486
throw e;
8587
}
8688

@@ -107,17 +109,18 @@ private static void printBannerAndVersions(Features features) {
107109
new BannerLogger().log();
108110
String[] versions = new VersionProvider().getVersion();
109111
for (String version : versions) {
110-
LOGGER.info("{}", version);
112+
LOGGER.atInfo()
113+
.addKeyValue("version", version)
114+
.log("Kroxylicious version");
111115
}
112116
features.warnings().forEach(LOGGER::warn);
113117
LOGGER.atInfo()
114-
.setMessage("Platform: Java {}({}) running on {} {}/{}")
115-
.addArgument(Runtime::version)
116-
.addArgument(() -> System.getProperty("java.vendor"))
117-
.addArgument(() -> System.getProperty("os.name"))
118-
.addArgument(() -> System.getProperty("os.version"))
119-
.addArgument(() -> System.getProperty("os.arch"))
120-
.log();
118+
.addKeyValue("javaVersion", Runtime::version)
119+
.addKeyValue("javaVendor", () -> System.getProperty("java.vendor"))
120+
.addKeyValue("osName", () -> System.getProperty("os.name"))
121+
.addKeyValue("osVersion", () -> System.getProperty("os.version"))
122+
.addKeyValue("osArch", () -> System.getProperty("os.arch"))
123+
.log("Java Platform");
121124
}
122125

123126
/**

‎kroxylicious-app/src/main/resources/log4j2.yaml‎

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -10,10 +10,26 @@ Configuration:
1010
name: Config
1111
Appenders:
1212
Console:
13+
# Pattern layout appender (text format - current default)
14+
- name: STDOUT-PATTERN
15+
target: SYSTEM_OUT
16+
PatternLayout:
17+
pattern: "%d{yyyy-MM-dd HH:mm:ss} %-5p <%t> %c{2.} - %m%replace{ %K{ctx}}{' $'}{}%n"
18+
# JSON layout appender (structured JSON output)
19+
- name: STDOUT-JSON
20+
target: SYSTEM_OUT
21+
JsonTemplateLayout:
22+
eventTemplateUri: "classpath:LogstashJsonEventLayoutV1.json"
23+
# Routing appender - selects between Pattern and JSON based on env var
24+
Routing:
1325
name: STDOUT
14-
target: SYSTEM_OUT
15-
PatternLayout:
16-
pattern: "%d{yyyy-MM-dd HH:mm:ss} %-5p <%t> %c{2.} - %m%n"
26+
Routes:
27+
pattern: "${env:KROXYLICIOUS_LOG_FORMAT:-text}"
28+
Route:
29+
- key: json
30+
ref: STDOUT-JSON
31+
- key: text
32+
ref: STDOUT-PATTERN
1733
Loggers:
1834
Root:
1935
level: "${env:KROXYLICIOUS_ROOT_LOG_LEVEL:-WARN}"

‎kroxylicious-app/src/test/resources/log4j2-test.properties‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,7 +12,7 @@ appender.null.name = NullAppender
1212
appender.console.type = Console
1313
appender.console.name = STDOUT
1414
appender.console.layout.type = PatternLayout
15-
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} <%t> %-5p %c:%L - %m%n
15+
appender.console.layout.pattern = %d{yyyy-MM-dd HH:mm:ss} <%t> %-5p %c:%L - %m%replace{ %K{ctx}}{' $'}{}%n
1616

1717
rootLogger.level = TRACE
1818
rootLogger.appenderRefs = null,console

‎kroxylicious-docs/docs/_modules/monitoring/proc-proxy-setting-log-levels.adoc‎

Lines changed: 52 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -33,3 +33,55 @@ KROXYLICIOUS_ROOT_LOG_LEVEL="DEBUG"
3333
----
3434
3535
NOTE: Setting the root log level to `DEBUG` or `TRACE` will produce very verbose logs.
36+
37+
[id='proc-proxy-json-log-format-{context}']
38+
== Switching to JSON log format
39+
40+
By default, Kroxylicious outputs logs in human-readable text format. You can switch to structured JSON output for integration with log aggregation systems.
41+
42+
.Procedure
43+
44+
. Set the `KROXYLICIOUS_LOG_FORMAT` environment variable:
45+
+
46+
[source,bash]
47+
----
48+
export KROXYLICIOUS_LOG_FORMAT=json
49+
----
50+
51+
. Start Kroxylicious:
52+
+
53+
[source,bash]
54+
----
55+
bin/kroxylicious-start.sh
56+
----
57+
58+
.Expected output (JSON format)
59+
60+
[source,json]
61+
----
62+
{
63+
"@version": "1",
64+
"@timestamp": "2026-04-01T14:25:30.123Z",
65+
"message": "Connection established",
66+
"logger_name": "io.kroxylicious.proxy.internal.FilterHandler",
67+
"thread_name": "kafka-request-handler-1",
68+
"level": "INFO",
69+
"level_value": 20000,
70+
"stack_trace": null,
71+
"sessionId": "abc-123",
72+
"clientId": "producer-1"
73+
}
74+
----
75+
76+
NOTE: Structured logging parameters like `sessionId` and `clientId` appear as top-level fields in JSON output.
77+
78+
.Switching back to text format
79+
80+
Remove the environment variable or set it to `text`:
81+
82+
[source,bash]
83+
----
84+
unset KROXYLICIOUS_LOG_FORMAT
85+
# or
86+
export KROXYLICIOUS_LOG_FORMAT=text
87+
----

‎kroxylicious-filters/kroxylicious-authorization/src/main/java/io/kroxylicious/filter/authorization/Authorization.java‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -31,7 +31,7 @@
3131
@Plugin(configType = AuthorizationConfig.class)
3232
public class Authorization implements FilterFactory<AuthorizationConfig, Authorizer> {
3333

34-
private static final Logger LOG = LoggerFactory.getLogger(Authorization.class);
34+
private static final Logger LOGGER = LoggerFactory.getLogger(Authorization.class);
3535

3636
private @Nullable AuthorizerService<?> authorizerService = null;
3737

@@ -40,7 +40,7 @@ public class Authorization implements FilterFactory<AuthorizationConfig, Authori
4040
public Authorizer initialize(FilterFactoryContext context,
4141
AuthorizationConfig authorizationConfig)
4242
throws PluginConfigurationException {
43-
LOG.warn("Authorization is an experimental Filter not yet recommended for production environments.");
43+
LOGGER.atWarn().log("Authorization is an experimental Filter not yet recommended for production environments");
4444
var configuration = Plugins.requireConfig(this, authorizationConfig);
4545
this.authorizerService = context.pluginInstance(AuthorizerService.class, configuration.authorizer());
4646
((AuthorizerService) authorizerService).initialize(configuration.authorizerConfig());

‎kroxylicious-filters/kroxylicious-authorization/src/main/java/io/kroxylicious/filter/authorization/AuthorizationFilter.java‎

Lines changed: 41 additions & 26 deletions
Original file line numberDiff line numberDiff line change
@@ -48,7 +48,7 @@
4848
*/
4949
public class AuthorizationFilter implements RequestFilter, ResponseFilter {
5050

51-
private static final Logger LOG = LoggerFactory.getLogger(AuthorizationFilter.class);
51+
private static final Logger LOGGER = LoggerFactory.getLogger(AuthorizationFilter.class);
5252

5353
static Map<ApiKeys, ApiEnforcement<?, ?>> apiEnforcement = new EnumMap<>(ApiKeys.class);
5454

@@ -173,18 +173,28 @@ CompletionStage<AuthorizeResult> authorization(FilterContext context, List<Actio
173173
actionsWithSupportedResourceTypes)
174174
.thenApply(authz -> {
175175
if (!authz.denied().isEmpty()) {
176-
LOG.info("DENY {} to {}", authz.denied(), authz.subject());
176+
LOGGER.atInfo()
177+
.addKeyValue("deniedActions", authz.denied())
178+
.addKeyValue("subject", authz.subject())
179+
.log("Authorization DENY decision");
177180
}
178181
else if (!authz.allowed().isEmpty()) {
179-
LOG.debug("ALLOW {} to {}", authz.allowed(), authz.subject());
182+
LOGGER.atDebug()
183+
.addKeyValue("allowedActions", authz.allowed())
184+
.addKeyValue("subject", authz.subject())
185+
.log("Authorization ALLOW decision");
180186
}
181187
else if (actions.isEmpty()) {
182-
LOG.debug("ALLOW {} no authorizable actions", authz.subject());
188+
LOGGER.atDebug()
189+
.addKeyValue("subject", authz.subject())
190+
.log("Authorization ALLOW decision with no authorizable actions");
183191
}
184192
if (!actionsWithUnsupportedResourceTypes.isEmpty()) {
185-
LOG.debug("ALLOW {} to {} (due to resource types not being supported by {})",
186-
actionsWithUnsupportedResourceTypes, authz.subject(),
187-
authorizer.getClass().getName());
193+
LOGGER.atDebug()
194+
.addKeyValue("unsupportedActions", actionsWithUnsupportedResourceTypes)
195+
.addKeyValue("subject", authz.subject())
196+
.addKeyValue("authorizerClass", authorizer.getClass().getName())
197+
.log("Authorization ALLOW decision for unsupported resource types");
188198
authz = new AuthorizeResult(authz.subject(),
189199
Stream.concat(authz.allowed().stream(), actionsWithUnsupportedResourceTypes.stream()).collect(Collectors.toUnmodifiableList()),
190200
authz.denied());
@@ -194,11 +204,15 @@ else if (actions.isEmpty()) {
194204
}
195205

196206
static void nonAuthorizableRequest(FilterContext context) {
197-
LOG.debug("NON-AUTHORIZABLE request from {}", context.authenticatedSubject());
207+
LOGGER.atDebug()
208+
.addKeyValue("subject", context.authenticatedSubject())
209+
.log("Non-authorizable request");
198210
}
199211

200212
static void nonAuthorizableResponse(FilterContext context) {
201-
LOG.debug("NON-AUTHORIZABLE response from {}", context.authenticatedSubject());
213+
LOGGER.atDebug()
214+
.addKeyValue("subject", context.authenticatedSubject())
215+
.log("Non-authorizable response");
202216
}
203217

204218
<R> void pushInflightState(RequestHeaderData header, InflightState<R> inflightState) {
@@ -263,22 +277,20 @@ public CompletionStage<RequestFilterResult> onRequest(ApiKeys apiKey,
263277

264278
private void logUnsupportedVersion(ApiKeys apiKey, RequestHeaderData header) {
265279
if (isApiSupported(apiKey)) {
266-
LOG.warn("Filter of type {} does not support {} API version {} used in request."
267-
+ " It supports version {} to {} (inclusive) of this API."
268-
+ " This error is due to a misconfigured, buggy, or possibly malicious client.",
269-
getClass().getName(),
270-
apiKey,
271-
header.requestApiVersion(),
272-
minSupportedApiVersion(apiKey),
273-
maxSupportedApiVersion(apiKey));
280+
LOGGER.atWarn()
281+
.addKeyValue("filterClass", getClass().getName())
282+
.addKeyValue("apiKey", apiKey)
283+
.addKeyValue("requestApiVersion", header.requestApiVersion())
284+
.addKeyValue("minSupportedVersion", minSupportedApiVersion(apiKey))
285+
.addKeyValue("maxSupportedVersion", maxSupportedApiVersion(apiKey))
286+
.log("Filter does not support API version used in request. This error is due to a misconfigured, buggy, or possibly malicious client");
274287
}
275288
else {
276-
LOG.warn("Filter of type {} does not support {} API version {} used in request."
277-
+ " It does not support version this API at all."
278-
+ " This error is due to a misconfigured, buggy, or possibly malicious client.",
279-
getClass().getName(),
280-
apiKey,
281-
header.requestApiVersion());
289+
LOGGER.atWarn()
290+
.addKeyValue("filterClass", getClass().getName())
291+
.addKeyValue("apiKey", apiKey)
292+
.addKeyValue("requestApiVersion", header.requestApiVersion())
293+
.log("Filter does not support this API at all. This error is due to a misconfigured, buggy, or possibly malicious client");
282294
}
283295
}
284296

@@ -329,9 +341,12 @@ private CompletionStage<ResponseFilterResult> checkCompat(ResponseHeaderData hea
329341
var minMetadataVersion = apiVersion.minVersion();
330342
var maxMetadataVersion = apiVersion.maxVersion();
331343
if (maxMetadataVersion < 4) {
332-
LOG.error("Filter {} requires the broker to support at least METADATA API version 4. "
333-
+ "The connected broker supports only {}-{}.",
334-
AuthorizationFilter.class.getName(), minMetadataVersion, maxMetadataVersion);
344+
LOGGER.atError()
345+
.addKeyValue("filterClass", AuthorizationFilter.class.getName())
346+
.addKeyValue("requiredMinVersion", (short) 4)
347+
.addKeyValue("brokerMinVersion", minMetadataVersion)
348+
.addKeyValue("brokerMaxVersion", maxMetadataVersion)
349+
.log("Filter requires broker to support at least METADATA API version 4. Connected broker does not meet requirements");
335350
return context.responseFilterResultBuilder().withCloseConnection().completed();
336351
}
337352
this.useMetadataVersion = (short) Math.min(ApiKeys.METADATA.latestVersion(), maxMetadataVersion);

0 commit comments

Comments
 (0)