Open
Conversation
Contributor
|
We need tests to accept a change like this. |
Contributor
There was a problem hiding this comment.
Pull request overview
This PR aims to reduce duplicate ERROR log entries emitted by DefaultStackTraceFilterer by filtering stack traces for the full exception cause-chain without logging each cause separately, and logging the full stack trace only once for the top-level exception.
Changes:
- Extracted the filtering/trimming logic into a new private
doFilter(Throwable)method. - Updated recursive filtering to call
doFilter(...)when walking the cause chain. - Updated
filter(Throwable)to log conditionally (intended: once per top-level exception).
Comments suppressed due to low confidence (1)
grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java:88
- In
filter(Throwable source, boolean recursive), the recursive walk callsdoFilter(current)starting withcurrent = source, and thenfilter(source)is invoked afterward. This filters the top-level exception twice and, more importantly, ensures the later log infilter(source)will observe an already-filtered stack trace. Consider starting the loop atsource.getCause()(filter causes only) so the top-level exception is filtered/logged exactly once infilter(source).
public Throwable filter(Throwable source, boolean recursive) {
if (recursive) {
Throwable current = source;
while (current != null) {
doFilter(current);
current = current.getCause();
}
}
return filter(source);
💡 Add Copilot custom instructions for smarter, more guided reviews. Learn how to get started.
Comment on lines
91
to
97
| public Throwable filter(Throwable source) { | ||
| if (shouldFilter) { | ||
| StackTraceElement[] trace = source.getStackTrace(); | ||
| List<StackTraceElement> newTrace = filterTraceWithCutOff(trace, cutOffPackage); | ||
|
|
||
| if (newTrace.isEmpty()) { | ||
| // filter with no cut-off so at least there is some trace | ||
| newTrace = filterTraceWithCutOff(trace, null); | ||
| } | ||
|
|
||
| // Only trim the trace if there was some application trace on the stack | ||
| // if not we will just skip sanitizing and leave it as is | ||
| if (!newTrace.isEmpty()) { | ||
| // We don't want to lose anything, so log it | ||
| boolean modified = doFilter(source); | ||
| if (modified) { | ||
| // Log the full stack trace once for the top-level exception (includes causes) | ||
| STACK_LOG.error(FULL_STACK_TRACE_MESSAGE, source); | ||
| StackTraceElement[] clean = new StackTraceElement[newTrace.size()]; | ||
| newTrace.toArray(clean); | ||
| source.setStackTrace(clean); | ||
| } |
There was a problem hiding this comment.
filter(Throwable source) currently calls doFilter(source) (which mutates source via setStackTrace) before logging FULL_STACK_TRACE_MESSAGE. That means the "Full Stack Trace" log is no longer the full/original trace, but the already-filtered trace. To preserve prior behavior and the PR description, log the exception before applying the filtered stack trace (e.g., have doFilter compute/return the cleaned trace without mutating, then apply after logging, or temporarily save/restore the original trace around the log call).
Comment on lines
92
to
97
| if (shouldFilter) { | ||
| StackTraceElement[] trace = source.getStackTrace(); | ||
| List<StackTraceElement> newTrace = filterTraceWithCutOff(trace, cutOffPackage); | ||
|
|
||
| if (newTrace.isEmpty()) { | ||
| // filter with no cut-off so at least there is some trace | ||
| newTrace = filterTraceWithCutOff(trace, null); | ||
| } | ||
|
|
||
| // Only trim the trace if there was some application trace on the stack | ||
| // if not we will just skip sanitizing and leave it as is | ||
| if (!newTrace.isEmpty()) { | ||
| // We don't want to lose anything, so log it | ||
| boolean modified = doFilter(source); | ||
| if (modified) { | ||
| // Log the full stack trace once for the top-level exception (includes causes) | ||
| STACK_LOG.error(FULL_STACK_TRACE_MESSAGE, source); | ||
| StackTraceElement[] clean = new StackTraceElement[newTrace.size()]; | ||
| newTrace.toArray(clean); | ||
| source.setStackTrace(clean); | ||
| } |
There was a problem hiding this comment.
This change modifies when/how often the StackTrace logger logs (STACK_LOG.error(...)) during recursive filtering, but existing specs (e.g., grails-core/src/test/.../StackTraceFiltererSpec.groovy) only assert the sanitized stack trace contents and don't cover log emission/count. Adding a test that captures the StackTrace logger output and asserts a single "Full Stack Trace" entry for filter(e, true) would help prevent regressions.
jdaugherty
reviewed
Apr 8, 2026
| boolean modified = doFilter(source); | ||
| if (modified) { | ||
| // Log the full stack trace once for the top-level exception (includes causes) | ||
| STACK_LOG.error(FULL_STACK_TRACE_MESSAGE, source); |
Contributor
There was a problem hiding this comment.
Isn't this a different meaning now? Before it would have been the full stack trace while now it's the filtered. Wouldn't a better solution be to set the logging to trace or something for these detailed stack traces ? Instead of this change why not disable STACK_LOG if you don't want this output?
Contributor
Author
There was a problem hiding this comment.
@jdaugherty sensible defaults. logging a stracktrace 4x that has no useful information (especially with the groovy 4 clutter) quickly leads to a scenario where you can run out of disk space fast.
I have yet to see an example where the 4x logging provides anything useful. do you have one?
Contributor
|
The more I have thought about this, the more I realize this is not a bug fix. This is a feature - we are not trimming stacktraces that got longer due to groovy 4. We are instead hiding traces that get logged multiple times. I think the original behavior needs to stay and we need to make the new feature opt in. |
This comment has been minimized.
This comment has been minimized.
Contributor
|
I would probably label this as a bug. Or is this behavior intentional? This is the log output when visiting package com.example
class StackTraceController {
def show() {
display()
}
private void display() {
notHere
}
}> <
> ____ _ _ <
> / ___|_ __ __ _(_) |___ <
> | | _| '__/ _` | | / __| <
> | |_| | | | (_| | | \__ \ <
> \____|_| \__,_|_|_|___/ <
> https://grails.apache.org <
> <
Grails application running at http://localhost:8080 in environment: development
2026-04-09T13:48:34.488+02:00 ERROR 2325051 --- [p1601249101-110] StackTrace : Full Stack Trace:
java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:751)
at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1622)
at org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:195)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:110)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:91)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1555)
at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:822)
at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:438)
at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:470)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:717)
at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1102)
at org.eclipse.jetty.server.Handler$Wrapper.handle(Handler.java:740)
at org.eclipse.jetty.server.handler.EventsHandler.handle(EventsHandler.java:81)
at org.eclipse.jetty.server.Server.handle(Server.java:182)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:721)
at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:416)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166)
at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: com.example.StackTraceController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at com.example.StackTraceController.propertyMissing(StackTraceController.groovy)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:343)
at groovy.lang.MetaClassImpl.invokeMissingProperty(MetaClassImpl.java:852)
at groovy.lang.MetaClassImpl$11.getProperty(MetaClassImpl.java:2181)
at org.codehaus.groovy.runtime.callsite.GetEffectivePogoPropertySite.getProperty(GetEffectivePogoPropertySite.java:90)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callGroovyObjectGetProperty(AbstractCallSite.java:341)
at com.example.StackTraceController.display(StackTraceController.groovy:10)
at com.example.StackTraceController.show(StackTraceController.groovy:6)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
... 55 common frames omitted
2026-04-09T13:48:34.498+02:00 ERROR 2325051 --- [p1601249101-110] StackTrace : Full Stack Trace:
groovy.lang.MissingPropertyException: No such property: notHere for class: com.example.StackTraceController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at com.example.StackTraceController.propertyMissing(StackTraceController.groovy)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:343)
at groovy.lang.MetaClassImpl.invokeMissingProperty(MetaClassImpl.java:852)
at groovy.lang.MetaClassImpl$11.getProperty(MetaClassImpl.java:2181)
at org.codehaus.groovy.runtime.callsite.GetEffectivePogoPropertySite.getProperty(GetEffectivePogoPropertySite.java:90)
at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callGroovyObjectGetProperty(AbstractCallSite.java:341)
at com.example.StackTraceController.display(StackTraceController.groovy:10)
at com.example.StackTraceController.show(StackTraceController.groovy:6)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at java.base/java.lang.reflect.Method.invoke(Method.java:580)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:527)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at jakarta.servlet.http.HttpServlet.service(HttpServlet.java:614)
at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:751)
at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1622)
at org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:195)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:201)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.springframework.web.filter.ServerHttpObservationFilter.doFilterInternal(ServerHttpObservationFilter.java:110)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.springframework.web.filter.CorsFilter.doFilterInternal(CorsFilter.java:91)
at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:116)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1555)
at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:822)
at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:438)
at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:470)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:717)
at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1102)
at org.eclipse.jetty.server.Handler$Wrapper.handle(Handler.java:740)
at org.eclipse.jetty.server.handler.EventsHandler.handle(EventsHandler.java:81)
at org.eclipse.jetty.server.Server.handle(Server.java:182)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:721)
at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:416)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166)
at java.base/java.lang.Thread.run(Thread.java:1583)
2026-04-09T13:48:34.502+02:00 ERROR 2325051 --- [p1601249101-110] StackTrace : Full Stack Trace:
java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:751)
at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1622)
at org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:195)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1555)
at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:822)
at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:438)
at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:470)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:717)
at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1102)
at org.eclipse.jetty.server.Handler$Wrapper.handle(Handler.java:740)
at org.eclipse.jetty.server.handler.EventsHandler.handle(EventsHandler.java:81)
at org.eclipse.jetty.server.Server.handle(Server.java:182)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:721)
at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:416)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166)
at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: com.example.StackTraceController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at com.example.StackTraceController.display(StackTraceController.groovy:10)
at com.example.StackTraceController.show(StackTraceController.groovy:6)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
... 44 common frames omitted
2026-04-09T13:48:34.524+02:00 ERROR 2325051 --- [p1601249101-110] o.g.web.errors.GrailsExceptionResolver : MissingPropertyException occurred when processing request: [GET] /stackTrace/show
No such property: notHere for class: com.example.StackTraceController. Stacktrace follows:
java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at org.eclipse.jetty.ee10.servlet.ServletHolder.handle(ServletHolder.java:751)
at org.eclipse.jetty.ee10.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1622)
at org.eclipse.jetty.ee10.websocket.servlet.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:195)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.FilterHolder.doFilter(FilterHolder.java:205)
at org.eclipse.jetty.ee10.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1594)
at org.eclipse.jetty.ee10.servlet.ServletHandler$MappedServlet.handle(ServletHandler.java:1555)
at org.eclipse.jetty.ee10.servlet.ServletChannel.dispatch(ServletChannel.java:822)
at org.eclipse.jetty.ee10.servlet.ServletChannel.handle(ServletChannel.java:438)
at org.eclipse.jetty.ee10.servlet.ServletHandler.handle(ServletHandler.java:470)
at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:575)
at org.eclipse.jetty.ee10.servlet.SessionHandler.handle(SessionHandler.java:717)
at org.eclipse.jetty.server.handler.ContextHandler.handle(ContextHandler.java:1102)
at org.eclipse.jetty.server.Handler$Wrapper.handle(Handler.java:740)
at org.eclipse.jetty.server.handler.EventsHandler.handle(EventsHandler.java:81)
at org.eclipse.jetty.server.Server.handle(Server.java:182)
at org.eclipse.jetty.server.internal.HttpChannelState$HandlerInvoker.run(HttpChannelState.java:721)
at org.eclipse.jetty.server.internal.HttpConnection.onFillable(HttpConnection.java:416)
at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:322)
at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
at org.eclipse.jetty.io.SelectableChannelEndPoint$1.run(SelectableChannelEndPoint.java:53)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:981)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.doRunJob(QueuedThreadPool.java:1211)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1166)
at java.base/java.lang.Thread.run(Thread.java:1583)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: com.example.StackTraceController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
at com.example.StackTraceController.display(StackTraceController.groovy:10)
at com.example.StackTraceController.show(StackTraceController.groovy:6)
at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
... 44 common frames omitted
|
Contributor
|
This is the log output with these changes: > <
> ____ _ _ <
> / ___|_ __ __ _(_) |___ <
> | | _| '__/ _` | | / __| <
> | |_| | | | (_| | | \__ \ <
> \____|_| \__,_|_|_|___/ <
> https://grails.apache.org <
> <
grails-test-examples-app5: 0.1 | JVM: BellSoft 17.0.18
Grails: 7.1.0-SNAPSHOT | Groovy: 4.0.31 | Spring Boot: 3.5.13
Spring: 6.2.17
Grails application running at http://localhost:8080 in environment: development
2026-04-09 15:32:18.490 ERROR --- [nio-8080-exec-1] StackTrace : Full Stack Trace:
java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: app5.TargetController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at app5.TargetController.display(TargetController.groovy:41)
at app5.TargetController.show(TargetController.groovy:37)
... 13 common frames omitted
2026-04-09 15:32:18.517 ERROR --- [nio-8080-exec-1] o.g.web.errors.GrailsExceptionResolver : MissingPropertyException occurred when processing request: [GET] /target/show
No such property: notHere for class: app5.TargetController. Stacktrace follows:
java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: app5.TargetController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at app5.TargetController.display(TargetController.groovy:41)
at app5.TargetController.show(TargetController.groovy:37)
... 13 common frames omitted |
- cleanup and clarify current tests - add test for logging once
Let `CountingStackTraceFilterer` call `super.filter(source)`.
Contributor
|
I think the intent is to disable the logging on this filter, yes? Then you don't see the the full stacktraces. |
Contributor
|
Why not change the default configuration to just hide logs from grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java then there wouldn't be a duplicate log right? We also appear to have removed the cut off package, which means it could filter our own package |
Contributor
Yes, that might be one option/solution! <logger name="StackTrace" level="OFF" />> <
> ____ _ _ <
> / ___|_ __ __ _(_) |___ <
> | | _| '__/ _` | | / __| <
> | |_| | | | (_| | | \__ \ <
> \____|_| \__,_|_|_|___/ <
> https://grails.apache.org <
> <
grails-test-examples-app5: 0.1 | JVM: BellSoft 17.0.18
Grails: 8.0.0-SNAPSHOT | Groovy: 4.0.31 | Spring Boot: 3.5.13
Spring: 6.2.17
Grails application running at http://localhost:8080 in environment: development
2026-04-09 16:33:53.713 ERROR --- [nio-8080-exec-1] o.g.web.errors.GrailsExceptionResolver : MissingPropertyException occurred when processing request: [GET] /target/show
No such property: notHere for class: app5.TargetController. Stacktrace follows:
java.lang.reflect.InvocationTargetException
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at org.grails.core.DefaultGrailsControllerClass$ReflectionInvoker.invoke(DefaultGrailsControllerClass.java:215)
at org.grails.core.DefaultGrailsControllerClass.invoke(DefaultGrailsControllerClass.java:192)
at org.grails.web.mapping.mvc.UrlMappingsInfoHandlerAdapter.handle(UrlMappingsInfoHandlerAdapter.groovy:110)
at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:1089)
at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:979)
at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:1014)
at org.springframework.web.servlet.FrameworkServlet.doGet(FrameworkServlet.java:903)
at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:885)
at org.grails.web.servlet.mvc.GrailsWebRequestFilter.doFilterInternal(GrailsWebRequestFilter.java:80)
at org.grails.web.filters.HiddenHttpMethodFilter.doFilterInternal(HiddenHttpMethodFilter.java:70)
at java.base/java.lang.Thread.run(Thread.java:840)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: app5.TargetController
at grails.artefact.gsp.TagLibraryInvoker$Trait$Helper.propertyMissing(TagLibraryInvoker.groovy:125)
at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:77)
at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at app5.TargetController.display(TargetController.groovy:41)
Caused by: groovy.lang.MissingPropertyException: No such property: notHere for class: app5.TargetController
at app5.TargetController.show(TargetController.groovy:37)
... 13 common frames omitted |
Contributor
|
Curiosly enough, setting the system property |
✅ All tests passed ✅🏷️ Commit: ce60438 Learn more about TestLens at testlens.app. |
Contributor
|
Hmm, it looks to me like the console logging from So, if that is the case, disabling logging output for <logger name="StackTrace" level="OFF" />However, In that case I do think the logger should have a more descriptive name, like |
Contributor
|
Yeah, I think this is just "debug" output in case something is being truncated. I think instead of making this change we should just set |
Contributor
Author
I am fully aware that What other framework defaults to printing a stack trace 4x? Micronaut? Spring Boot? Anything?? and register it @jdaugherty, in @matrei examples above, what information does the 4x version have that the 1x version does not? Why would we want to silence logs from a class named DefaultStackTraceFilterer? Isn't the job of a stack trace filter to filter stack traces instead of replicate them? |
Contributor
|
With the forward and async actions I suspect its important. Thats probably the only real reason to turn it on. Sensible default would be to configure logging with it just off. It will still log in their error controller - the stacktrace logger is just for details. |
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Fix duplicate stack trace logging in DefaultStackTraceFilterer
When an exception occurs in a Grails controller, the same error is logged multiple times to the
StackTracelogger. For a typicalInvocationTargetExceptionwrapping aRuntimeException, this produces 3-4 separate ERROR log entries for a single request:StackTracelogger: Full stack trace of the wrapper exceptionStackTracelogger: Full stack trace of the root causeStackTracelogger: Full stack trace of the wrapper again (condensed)GrailsExceptionResolverlogger: The exception with request contextEntries 1-3 all come from
DefaultStackTraceFilterer.filter(). Thefilter(Throwable source, boolean recursive)method walks thecause chain and calls
filter(Throwable source)for each throwable. Butfilter(Throwable source)logs the full stack trace viaSTACK_LOG.error(FULL_STACK_TRACE_MESSAGE, source)every time it trims a trace — so each cause in the chain gets its own log entry.This is compounded by the fact that
GrailsExceptionResolver.logStackTrace()then logs the exception a final time with requestcontext. The filterer and the resolver were written independently — the filterer doesn't know the resolver will also log, and the
resolver doesn't know the filterer already logged.
Fix
Extract the stack trace trimming logic into a private
doFilter(Throwable)method that filters without logging. The recursive walkcalls
doFilter()for each cause in the chain. The publicfilter(Throwable source)method callsdoFilter()and then logs thefull stack trace once for the top-level exception (which naturally includes its causes in the log output).
This reduces the
StackTracelogger output from N entries (one per cause) to 1 entry, while preserving all existing behavior:StackTraceFiltererinterface is unchangedGrailsExceptionResolversubclasses are unaffectedThe name of this class is DefaultStackTraceFilterer, should the intent not be to filter stack traces?