Skip to content

fix(logging): collapse framework stack frames via log4j2 %xEx filters - #36516

Merged
wezell merged 3 commits into
mainfrom
issue-36515-log4j2-stack-frame-filters
Jul 10, 2026
Merged

fix(logging): collapse framework stack frames via log4j2 %xEx filters#36516
wezell merged 3 commits into
mainfrom
issue-36515-log4j2-stack-frame-filters

Conversation

@wezell

@wezell wezell commented Jul 10, 2026

Copy link
Copy Markdown
Member

Proposed Changes

  • Add a stack.filter property listing framework/plumbing packages to both runtime log4j2 configs (webapp default and Docker OVERRIDE, which is what production containers use).
  • Apply %xEx{filters(${stack.filter})} to the Console pattern in both configs and to MESSAGE_PATTERN (used by the dotcms.log RollingFile appender) in the Docker override.

Frames from org.apache.catalina/coyote/tomcat, javax.servlet, org.tuckey, io.vavr, graphql.execution/kickstart/GraphQL, java.util.concurrent, java.lang.Thread, sun.nio.ch, jdk.internal.reflect, and java.lang.reflect collapse to a single ... suppressed NN lines marker. Exception messages, full Caused by chains, and all com.dotcms / com.dotmarketing frames remain visible. A representative 150-line GraphQL trace renders at ~15 lines.

Environment-variable overrides

Operators can tune logging per environment without replacing the config file:

Env var Overrides
CMS_LOG4J_CONSOLE_PATTERN Console pattern layout
CMS_LOG4J_MESSAGE_PATTERN dotcms.log file pattern (Docker config)
CMS_LOG4J_STACK_FILTER Comma-separated packages collapsed in traces

In the container, defaults live in a new entrypoint script /srv/35-set-logging-defaults.sh (same pattern as 15-detect-fips-and-set-ssl-engine.sh for CMS_SSL_ENGINE); the Docker log4j2.xml reads the env vars directly, which is safe because that config is only installed by 20-copy-overriden-files.sh when the entrypoint ran. The script composes the full patterns with the filter list embedded — log4j2 does not resolve ${...} lookups inside values sourced from env vars (log4shell hardening), so a pattern env var cannot reference the stack.filter property. The non-docker webapp config keeps self-contained in-file defaults with the same env-var override hooks.

Checklist

  • Verified by running log4j-core 2.23.1 (the version pinned in bom/logging/pom.xml) against both edited config files with exceptions thrown through CompletableFuture chains, reflection, executors, and io.vavr.control.Try — filtered frames collapse, application frames and cause chains stay intact.

Before (GraphQL story-block JSON error, abridged — 150+ lines in production):

 17:30:03.297  WARN  execution.SimpleDataFetcherExceptionHandler - Exception while fetching data (/page/containers[1]/containerContentlets[0]/contentlets[0]/subheading) : Expected a ':' after a key at 152 [character 153 line 1]
 com.dotmarketing.util.json.JSONException: Expected a ':' after a key at 152 [character 153 line 1]
 	at com.dotmarketing.util.json.JSONTokener.syntaxError(JSONTokener.java:399) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:198) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:328) ~[?:?]
 	at com.dotmarketing.util.json.JSONArray.<init>(JSONArray.java:240) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:332) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:200) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:328) ~[?:?]
 	at com.dotmarketing.util.json.JSONArray.<init>(JSONArray.java:240) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:332) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:200) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:304) ~[?:?]
 	at com.dotcms.graphql.datafetcher.StoryBlockFieldDataFetcher.get(StoryBlockFieldDataFetcher.java:22) ~[?:?]
 	at com.dotcms.graphql.datafetcher.StoryBlockFieldDataFetcher.get(StoryBlockFieldDataFetcher.java:12) ~[?:?]
 	at graphql.execution.ExecutionStrategy.fetchField(ExecutionStrategy.java:279) ~[?:?]
 	at graphql.execution.ExecutionStrategy.resolveFieldWithInfo(ExecutionStrategy.java:210) ~[?:?]
 	at graphql.execution.AsyncExecutionStrategy.execute(AsyncExecutionStrategy.java:60) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForObject(ExecutionStrategy.java:667) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:454) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForList(ExecutionStrategy.java:546) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForList(ExecutionStrategy.java:500) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:439) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeField(ExecutionStrategy.java:404) ~[?:?]
 	at graphql.execution.ExecutionStrategy.lambda$resolveFieldWithInfo$1(ExecutionStrategy.java:212) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:705) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:683) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2227) ~[?:?]
 	at graphql.execution.ExecutionStrategy.resolveFieldWithInfo(ExecutionStrategy.java:211) ~[?:?]
 	at graphql.execution.AsyncExecutionStrategy.execute(AsyncExecutionStrategy.java:60) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForObject(ExecutionStrategy.java:667) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:454) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForList(ExecutionStrategy.java:546) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForList(ExecutionStrategy.java:500) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:439) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeField(ExecutionStrategy.java:404) ~[?:?]
 	at graphql.execution.ExecutionStrategy.lambda$resolveFieldWithInfo$1(ExecutionStrategy.java:212) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:705) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:683) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2227) ~[?:?]
 	at graphql.execution.ExecutionStrategy.resolveFieldWithInfo(ExecutionStrategy.java:211) ~[?:?]
 	at graphql.execution.AsyncExecutionStrategy.execute(AsyncExecutionStrategy.java:60) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForObject(ExecutionStrategy.java:667) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:454) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForList(ExecutionStrategy.java:546) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForList(ExecutionStrategy.java:500) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:439) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeField(ExecutionStrategy.java:404) ~[?:?]
 	at graphql.execution.ExecutionStrategy.lambda$resolveFieldWithInfo$1(ExecutionStrategy.java:212) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:705) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:683) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2227) ~[?:?]
 	at graphql.execution.ExecutionStrategy.resolveFieldWithInfo(ExecutionStrategy.java:211) ~[?:?]
 	at graphql.execution.AsyncExecutionStrategy.execute(AsyncExecutionStrategy.java:60) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValueForObject(ExecutionStrategy.java:667) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeValue(ExecutionStrategy.java:454) ~[?:?]
 	at graphql.execution.ExecutionStrategy.completeField(ExecutionStrategy.java:404) ~[?:?]
 	at graphql.execution.ExecutionStrategy.lambda$resolveFieldWithInfo$1(ExecutionStrategy.java:212) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyNow(CompletableFuture.java:705) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.uniApplyStage(CompletableFuture.java:683) ~[?:?]
 	at java.base/java.util.concurrent.CompletableFuture.thenApply(CompletableFuture.java:2227) ~[?:?]
 	at graphql.execution.ExecutionStrategy.resolveFieldWithInfo(ExecutionStrategy.java:211) ~[?:?]
 	at graphql.execution.AsyncExecutionStrategy.execute(AsyncExecutionStrategy.java:60) ~[?:?]
 	at graphql.execution.Execution.executeOperation(Execution.java:159) ~[?:?]
 	at graphql.execution.Execution.execute(Execution.java:105) ~[?:?]
 	at graphql.GraphQL.execute(GraphQL.java:613) ~[?:?]
 	at graphql.GraphQL.parseValidateAndExecute(GraphQL.java:538) ~[?:?]
 	at graphql.GraphQL.executeAsync(GraphQL.java:502) ~[?:?]
 	at graphql.kickstart.execution.GraphQLInvoker.executeAsync(GraphQLInvoker.java:37) ~[?:?]
 	at graphql.kickstart.execution.GraphQLInvoker.execute(GraphQLInvoker.java:28) ~[?:?]
 	at graphql.kickstart.servlet.HttpRequestInvokerImpl.invoke(HttpRequestInvokerImpl.java:200) ~[?:?]
 	at graphql.kickstart.servlet.HttpRequestInvokerImpl.handle(HttpRequestInvokerImpl.java:108) ~[?:?]
 	at graphql.kickstart.servlet.HttpRequestInvokerImpl.execute(HttpRequestInvokerImpl.java:48) ~[?:?]
 	at graphql.kickstart.servlet.HttpRequestHandlerImpl.handle(HttpRequestHandlerImpl.java:43) ~[?:?]
 	at com.dotcms.graphql.DotGraphQLHttpServlet.handleRequest(DotGraphQLHttpServlet.java:80) ~[?:?]
 	at com.dotcms.graphql.DotGraphQLHttpServlet.doPost(DotGraphQLHttpServlet.java:63) ~[?:?]
 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:555) ~[?:?]
 	at javax.servlet.http.HttpServlet.service(HttpServlet.java:623) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:197) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:51) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotmarketing.filters.CMSFilter.doFilterInternal(CMSFilter.java:215) ~[?:?]
 	at com.dotmarketing.filters.CMSFilter.doFilter(CMSFilter.java:62) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.filters.interceptor.AbstractWebInterceptorSupportFilter.doFilter(AbstractWebInterceptorSupportFilter.java:90) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.filters.interceptor.AbstractWebInterceptorSupportFilter.doFilter(AbstractWebInterceptorSupportFilter.java:90) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.visitor.filter.servlet.VisitorFilter.doFilter(VisitorFilter.java:79) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.vanityurl.filters.VanityURLFilter.doFilter(VanityURLFilter.java:107) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at org.tuckey.web.filters.urlrewrite.RuleChain.handleRewrite(RuleChain.java:176) ~[?:?]
 	at org.tuckey.web.filters.urlrewrite.RuleChain.doRules(RuleChain.java:145) ~[?:?]
 	at org.tuckey.web.filters.urlrewrite.UrlRewriter.processRequest(UrlRewriter.java:92) ~[?:?]
 	at org.tuckey.web.filters.urlrewrite.UrlRewriteFilter.doFilter(UrlRewriteFilter.java:389) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotmarketing.filters.TimeMachineFilter.doFilter(TimeMachineFilter.java:71) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.filters.interceptor.AbstractWebInterceptorSupportFilter.doFilter(AbstractWebInterceptorSupportFilter.java:90) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotmarketing.filters.ThreadNameFilter.doFilter(ThreadNameFilter.java:88) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotmarketing.filters.CharsetEncodingFilter.doFilter(CharsetEncodingFilter.java:99) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotmarketing.filters.CookiesFilter.doFilter(CookiesFilter.java:53) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at org.apache.catalina.filters.HttpHeaderSecurityFilter.doFilter(HttpHeaderSecurityFilter.java:129) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.filters.RequestTrackingFilter.doFilter(RequestTrackingFilter.java:77) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.cost.RequestCostFilter.doFilter(RequestCostFilter.java:65) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at com.dotcms.filters.NormalizationFilter.doFilter(NormalizationFilter.java:89) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:166) ~[?:?]
 	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:142) ~[?:?]
 	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:166) ~[?:?]
 	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:88) ~[?:?]
 	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:491) ~[?:?]
 	at com.dotcms.tomcat.redissessions.RedisSessionHandlerValve.invoke(RedisSessionHandlerValve.java:38) ~[?:?]
 	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127) ~[?:?]
 	at org.apache.catalina.valves.AbstractAccessLogValve.invoke(AbstractAccessLogValve.java:764) ~[?:?]
 	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:83) ~[?:?]
 	at org.apache.catalina.valves.RemoteIpValve.invoke(RemoteIpValve.java:763) ~[?:?]
 	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:72) ~[?:?]
 	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:344) ~[?:?]
 	at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:398) ~[?:?]
 	at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:63) ~[?:?]
 	at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:1309) ~[?:?]
 	at org.apache.tomcat.util.net.Nio2Endpoint$SocketProcessor.doRun(Nio2Endpoint.java:1731) ~[?:?]
 	at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52) ~[?:?]
 	at org.apache.tomcat.util.net.AbstractEndpoint.processSocket(AbstractEndpoint.java:1461) ~[?:?]
 	at org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper$2.completed(Nio2Endpoint.java:643) ~[?:?]
 	at org.apache.tomcat.util.net.Nio2Endpoint$Nio2SocketWrapper$2.completed(Nio2Endpoint.java:619) ~[?:?]
 	at java.base/sun.nio.ch.Invoker.invokeUnchecked(Invoker.java:121) ~[?:?]
 	at java.base/sun.nio.ch.Invoker$1.run(Invoker.java:201) ~[?:?]
 	at java.base/sun.nio.ch.AsynchronousChannelGroupImpl$1.run(AsynchronousChannelGroupImpl.java:108) ~[?:?]
 	at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:973) ~[?:?]
 	at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:491) ~[?:?]
 	at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:63) ~[?:?]
 	at java.base/java.lang.Thread.run(Thread.java:1474) [?:?]

After:

WARN  execution.SimpleDataFetcherExceptionHandler - Exception while fetching data (...) : Expected a ':' after a key at 152
com.dotmarketing.util.json.JSONException: Expected a ':' after a key at 152
 	at com.dotmarketing.util.json.JSONTokener.syntaxError(JSONTokener.java:399) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:198) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:328) ~[?:?]
 	at com.dotmarketing.util.json.JSONArray.<init>(JSONArray.java:240) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:332) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:200) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:328) ~[?:?]
 	at com.dotmarketing.util.json.JSONArray.<init>(JSONArray.java:240) ~[?:?]
 	at com.dotmarketing.util.json.JSONTokener.nextValue(JSONTokener.java:332) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:200) ~[?:?]
 	at com.dotmarketing.util.json.JSONObject.<init>(JSONObject.java:304) ~[?:?]
 	at com.dotcms.graphql.datafetcher.StoryBlockFieldDataFetcher.get(StoryBlockFieldDataFetcher.java:22) ~[?:?]
 	at com.dotcms.graphql.datafetcher.StoryBlockFieldDataFetcher.get(StoryBlockFieldDataFetcher.java:12) ~[?:?]
    ... suppressed 135 lines

Note

Testing showed %ex{filters(...)} is silently ignored by log4j2 — only %xEx honors the filters option. The test configs (dotcms-integration, dotcms-postman, e2e, config/user/logging) all use %ex{filters(...)}, so their frame filtering has never worked; left out of scope here as a one-character follow-up fix.

Resolves #36515

🤖 Generated with Claude Code

This PR fixes: #36515

Stack traces in console and dotcms.log were dominated by framework
plumbing - a single GraphQL data error produced 150+ lines of which
only ~10 were dotCMS frames. Apply log4j2's %xEx{filters(...)} with a
shared stack.filter property so frames from Tomcat/Catalina, servlet,
GraphQL execution, java.util.concurrent, reflection, tuckey and vavr
packages collapse to "... suppressed NN lines". Exception messages,
Caused-by chains and all com.dotcms/com.dotmarketing frames remain
visible.

Note: %ex{filters(...)} is silently ignored by log4j2 (verified on
2.23.1) - only %xEx honors the filters option.

Resolves #36515

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
@claude

claude Bot commented Jul 10, 2026

Copy link
Copy Markdown
Contributor

Claude finished @wezell's task in 2m 51s —— View job


Code Review

I reviewed the four changed files against origin/main, focusing on the log4j2 pattern/property wiring and the new entrypoint script.

New Issues

  • 🟡 Medium: dotCMS/src/main/docker/original/ROOT/srv/OVERRIDE/WEB-INF/log4j/log4j2.xml:11-12MESSAGE_PATTERN and CONSOLE_PATTERN resolve to bare ${env:CMS_LOG4J_MESSAGE_PATTERN} / ${env:CMS_LOG4J_CONSOLE_PATTERN} with no in-file fallback default (unlike the webapp config at log4j2.xml:22-24, which uses ${env:...:-${DEFAULT_...}}). If those env vars are ever unset when this config loads, log4j2 leaves the lookup unresolved and the layout becomes the literal string ${env:CMS_LOG4J_MESSAGE_PATTERN}, breaking all console + dotcms.log output. In normal operation this is fine because entrypoint.sh sources 35-set-logging-defaults.sh before catalina.sh run, but the config now hard-depends on that script running — anyone launching catalina directly, or reordering the entrypoint sourcing, gets broken logs with no graceful degradation. Consider giving this config the same two-level DEFAULT_* fallback the webapp config has, so the file is self-contained. (Assumption: unresolved log4j2 env lookups without :- leave the literal token — standard StrSubstitutor behavior. What to verify: confirm on 2.23.1.)

  • 🟡 Medium: dotCMS/src/main/docker/original/ROOT/srv/35-set-logging-defaults.sh:20-21 — the Docker default console/file patterns omit the {nolookups} guard that the webapp config applies to %logger/%msg (webapp/.../log4j2.xml:23). Message lookups are disabled by default in log4j 2.23.1, so this is defense-in-depth rather than an active vuln, but since you're rewriting these patterns now it's a good moment to align the two configs and keep the hardening consistent across the webapp default and the production container override.

Notes (non-blocking)

  • The two-level indirection (DEFAULT_CONSOLE_PATTERNCONSOLE_PATTERN) correctly sidesteps the %d{...} brace-vs-:- parsing problem; good call documenting why in the comment.
  • log4j2 splits the filters(...) list on \s*,\s*, so the newline-and-indent formatting of DEFAULT_STACK_FILTER in webapp/.../log4j2.xml:8-21 is parsed correctly — no whitespace leaks into package names. Verified this is safe.
  • The %ex{filters(...)}-is-silently-ignored finding for the test configs is well worth landing as the promised follow-up; this PR correctly uses %xEx everywhere.
  • entrypoint.sh mode change to 755 and the new script at 755 (sourced, not exec'd) are both fine.

No correctness bugs found in the happy path; both flags are robustness/consistency items and neither blocks merge.

• branch issue-36515-log4j2-stack-frame-filters

…lter

Wrap the pattern and stack-filter properties in ${env:...} lookups with
the existing values as fallback defaults, so operators can tune logging
per environment without replacing the whole config file:

- CMS_LOG4J_MESSAGE_PATTERN  (dotcms.log file pattern, docker config)
- CMS_LOG4J_CONSOLE_PATTERN  (console pattern)
- CMS_LOG4J_STACK_FILTER     (comma-separated packages to collapse)

Defaults live in DEFAULT_* properties because a pattern inlined as an
${env:VAR:-default} default value would terminate early at the first
bare '}' from %d{...}/%xEx{...}.

Resolves #36515

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>
Define the CMS_LOG4J_* defaults in /srv/35-set-logging-defaults.sh
alongside the other container env defaults, following the pattern of
15-detect-fips-and-set-ssl-engine.sh. The docker log4j2.xml now reads
the env vars directly - safe because that config is only installed by
20-copy-overriden-files.sh, i.e. when the entrypoint ran.

The script composes the full patterns with the filter list embedded:
log4j2 does not resolve ${...} lookups inside values sourced from env
vars (log4shell hardening), so a pattern env var cannot reference the
stack.filter property.

The non-docker webapp config keeps self-contained in-file defaults.

Resolves #36515

Co-Authored-By: Claude Fable 5 <noreply@anthropic.com>

@notmattmonroe notmattmonroe left a comment

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

reviewed for better logging

@mergify

mergify Bot commented Jul 10, 2026

Copy link
Copy Markdown

Tick the box to add this pull request to the merge queue (same as @mergifyio queue).

  • Queue this pull request

@wezell
wezell added this pull request to the merge queue Jul 10, 2026
Merged via the queue into main with commit ac778a1 Jul 10, 2026
65 checks passed
@wezell
wezell deleted the issue-36515-log4j2-stack-frame-filters branch July 10, 2026 20:46
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

AI: Safe To Rollback Area : Backend PR changes Java/Maven backend code

Projects

Status: No status

Development

Successfully merging this pull request may close these issues.

Reduce log verbosity: collapse framework stack frames via log4j2 %xEx filters

4 participants