From 939cb663d2ea3179d5016a63ec45a189eaa32b8f Mon Sep 17 00:00:00 2001 From: Ashish Vijaywargiya Date: Wed, 8 Jul 2026 23:16:52 +0530 Subject: [PATCH 1/5] Add opt-in ECS/JSON structured logging Adds a JSON appender to log4j2.xml (ECS schema via JsonTemplateLayout), writing runtime/logs/ofbiz-json.log alongside the existing text logs. Off by default; controlled by json.logs.enabled in debug.properties, so the default "./gradlew ofbiz" command picks it up with no extra flag. The JSON template location is a placeholder property (jsonLogTemplateUri / -Dofbiz.json.logs.template) so alternate schemas (Splunk, CloudWatch, etc.) can be added from a custom component without framework changes. ControlFilter now populates requestId/visitId/userLoginId into Log4j2's ThreadContext (MDC) so every log line for a given request or visit can be correlated. --- build.gradle | 16 ++++-- dependencies.gradle | 1 + framework/base/config/debug.properties | 7 ++- framework/base/config/log4j2.xml | 38 ++++++++++++++ .../base/config/templates/ecs-layout.json | 49 +++++++++++++++++++ .../ofbiz/webapp/control/ControlFilter.java | 27 +++++++++- .../webapp/control/ControlFilterTests.java | 4 ++ 7 files changed, 136 insertions(+), 6 deletions(-) create mode 100644 framework/base/config/templates/ecs-layout.json diff --git a/build.gradle b/build.gradle index 7c0d72f6b2c..a4b2baa087b 100644 --- a/build.gradle +++ b/build.gradle @@ -116,14 +116,22 @@ ext.os = System.getProperty('os.name').toLowerCase() ext.gradlew = os.contains('windows') ? 'gradlew.bat' : './gradlew' ext.pluginsDir = "${rootDir}/plugins" +// Global switch for structured (ECS JSON) logging - read from debug.properties so the default +// "./gradlew ofbiz" command reflects it directly, with no separate command-line flag to remember. +def debugProperties = new Properties() +file('framework/base/config/debug.properties').withInputStream { debugProperties.load(it) } +ext.jsonLogsEnabled = debugProperties.getProperty('json.logs.enabled', 'false').toBoolean() + application { mainClass = 'org.apache.ofbiz.base.start.Start' - applicationDefaultJvmArgs = project.hasProperty('jvmArgs') - ? jvmArgs.tokenize() - : ['-Xms128M','-Xmx1024M', + def defaultJvmArgs = ['-Xms128M','-Xmx1024M', '-Djdk.serialFilter=maxarray=100000;maxdepth=20;maxrefs=1000;maxbytes=500000', // OFBIZ-12592 and OFBIZ-12716 - '--add-opens=java.base/java.util=ALL-UNNAMED' // OFBIZ-12726 + '--add-opens=java.base/java.util=ALL-UNNAMED', // OFBIZ-12726 + "-Dofbiz.json.logs=${jsonLogsEnabled}" ] + applicationDefaultJvmArgs = project.hasProperty('jvmArgs') + ? jvmArgs.tokenize() + : defaultJvmArgs } distributions.main.contents.from(rootDir) { diff --git a/dependencies.gradle b/dependencies.gradle index ab8ef10dbaf..eb56fa75688 100644 --- a/dependencies.gradle +++ b/dependencies.gradle @@ -49,6 +49,7 @@ dependencies { implementation 'org.apache.httpcomponents:httpclient-cache:4.5.14' implementation 'org.apache.logging.log4j:log4j-api:2.25.4' // the API of log4j 2 implementation 'org.apache.logging.log4j:log4j-core:2.25.4' // Somehow needed by Buildbot to compile OFBizDynamicThresholdFilter.java + implementation 'org.apache.logging.log4j:log4j-layout-template-json:2.25.4' // JSON/ECS structured logging profile (log4j2-json.xml) implementation 'org.apache.poi:poi:5.5.1' implementation 'org.apache.pdfbox:pdfbox:3.0.7' implementation 'org.apache.pdfbox:pdfbox-io:3.0.7' diff --git a/framework/base/config/debug.properties b/framework/base/config/debug.properties index 412c424d138..7f9522f9d31 100644 --- a/framework/base/config/debug.properties +++ b/framework/base/config/debug.properties @@ -35,4 +35,9 @@ print.fatal=true ## File to display on webtools https://localhost:8443/webtools/control/LogView # log4j.appender.css.defaultFile=ofbiz.log ## RegExp use to filter file available on dropdown selection to diplay log on https://localhost:8443/webtools/control/FetchLog -# log4j.appender.css.fileNameRegExp=[(ofbiz)|(error)].* \ No newline at end of file +# log4j.appender.css.fileNameRegExp=[(ofbiz)|(error)].* + +## Global switch for structured (ECS JSON) logging - default false, zero extra cost when disabled. +## Set to true to have the default "./gradlew ofbiz" command write runtime/logs/ofbiz-json.log +## alongside the normal text logs; no extra command-line flag needed. +json.logs.enabled=false \ No newline at end of file diff --git a/framework/base/config/log4j2.xml b/framework/base/config/log4j2.xml index e0a44aeecf4..cba2171cfcb 100644 --- a/framework/base/config/log4j2.xml +++ b/framework/base/config/log4j2.xml @@ -29,6 +29,14 @@ under the License. false %date{DEFAULT} |%-20.20thread |%-30.30logger{1}${lineToken_${sys:ofbiz.env:-dev}}|%level{length=1}| %message%n ${includeLocation_${sys:ofbiz.env:-dev}} + + ${sys:ofbiz.json.logs.template:-classpath:templates/ecs-layout.json} @@ -74,10 +82,40 @@ under the License. + + + + diff --git a/framework/base/config/templates/ecs-layout.json b/framework/base/config/templates/ecs-layout.json new file mode 100644 index 00000000000..5a96edcb2ab --- /dev/null +++ b/framework/base/config/templates/ecs-layout.json @@ -0,0 +1,49 @@ +{ + "@timestamp": { + "$resolver": "timestamp", + "pattern": { + "format": "yyyy-MM-dd'T'HH:mm:ss.SSS'Z'", + "timeZone": "UTC" + } + }, + "ecs.version": "1.2.0", + "log.level": { + "$resolver": "level", + "field": "name" + }, + "message": { + "$resolver": "message", + "stringified": true + }, + "process.thread.name": { + "$resolver": "thread", + "field": "name" + }, + "log.logger": { + "$resolver": "logger", + "field": "name" + }, + "labels": { + "$resolver": "mdc", + "flatten": false, + "stringified": true + }, + "tags": { + "$resolver": "ndc" + }, + "error.type": { + "$resolver": "exception", + "field": "className" + }, + "error.message": { + "$resolver": "exception", + "field": "message" + }, + "error.stack_trace": { + "$resolver": "exception", + "field": "stackTrace", + "stackTrace": { + "stringified": true + } + } +} diff --git a/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java b/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java index acc7d3a7049..fee487be333 100644 --- a/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java +++ b/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java @@ -29,6 +29,8 @@ import java.util.List; import java.util.Map; import java.util.Set; +import java.util.UUID; +import java.util.concurrent.ThreadLocalRandom; import java.util.stream.Collectors; import org.apache.commons.lang.BooleanUtils; @@ -45,6 +47,7 @@ import org.apache.ofbiz.entity.GenericValue; import org.apache.ofbiz.security.SecuredFreemarker; import org.apache.ofbiz.security.SecuredUpload; +import org.apache.ofbiz.webapp.stats.VisitHandler; import jakarta.servlet.FilterChain; import jakarta.servlet.FilterConfig; @@ -95,6 +98,17 @@ public class ControlFilter extends HttpFilter { private int errorCode; /** The list of all path prefixes that are allowed. */ private Set allowedPaths; + + /** + * Generates a UUID-shaped log correlation id from {@link ThreadLocalRandom} instead of + * {@link UUID#randomUUID()}. Request ids only need to be unique for log correlation, not + * cryptographically unpredictable, and UUID.randomUUID() draws from a shared SecureRandom + * that can become a contention point across threads under high concurrency. + */ + private static String generateRequestId() { + ThreadLocalRandom random = ThreadLocalRandom.current(); + return new UUID(random.nextLong(), random.nextLong()).toString(); + } private static final List ALLOWEDTOKENS = getAllowedTokens(); @@ -265,12 +279,23 @@ public void doFilter(HttpServletRequest req, HttpServletResponse resp, FilterCha // Check if the requested URI is allowed. if (allowedPaths.stream().anyMatch(uri::startsWith)) { try { - // support OFBizDynamicThresholdFilter in log4j2.xml + // support OFBizDynamicThresholdFilter in log4j2.xml, and structured logging (log4j2-json.xml) ThreadContext.put("uri", uri); + ThreadContext.put("requestId", generateRequestId()); + String visitId = VisitHandler.getVisitId(session); + if (visitId != null) { + ThreadContext.put("visitId", visitId); + } + if (userLogin != null) { + ThreadContext.put("userLoginId", userLogin.getString("userLoginId")); + } chain.doFilter(req, resp); } finally { ThreadContext.remove("uri"); + ThreadContext.remove("requestId"); + ThreadContext.remove("visitId"); + ThreadContext.remove("userLoginId"); } } else { if (redirectPath == null) { diff --git a/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java b/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java index baae0b46368..0dd2db11cbe 100644 --- a/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java +++ b/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java @@ -30,6 +30,7 @@ import jakarta.servlet.FilterChain; import jakarta.servlet.FilterConfig; +import jakarta.servlet.ServletContext; import jakarta.servlet.http.HttpServletRequest; import jakarta.servlet.http.HttpServletResponse; import jakarta.servlet.http.HttpSession; @@ -42,6 +43,7 @@ public final class ControlFilterTests { private HttpServletResponse resp; private FilterChain next; private HttpSession session; + private ServletContext servletContext; @BeforeEach public void setUp() { @@ -49,6 +51,8 @@ public void setUp() { when(config.getInitParameter(anyString())).thenReturn(null); session = mock(HttpSession.class); when(session.getAttribute(anyString())).thenReturn(null); + servletContext = mock(ServletContext.class); + when(session.getServletContext()).thenReturn(servletContext); req = mock(HttpServletRequest.class); when(req.getSession()).thenReturn(session); when(req.getContextPath()).thenReturn(""); From d39e202f0c78a7e23669410b7846984162fd05ce Mon Sep 17 00:00:00 2001 From: Ashish Vijaywargiya Date: Thu, 9 Jul 2026 10:00:39 +0530 Subject: [PATCH 2/5] Move log correlation fields from ControlFilter to a CorrelationValve Moves requestId/visitId/userLoginId population out of ControlFilter and into a new engine-level Tomcat Valve (CorrelationValve, registered in CatalinaContainer alongside the existing valves), so it runs ahead of the servlet filter chain instead of inside framework webapp code. ControlFilter/ControlFilterTests are back to their original form. Also adds CorrelationFieldProvider, a ServiceLoader-based extension point: any component can contribute additional correlation fields (e.g. security group, permissions) by implementing the interface and registering it via META-INF/services, with no framework changes. All discovered providers are merged; a provider overwriting a core field is allowed but logged as a warning, and a failing provider is caught and skipped without affecting the request or other providers. --- .../catalina/container/CatalinaContainer.java | 3 + .../container/CorrelationFieldProvider.java | 48 +++++++ .../catalina/container/CorrelationValve.java | 130 ++++++++++++++++++ .../ofbiz/webapp/control/ControlFilter.java | 27 +--- .../webapp/control/ControlFilterTests.java | 4 - 5 files changed, 182 insertions(+), 30 deletions(-) create mode 100644 framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationFieldProvider.java create mode 100644 framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java diff --git a/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CatalinaContainer.java b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CatalinaContainer.java index fac58c164c8..84c8460381c 100644 --- a/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CatalinaContainer.java +++ b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CatalinaContainer.java @@ -376,6 +376,9 @@ private static List prepareTomcatEngineValves(Configuration.Property engi throws ContainerException { List engineValves = new ArrayList<>(); + // populates Log4j2 ThreadContext with requestId/visitId/userLoginId for log correlation + engineValves.add(new CorrelationValve()); + // configure the CrossSubdomainSessionValve if (ContainerConfig.getPropertyValue(engineConfig, "enable-cross-subdomain-sessions", false)) { engineValves.add(new CrossSubdomainSessionValve()); diff --git a/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationFieldProvider.java b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationFieldProvider.java new file mode 100644 index 00000000000..668b8275d69 --- /dev/null +++ b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationFieldProvider.java @@ -0,0 +1,48 @@ +/******************************************************************************* + * 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.ofbiz.catalina.container; + +import java.util.Map; + +import org.apache.catalina.connector.Request; +import org.apache.ofbiz.entity.GenericValue; + +/** + * Extension point for {@link CorrelationValve}: lets a component contribute additional + * key/value pairs to the per-request logging correlation context (Log4j2 {@code ThreadContext}), + * beyond the core {@code requestId}/{@code visitId}/{@code userLoginId} fields the Valve always + * sets. + * + *

Implementations are discovered via {@link java.util.ServiceLoader} - a component adds one by + * providing an implementation class plus a + * {@code META-INF/services/org.apache.ofbiz.catalina.container.CorrelationFieldProvider} file + * naming it, with no framework code changes required. All discovered providers are called for + * every request and their fields merged together. + */ +public interface CorrelationFieldProvider { + + /** + * Returns additional correlation fields for the current request, or {@code null}/empty if + * this provider has nothing to add (e.g. an anonymous request for a provider that only + * contributes fields for logged-in users). + * @param request the current request + * @param userLogin the logged-in user, or {@code null} if the request is anonymous + */ + Map getFields(Request request, GenericValue userLogin); +} diff --git a/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java new file mode 100644 index 00000000000..573ff31d95c --- /dev/null +++ b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java @@ -0,0 +1,130 @@ +/******************************************************************************* + * 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.ofbiz.catalina.container; + +import java.io.IOException; +import java.util.ArrayList; +import java.util.LinkedHashSet; +import java.util.List; +import java.util.Map; +import java.util.ServiceLoader; +import java.util.Set; +import java.util.UUID; +import java.util.concurrent.ThreadLocalRandom; + +import jakarta.servlet.ServletException; +import jakarta.servlet.http.HttpSession; + +import org.apache.catalina.connector.Request; +import org.apache.catalina.connector.Response; +import org.apache.catalina.valves.ValveBase; +import org.apache.logging.log4j.ThreadContext; +import org.apache.ofbiz.base.util.Debug; +import org.apache.ofbiz.entity.GenericValue; +import org.apache.ofbiz.webapp.stats.VisitHandler; + +/** + * Populates Log4j2's {@code ThreadContext} (MDC) with per-request logging correlation fields - + * {@code requestId}, {@code visitId}, {@code userLoginId} - so every log line produced while + * handling one HTTP request or one user visit can be tied together (see + * {@code framework/base/config/log4j2.xml}, the ECS JSON logging profile in particular). + * + *

Runs as an engine-level Valve, ahead of the servlet filter chain, so the fields are already + * in place before {@code ControlFilter} and every downstream filter/servlet run. + * + *

Additional fields can be contributed by any component without changing this class - see + * {@link CorrelationFieldProvider}. + */ +public class CorrelationValve extends ValveBase { + + private static final String MODULE = CorrelationValve.class.getName(); + private static final Set CORE_FIELDS = Set.of("requestId", "visitId", "userLoginId"); + private static final List PROVIDERS = loadProviders(); + + CorrelationValve() { + super(); + } + + private static List loadProviders() { + List providers = new ArrayList<>(); + ServiceLoader.load(CorrelationFieldProvider.class).forEach(providers::add); + return List.copyOf(providers); + } + + @Override + public void invoke(Request request, Response response) throws IOException, ServletException { + Set contextKeys = new LinkedHashSet<>(); + try { + putField(contextKeys, "requestId", generateRequestId()); + + HttpSession session = request.getSession(false); + String visitId = session != null ? VisitHandler.getVisitId(session) : null; + if (visitId != null) { + putField(contextKeys, "visitId", visitId); + } + GenericValue userLogin = session != null ? (GenericValue) session.getAttribute("userLogin") : null; + if (userLogin != null) { + putField(contextKeys, "userLoginId", userLogin.getString("userLoginId")); + } + + for (CorrelationFieldProvider provider : PROVIDERS) { + applyProvider(provider, request, userLogin, contextKeys); + } + + getNext().invoke(request, response); + } finally { + contextKeys.forEach(ThreadContext::remove); + } + } + + private void applyProvider(CorrelationFieldProvider provider, Request request, GenericValue userLogin, Set contextKeys) { + try { + Map fields = provider.getFields(request, userLogin); + if (fields == null) { + return; + } + for (Map.Entry field : fields.entrySet()) { + if (CORE_FIELDS.contains(field.getKey())) { + Debug.logWarning("CorrelationFieldProvider [" + provider.getClass().getName() + "] overwrote core " + + "correlation field '" + field.getKey() + "'", MODULE); + } + putField(contextKeys, field.getKey(), field.getValue()); + } + } catch (Exception e) { + Debug.logError(e, "CorrelationFieldProvider [" + provider.getClass().getName() + "] failed to provide " + + "correlation fields; skipping it for this request", MODULE); + } + } + + private void putField(Set contextKeys, String key, String value) { + ThreadContext.put(key, value); + contextKeys.add(key); + } + + /** + * Generates a UUID-shaped log correlation id from {@link ThreadLocalRandom} instead of + * {@link UUID#randomUUID()}. Request ids only need to be unique for log correlation, not + * cryptographically unpredictable, and UUID.randomUUID() draws from a shared SecureRandom + * that can become a contention point across threads under high concurrency. + */ + private static String generateRequestId() { + ThreadLocalRandom random = ThreadLocalRandom.current(); + return new UUID(random.nextLong(), random.nextLong()).toString(); + } +} diff --git a/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java b/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java index fee487be333..acc7d3a7049 100644 --- a/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java +++ b/framework/webapp/src/main/java/org/apache/ofbiz/webapp/control/ControlFilter.java @@ -29,8 +29,6 @@ import java.util.List; import java.util.Map; import java.util.Set; -import java.util.UUID; -import java.util.concurrent.ThreadLocalRandom; import java.util.stream.Collectors; import org.apache.commons.lang.BooleanUtils; @@ -47,7 +45,6 @@ import org.apache.ofbiz.entity.GenericValue; import org.apache.ofbiz.security.SecuredFreemarker; import org.apache.ofbiz.security.SecuredUpload; -import org.apache.ofbiz.webapp.stats.VisitHandler; import jakarta.servlet.FilterChain; import jakarta.servlet.FilterConfig; @@ -98,17 +95,6 @@ public class ControlFilter extends HttpFilter { private int errorCode; /** The list of all path prefixes that are allowed. */ private Set allowedPaths; - - /** - * Generates a UUID-shaped log correlation id from {@link ThreadLocalRandom} instead of - * {@link UUID#randomUUID()}. Request ids only need to be unique for log correlation, not - * cryptographically unpredictable, and UUID.randomUUID() draws from a shared SecureRandom - * that can become a contention point across threads under high concurrency. - */ - private static String generateRequestId() { - ThreadLocalRandom random = ThreadLocalRandom.current(); - return new UUID(random.nextLong(), random.nextLong()).toString(); - } private static final List ALLOWEDTOKENS = getAllowedTokens(); @@ -279,23 +265,12 @@ public void doFilter(HttpServletRequest req, HttpServletResponse resp, FilterCha // Check if the requested URI is allowed. if (allowedPaths.stream().anyMatch(uri::startsWith)) { try { - // support OFBizDynamicThresholdFilter in log4j2.xml, and structured logging (log4j2-json.xml) + // support OFBizDynamicThresholdFilter in log4j2.xml ThreadContext.put("uri", uri); - ThreadContext.put("requestId", generateRequestId()); - String visitId = VisitHandler.getVisitId(session); - if (visitId != null) { - ThreadContext.put("visitId", visitId); - } - if (userLogin != null) { - ThreadContext.put("userLoginId", userLogin.getString("userLoginId")); - } chain.doFilter(req, resp); } finally { ThreadContext.remove("uri"); - ThreadContext.remove("requestId"); - ThreadContext.remove("visitId"); - ThreadContext.remove("userLoginId"); } } else { if (redirectPath == null) { diff --git a/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java b/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java index 0dd2db11cbe..baae0b46368 100644 --- a/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java +++ b/framework/webapp/src/test/java/org/apache/ofbiz/webapp/control/ControlFilterTests.java @@ -30,7 +30,6 @@ import jakarta.servlet.FilterChain; import jakarta.servlet.FilterConfig; -import jakarta.servlet.ServletContext; import jakarta.servlet.http.HttpServletRequest; import jakarta.servlet.http.HttpServletResponse; import jakarta.servlet.http.HttpSession; @@ -43,7 +42,6 @@ public final class ControlFilterTests { private HttpServletResponse resp; private FilterChain next; private HttpSession session; - private ServletContext servletContext; @BeforeEach public void setUp() { @@ -51,8 +49,6 @@ public void setUp() { when(config.getInitParameter(anyString())).thenReturn(null); session = mock(HttpSession.class); when(session.getAttribute(anyString())).thenReturn(null); - servletContext = mock(ServletContext.class); - when(session.getServletContext()).thenReturn(servletContext); req = mock(HttpServletRequest.class); when(req.getSession()).thenReturn(session); when(req.getContextPath()).thenReturn(""); From 55d057130e173bbad5e442f51335e93df564ab45 Mon Sep 17 00:00:00 2001 From: Ashish Vijaywargiya Date: Thu, 9 Jul 2026 10:48:42 +0530 Subject: [PATCH 3/5] Drive the JSON log template choice from debug.properties too Extends the same config-file-driven pattern already used for json.logs.enabled: adds json.logs.template to debug.properties (default: the bundled ECS template) and has build.gradle read it and always emit -Dofbiz.json.logs.template accordingly. A custom component wanting Splunk/CloudWatch/etc. just points this at its own template's classpath location - no JVM flag, no JAVA_TOOL_OPTIONS, no -PjvmArgs override, and the default "./gradlew ofbiz" command picks it up directly. --- build.gradle | 8 +++++--- framework/base/config/debug.properties | 9 ++++++++- framework/base/config/log4j2.xml | 5 +++-- 3 files changed, 16 insertions(+), 6 deletions(-) diff --git a/build.gradle b/build.gradle index a4b2baa087b..c45f4134251 100644 --- a/build.gradle +++ b/build.gradle @@ -116,18 +116,20 @@ ext.os = System.getProperty('os.name').toLowerCase() ext.gradlew = os.contains('windows') ? 'gradlew.bat' : './gradlew' ext.pluginsDir = "${rootDir}/plugins" -// Global switch for structured (ECS JSON) logging - read from debug.properties so the default -// "./gradlew ofbiz" command reflects it directly, with no separate command-line flag to remember. +// Global switches for structured (ECS JSON) logging - read from debug.properties so the default +// "./gradlew ofbiz" command reflects them directly, with no separate command-line flag to remember. def debugProperties = new Properties() file('framework/base/config/debug.properties').withInputStream { debugProperties.load(it) } ext.jsonLogsEnabled = debugProperties.getProperty('json.logs.enabled', 'false').toBoolean() +ext.jsonLogsTemplate = debugProperties.getProperty('json.logs.template', 'classpath:templates/ecs-layout.json') application { mainClass = 'org.apache.ofbiz.base.start.Start' def defaultJvmArgs = ['-Xms128M','-Xmx1024M', '-Djdk.serialFilter=maxarray=100000;maxdepth=20;maxrefs=1000;maxbytes=500000', // OFBIZ-12592 and OFBIZ-12716 '--add-opens=java.base/java.util=ALL-UNNAMED', // OFBIZ-12726 - "-Dofbiz.json.logs=${jsonLogsEnabled}" + "-Dofbiz.json.logs=${jsonLogsEnabled}", + "-Dofbiz.json.logs.template=${jsonLogsTemplate}" ] applicationDefaultJvmArgs = project.hasProperty('jvmArgs') ? jvmArgs.tokenize() diff --git a/framework/base/config/debug.properties b/framework/base/config/debug.properties index 7f9522f9d31..e2a10130c86 100644 --- a/framework/base/config/debug.properties +++ b/framework/base/config/debug.properties @@ -40,4 +40,11 @@ print.fatal=true ## Global switch for structured (ECS JSON) logging - default false, zero extra cost when disabled. ## Set to true to have the default "./gradlew ofbiz" command write runtime/logs/ofbiz-json.log ## alongside the normal text logs; no extra command-line flag needed. -json.logs.enabled=false \ No newline at end of file +json.logs.enabled=false + +## Which JSON event template to use when structured logging is enabled above - a classpath +## location, defaulting to the bundled ECS template. Point this at a template shipped in your own +## custom component (e.g. classpath:templates/splunk-template.json) to switch formats without +## touching framework code or passing any JVM flag - picked up automatically by the default +## "./gradlew ofbiz" command, same as json.logs.enabled above. +json.logs.template=classpath:templates/ecs-layout.json \ No newline at end of file diff --git a/framework/base/config/log4j2.xml b/framework/base/config/log4j2.xml index cba2171cfcb..b114a8f9916 100644 --- a/framework/base/config/log4j2.xml +++ b/framework/base/config/log4j2.xml @@ -33,8 +33,9 @@ under the License. Placeholder for the JSON event template used by the opt-in structured logging appender below. Defaults to the bundled ECS template. To use a different schema (e.g. Splunk, CloudWatch), ship a template JSON file in your own component's config/ directory and - point this at it with -Dofbiz.json.logs.template=classpath:your-template.json - no - change to this file required. + point json.logs.template at it (classpath:your-template.json) in + framework/base/config/debug.properties - the default "./gradlew ofbiz" command picks + that up directly, no JVM flag or change to this file required. --> ${sys:ofbiz.json.logs.template:-classpath:templates/ecs-layout.json} From f068e5be4b9461e28b81bd630dd03e7a261226f3 Mon Sep 17 00:00:00 2001 From: Ashish Vijaywargiya Date: Thu, 9 Jul 2026 14:45:17 +0530 Subject: [PATCH 4/5] Adding more description above ecs-layout.json file. These notes will help user to maintain the json files properly and with distinct names. --- framework/base/config/debug.properties | 15 ++++++++++++--- 1 file changed, 12 insertions(+), 3 deletions(-) diff --git a/framework/base/config/debug.properties b/framework/base/config/debug.properties index e2a10130c86..52bbabcc781 100644 --- a/framework/base/config/debug.properties +++ b/framework/base/config/debug.properties @@ -44,7 +44,16 @@ json.logs.enabled=false ## Which JSON event template to use when structured logging is enabled above - a classpath ## location, defaulting to the bundled ECS template. Point this at a template shipped in your own -## custom component (e.g. classpath:templates/splunk-template.json) to switch formats without -## touching framework code or passing any JVM flag - picked up automatically by the default -## "./gradlew ofbiz" command, same as json.logs.enabled above. +## custom component to switch formats without touching framework code or passing any JVM flag - +## picked up automatically by the default "./gradlew ofbiz" command, same as json.logs.enabled +## above. +## +## To define your own template in a component under plugins/, e.g. plugins/your-component/: +## 1. plugins/your-component/ofbiz-component.xml needs +## 2. put the template at plugins/your-component/config/templates/your-template.json +## 3. point this property at it: json.logs.template=classpath:templates/your-template.json +## Note: classpath: resolution isn't scoped per-component - it finds the first matching resource +## across the entire combined classpath, so a filename collision with ecs-layout.json or another +## component's template is ambiguous/classpath-order-dependent. Use a distinctive name (e.g. +## templates/mycompany-splunk-template.json, not templates/splunk-template.json) to avoid that. json.logs.template=classpath:templates/ecs-layout.json \ No newline at end of file From 1e28d178156053b5734a9acf96f4b1d80528cf63 Mon Sep 17 00:00:00 2001 From: Ashish Vijaywargiya Date: Sat, 18 Jul 2026 18:44:00 +0530 Subject: [PATCH 5/5] Add opt-in userLoginId hashing/redaction for JSON log correlation 1) Added log.correlation.userLoginId.mode property (plain/hash/off) in debug.properties controlling whether userLoginId is written raw, as a PBKDF2 digest, or omitted entirely from the structured JSON log correlation context, since userLoginId is often PII such as an email address. 2) Added log.correlation.userLoginId.hash.pepper and log.correlation.userLoginId.hash.keyLengthBits properties, required only when mode=hash, providing the deployment-specific PBKDF2 salt and digest length used when hashing. 3) Updated CorrelationValve to resolve and validate these properties at construction time, failing fast with an IllegalStateException at startup if mode=hash is set without a pepper or with a non-positive key length, instead of failing later on the first login attempt. 4) Implemented hashUserLoginId() in CorrelationValve using PBKDF2WithHmacSHA256 with the same iteration count OFBiz already uses for password storage (security.properties password.encrypt.pbkdf2.iterations), producing a deterministic, non-reversible digest so cross-request correlation still works without exposing the raw userLoginId in logs. 5) Added CorrelationValveTests covering all three modes (plain/hash/off), digest determinism and length, distinct users producing distinct digests, invalid mode falling back to plain, and fail-fast construction errors for a missing pepper or an invalid key length. --- framework/base/config/debug.properties | 37 +++- .../catalina/container/CorrelationValve.java | 114 +++++++++- .../container/CorrelationValveTests.java | 204 ++++++++++++++++++ 3 files changed, 353 insertions(+), 2 deletions(-) create mode 100644 framework/catalina/src/test/java/org/apache/ofbiz/catalina/container/CorrelationValveTests.java diff --git a/framework/base/config/debug.properties b/framework/base/config/debug.properties index 52bbabcc781..88fb5f05549 100644 --- a/framework/base/config/debug.properties +++ b/framework/base/config/debug.properties @@ -56,4 +56,39 @@ json.logs.enabled=false ## across the entire combined classpath, so a filename collision with ecs-layout.json or another ## component's template is ambiguous/classpath-order-dependent. Use a distinctive name (e.g. ## templates/mycompany-splunk-template.json, not templates/splunk-template.json) to avoid that. -json.logs.template=classpath:templates/ecs-layout.json \ No newline at end of file +json.logs.template=classpath:templates/ecs-layout.json + +## How userLoginId is written into the log correlation context (see CorrelationValve in +## framework/catalina). userLoginId is frequently PII (often an email address), and today it is +## the only correlation field written into ofbiz-json.log's "labels" - the plain-text logs never +## included it, so this setting only affects structured JSON logging. +## plain (default) - current behavior, raw userLoginId. +## hash - deterministic PBKDF2 digest keyed with log.correlation.userLoginId.hash.pepper below; +## the same user always yields the same value, so correlation across requests still +## works, but the raw userLoginId isn't in the logs. Still deterministic/linkable, so +## this reduces exposure to a casual reader of the logs - it does not by itself make +## userLoginId stop being personal data under regulations like GDPR. +## off - userLoginId is left out of the correlation context entirely. Use this, not hash, when +## the actual requirement is "no PII in logs" - correlate on requestId/visitId instead. +## mode=hash REQUIRES the pepper property below to be set - OFBiz refuses to start with mode=hash +## and no pepper configured, rather than silently hashing without one. +log.correlation.userLoginId.mode=plain + +## Mandatory when log.correlation.userLoginId.mode=hash above, ignored otherwise. Deployment- +## specific secret used as the PBKDF2 salt when hashing userLoginId. Treat this with the same +## handling rigor as a database password: it's one shared secret for every user (a per-user random +## salt would make the same user hash differently on every request, defeating the correlation this +## field exists for), so if it leaks, every userLoginId ever written to the logs under this +## deployment becomes crackable offline in one shot. +log.correlation.userLoginId.hash.pepper= + +## Only used when log.correlation.userLoginId.mode=hash above, ignored otherwise. Length in bits of +## the derived digest written into the logs - shorter values produce a shorter userLoginId field in +## every log line. This does not weaken resistance against an attacker who holds the pepper (that's +## governed by the iteration count and pepper secrecy alone); it only raises the odds of two +## different users' digests colliding, which is negligible at the 128-bit default for any realistic +## deployment. If you need to trace a specific user's activity, correlate via visitId against the +## Visit entity instead of trying to reverse this digest. +## Must be a positive number when mode=hash - OFBiz refuses to start with mode=hash and a zero, +## negative, or otherwise invalid value here, rather than letting it fail on the first login attempt. +log.correlation.userLoginId.hash.keyLengthBits=128 \ No newline at end of file diff --git a/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java index 573ff31d95c..9044080dfb0 100644 --- a/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java +++ b/framework/catalina/src/main/java/org/apache/ofbiz/catalina/container/CorrelationValve.java @@ -19,7 +19,11 @@ package org.apache.ofbiz.catalina.container; import java.io.IOException; +import java.nio.charset.StandardCharsets; +import java.security.NoSuchAlgorithmException; +import java.security.spec.InvalidKeySpecException; import java.util.ArrayList; +import java.util.Base64; import java.util.LinkedHashSet; import java.util.List; import java.util.Map; @@ -28,6 +32,9 @@ import java.util.UUID; import java.util.concurrent.ThreadLocalRandom; +import javax.crypto.SecretKeyFactory; +import javax.crypto.spec.PBEKeySpec; + import jakarta.servlet.ServletException; import jakarta.servlet.http.HttpSession; @@ -36,6 +43,9 @@ import org.apache.catalina.valves.ValveBase; import org.apache.logging.log4j.ThreadContext; import org.apache.ofbiz.base.util.Debug; +import org.apache.ofbiz.base.util.GeneralRuntimeException; +import org.apache.ofbiz.base.util.UtilProperties; +import org.apache.ofbiz.base.util.UtilValidate; import org.apache.ofbiz.entity.GenericValue; import org.apache.ofbiz.webapp.stats.VisitHandler; @@ -56,9 +66,35 @@ public class CorrelationValve extends ValveBase { private static final String MODULE = CorrelationValve.class.getName(); private static final Set CORE_FIELDS = Set.of("requestId", "visitId", "userLoginId"); private static final List PROVIDERS = loadProviders(); + private static final String PBKDF2_HASH_TYPE = "PBKDF2WithHmacSHA256"; + // Same property HashCrypt's password hashing uses, so hash mode's cost factor stays in step + // with whatever this deployment already tuned for password storage. + private static final int PBKDF2_ITERATIONS = UtilProperties.getPropertyAsInteger("security.properties", + "password.encrypt.pbkdf2.iterations", 10000); + + /** + * Controls what {@code userLoginId} value (if any) is written into the log correlation + * context - see {@code log.correlation.userLoginId.mode} in {@code debug.properties}. + * {@code PLAIN} keeps today's behavior; {@code HASH} substitutes a deterministic PBKDF2 + * digest (same user, same digest, every request, but not reversible to the raw value without + * the pepper); {@code OFF} omits the field entirely. + */ + private enum UserLoginIdMode { PLAIN, HASH, OFF } + + private final UserLoginIdMode userLoginIdMode; + private final String userLoginIdHashPepper; + // Digest length, not the PRF named above - shrinks the userLoginId field written to every log + // line. Lowering this does not weaken resistance against an attacker who holds the pepper + // (that's governed by PBKDF2_ITERATIONS and pepper secrecy alone); it only raises the odds of + // two different users' digests colliding, negligible at 128 bits for any realistic userbase - + // and tracing a specific user is expected to go through visitId/Visit, not a reversed digest. + private final int userLoginIdHashKeyLengthBits; CorrelationValve() { super(); + this.userLoginIdMode = resolveUserLoginIdMode(); + this.userLoginIdHashPepper = resolveHashPepper(this.userLoginIdMode); + this.userLoginIdHashKeyLengthBits = resolveHashKeyLengthBits(this.userLoginIdMode); } private static List loadProviders() { @@ -67,6 +103,45 @@ private static List loadProviders() { return List.copyOf(providers); } + private static UserLoginIdMode resolveUserLoginIdMode() { + String mode = UtilProperties.getPropertyValue("debug", "log.correlation.userLoginId.mode", "plain"); + try { + return UserLoginIdMode.valueOf(mode.trim().toUpperCase()); + } catch (IllegalArgumentException e) { + Debug.logWarning("Invalid log.correlation.userLoginId.mode [" + mode + "]; defaulting to 'plain'", MODULE); + return UserLoginIdMode.PLAIN; + } + } + + private static String resolveHashPepper(UserLoginIdMode mode) { + String pepper = UtilProperties.getPropertyValue("debug", "log.correlation.userLoginId.hash.pepper", ""); + if (mode == UserLoginIdMode.HASH && UtilValidate.isEmpty(pepper)) { + // Fail fast: a blank pepper must never fall back to "unsalted" or "randomly salted + // per call" behind the operator's back - either would silently defeat what hash mode + // promises (see HashCrypt.pbkdf2HashCrypt - an empty salt draws a fresh random one on + // every call, which would make the same userLoginId hash differently every request). + throw new IllegalStateException("log.correlation.userLoginId.mode=hash requires " + + "log.correlation.userLoginId.hash.pepper to be set - refusing to start with an " + + "unconfigured pepper"); + } + return pepper; + } + + private static int resolveHashKeyLengthBits(UserLoginIdMode mode) { + int keyLengthBits = UtilProperties.getPropertyAsInteger("debug", + "log.correlation.userLoginId.hash.keyLengthBits", 128); + if (mode == UserLoginIdMode.HASH && keyLengthBits <= 0) { + // Fail fast at startup rather than at first login: PBEKeySpec rejects a non-positive + // key length with an unchecked IllegalArgumentException that hashUserLoginId's + // catch block doesn't handle, so a bad value would otherwise only surface as an + // uncaught error on the first authenticated request. + throw new IllegalStateException("log.correlation.userLoginId.mode=hash requires " + + "log.correlation.userLoginId.hash.keyLengthBits to be a positive number, got " + + keyLengthBits); + } + return keyLengthBits; + } + @Override public void invoke(Request request, Response response) throws IOException, ServletException { Set contextKeys = new LinkedHashSet<>(); @@ -80,7 +155,16 @@ public void invoke(Request request, Response response) throws IOException, Servl } GenericValue userLogin = session != null ? (GenericValue) session.getAttribute("userLogin") : null; if (userLogin != null) { - putField(contextKeys, "userLoginId", userLogin.getString("userLoginId")); + switch (userLoginIdMode) { + case HASH: + putField(contextKeys, "userLoginId", hashUserLoginId(userLogin.getString("userLoginId"))); + break; + case OFF: + break; + case PLAIN: + default: + putField(contextKeys, "userLoginId", userLogin.getString("userLoginId")); + } } for (CorrelationFieldProvider provider : PROVIDERS) { @@ -117,6 +201,34 @@ private void putField(Set contextKeys, String key, String value) { contextKeys.add(key); } + /** + * Hashes {@code userLoginId} with the same password-grade PBKDF2 algorithm/iteration count + * OFBiz already uses for password storage, so the same user always produces the same value + * (preserving cross-request correlation) while making offline guessing of low-entropy values + * like email addresses meaningfully more expensive than a fast digest would. + * + *

Deliberately does not call {@code HashCrypt.pbkdf2HashCrypt} - that method's + * output format is {@code {type}iterations$base64(salt)$base64(hash)}, i.e. it embeds the + * salt itself, base64-encoded (trivially reversible), directly in the returned string. That's + * correct for password storage, where each password's own random salt has to travel with its + * hash to be verifiable later. Here the "salt" is {@link #userLoginIdHashPepper}, one fixed + * deployment secret already available out-of-band from {@code debug.properties} - embedding + * it in every hashed log line would put the pepper in cleartext-recoverable form in the exact + * artifact this feature exists to protect, regardless of whether the pepper is ever otherwise + * "leaked". Deriving the key directly and returning only the digest avoids that. + */ + private String hashUserLoginId(String userLoginId) { + try { + PBEKeySpec spec = new PBEKeySpec(userLoginId.toCharArray(), + userLoginIdHashPepper.getBytes(StandardCharsets.UTF_8), PBKDF2_ITERATIONS, userLoginIdHashKeyLengthBits); + SecretKeyFactory factory = SecretKeyFactory.getInstance(PBKDF2_HASH_TYPE); + byte[] key = factory.generateSecret(spec).getEncoded(); + return "{PBKDF2-SHA256}" + Base64.getEncoder().encodeToString(key); + } catch (NoSuchAlgorithmException | InvalidKeySpecException e) { + throw new GeneralRuntimeException("Error hashing userLoginId for log correlation", e); + } + } + /** * Generates a UUID-shaped log correlation id from {@link ThreadLocalRandom} instead of * {@link UUID#randomUUID()}. Request ids only need to be unique for log correlation, not diff --git a/framework/catalina/src/test/java/org/apache/ofbiz/catalina/container/CorrelationValveTests.java b/framework/catalina/src/test/java/org/apache/ofbiz/catalina/container/CorrelationValveTests.java new file mode 100644 index 00000000000..8a6b1d49916 --- /dev/null +++ b/framework/catalina/src/test/java/org/apache/ofbiz/catalina/container/CorrelationValveTests.java @@ -0,0 +1,204 @@ +/******************************************************************************* + * 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.ofbiz.catalina.container; + +import static org.junit.jupiter.api.Assertions.assertEquals; +import static org.junit.jupiter.api.Assertions.assertFalse; +import static org.junit.jupiter.api.Assertions.assertNotEquals; +import static org.junit.jupiter.api.Assertions.assertNull; +import static org.junit.jupiter.api.Assertions.assertThrows; +import static org.junit.jupiter.api.Assertions.assertTrue; +import static org.mockito.ArgumentMatchers.anyString; +import static org.mockito.Mockito.doAnswer; +import static org.mockito.Mockito.mock; +import static org.mockito.Mockito.when; + +import jakarta.servlet.http.HttpSession; + +import org.apache.catalina.Valve; +import org.apache.catalina.connector.Request; +import org.apache.catalina.connector.Response; +import org.apache.logging.log4j.ThreadContext; +import org.apache.ofbiz.base.util.UtilProperties; +import org.apache.ofbiz.entity.GenericValue; +import org.junit.jupiter.api.AfterEach; +import org.junit.jupiter.api.BeforeEach; +import org.junit.jupiter.api.Test; + +public final class CorrelationValveTests { + + private static final String MODE_PROP = "log.correlation.userLoginId.mode"; + private static final String PEPPER_PROP = "log.correlation.userLoginId.hash.pepper"; + private static final String KEY_LENGTH_PROP = "log.correlation.userLoginId.hash.keyLengthBits"; + + private Request request; + private Response response; + private HttpSession session; + private GenericValue userLogin; + private Valve next; + + @BeforeEach + public void setUp() { + request = mock(Request.class); + response = mock(Response.class); + session = mock(HttpSession.class); + when(session.getAttribute(anyString())).thenReturn(null); + // VisitHandler.getVisit() falls through to creating a new Visit entity (needs a real + // Delegator) unless session already has a "visit" attribute - stub one so tests only + // exercise the userLoginId path, which is what they're actually about. + GenericValue visit = mock(GenericValue.class); + when(visit.getString("visitId")).thenReturn("10000"); + when(session.getAttribute("visit")).thenReturn(visit); + when(request.getSession(false)).thenReturn(session); + userLogin = mock(GenericValue.class); + next = mock(Valve.class); + resetProperties(); + } + + @AfterEach + public void tearDown() { + resetProperties(); + } + + private void resetProperties() { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "plain"); + UtilProperties.setPropertyValueInMemory("debug", PEPPER_PROP, ""); + UtilProperties.setPropertyValueInMemory("debug", KEY_LENGTH_PROP, "128"); + } + + private CorrelationValve newValve() { + CorrelationValve valve = new CorrelationValve(); + valve.setNext(next); + return valve; + } + + private String captureUserLoginIdSeenByNext() throws Exception { + String[] captured = new String[1]; + doAnswer(invocation -> { + captured[0] = ThreadContext.get("userLoginId"); + return null; + }).when(next).invoke(request, response); + newValve().invoke(request, response); + return captured[0]; + } + + @Test + public void plainModeWritesRawUserLoginId() throws Exception { + when(session.getAttribute("userLogin")).thenReturn(userLogin); + when(userLogin.getString("userLoginId")).thenReturn("jdoe@example.com"); + + assertEquals("jdoe@example.com", captureUserLoginIdSeenByNext()); + assertNull(ThreadContext.get("userLoginId"), "context must be cleared after the request"); + } + + @Test + public void hashModeWritesDeterministicDigestNotRawValue() throws Exception { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "hash"); + UtilProperties.setPropertyValueInMemory("debug", PEPPER_PROP, "test-pepper"); + when(session.getAttribute("userLogin")).thenReturn(userLogin); + when(userLogin.getString("userLoginId")).thenReturn("jdoe@example.com"); + + String firstDigest = captureUserLoginIdSeenByNext(); + String secondDigest = captureUserLoginIdSeenByNext(); + + assertNotEquals("jdoe@example.com", firstDigest); + assertEquals(firstDigest, secondDigest, "same user must hash the same way across requests"); + assertTrue(firstDigest.startsWith("{PBKDF2"), "digest should be self-describing, was: " + firstDigest); + } + + @Test + public void hashModeDefaultKeyLengthProducesThirtyNineCharDigest() throws Exception { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "hash"); + UtilProperties.setPropertyValueInMemory("debug", PEPPER_PROP, "test-pepper"); + when(session.getAttribute("userLogin")).thenReturn(userLogin); + when(userLogin.getString("userLoginId")).thenReturn("jdoe@example.com"); + + String digest = captureUserLoginIdSeenByNext(); + + // "{PBKDF2-SHA256}" (15 chars) + base64(16-byte/128-bit key, padded) (24 chars) = 39. + assertEquals(39, digest.length(), "digest was: " + digest); + } + + @Test + public void hashModeProducesDifferentDigestsForDifferentUsers() throws Exception { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "hash"); + UtilProperties.setPropertyValueInMemory("debug", PEPPER_PROP, "test-pepper"); + + when(session.getAttribute("userLogin")).thenReturn(userLogin); + when(userLogin.getString("userLoginId")).thenReturn("jdoe@example.com"); + String firstUserDigest = captureUserLoginIdSeenByNext(); + + GenericValue otherUserLogin = mock(GenericValue.class); + when(otherUserLogin.getString("userLoginId")).thenReturn("asmith@example.com"); + when(session.getAttribute("userLogin")).thenReturn(otherUserLogin); + String secondUserDigest = captureUserLoginIdSeenByNext(); + + assertNotEquals(firstUserDigest, secondUserDigest); + } + + @Test + public void hashModeWithoutPepperFailsFastAtConstruction() { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "hash"); + + assertThrows(IllegalStateException.class, CorrelationValve::new); + } + + @Test + public void hashModeWithZeroKeyLengthFailsFastAtConstruction() { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "hash"); + UtilProperties.setPropertyValueInMemory("debug", PEPPER_PROP, "test-pepper"); + UtilProperties.setPropertyValueInMemory("debug", KEY_LENGTH_PROP, "0"); + + assertThrows(IllegalStateException.class, CorrelationValve::new); + } + + @Test + public void hashModeWithNegativeKeyLengthFailsFastAtConstruction() { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "hash"); + UtilProperties.setPropertyValueInMemory("debug", PEPPER_PROP, "test-pepper"); + UtilProperties.setPropertyValueInMemory("debug", KEY_LENGTH_PROP, "-128"); + + assertThrows(IllegalStateException.class, CorrelationValve::new); + } + + @Test + public void offModeOmitsUserLoginIdEntirely() throws Exception { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "off"); + when(session.getAttribute("userLogin")).thenReturn(userLogin); + when(userLogin.getString("userLoginId")).thenReturn("jdoe@example.com"); + + boolean[] hadKey = new boolean[1]; + doAnswer(invocation -> { + hadKey[0] = ThreadContext.containsKey("userLoginId"); + return null; + }).when(next).invoke(request, response); + newValve().invoke(request, response); + + assertFalse(hadKey[0]); + } + + @Test + public void invalidModeFallsBackToPlain() throws Exception { + UtilProperties.setPropertyValueInMemory("debug", MODE_PROP, "bogus"); + when(session.getAttribute("userLogin")).thenReturn(userLogin); + when(userLogin.getString("userLoginId")).thenReturn("jdoe@example.com"); + + assertEquals("jdoe@example.com", captureUserLoginIdSeenByNext()); + } +}