From 83b22f647a208666db4cfd0919082bd4f2cca0f8 Mon Sep 17 00:00:00 2001 From: Scott Murphy Heiberg Date: Tue, 7 Apr 2026 22:49:38 -0600 Subject: [PATCH 1/6] fix 4x exception logging --- .../reporting/DefaultStackTraceFilterer.java | 43 ++++++++++++------- 1 file changed, 27 insertions(+), 16 deletions(-) diff --git a/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java b/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java index 38c0235706b..8bd60872ee5 100644 --- a/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java +++ b/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java @@ -81,7 +81,7 @@ public Throwable filter(Throwable source, boolean recursive) { if (recursive) { Throwable current = source; while (current != null) { - current = filter(current); + doFilter(current); current = current.getCause(); } } @@ -90,27 +90,38 @@ public Throwable filter(Throwable source, boolean recursive) { public Throwable filter(Throwable source) { if (shouldFilter) { - StackTraceElement[] trace = source.getStackTrace(); - List 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); } } return source; } + private boolean doFilter(Throwable source) { + if (!shouldFilter) { + return false; + } + StackTraceElement[] trace = source.getStackTrace(); + List 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()) { + StackTraceElement[] clean = new StackTraceElement[newTrace.size()]; + newTrace.toArray(clean); + source.setStackTrace(clean); + return true; + } + return false; + } + private List filterTraceWithCutOff(StackTraceElement[] trace, String endPackage) { List newTrace = new ArrayList<>(); boolean foundGroovy = false; From e85c094eeced56303a6ff09fb08541bacc3c280f Mon Sep 17 00:00:00 2001 From: Mattias Reichel Date: Thu, 9 Apr 2026 15:42:38 +0200 Subject: [PATCH 2/6] test: update StackTraceFiltererSpec - cleanup and clarify current tests - add test for logging once --- .../reporting/StackTraceFiltererSpec.groovy | 198 +++++++++++------- 1 file changed, 122 insertions(+), 76 deletions(-) diff --git a/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy b/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy index 36affcd706d..d2d71b024ed 100644 --- a/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy +++ b/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy @@ -21,102 +21,148 @@ package org.grails.exception.reporting import org.grails.exceptions.reporting.DefaultStackTraceFilterer import spock.lang.Specification +import org.grails.exceptions.reporting.StackTraceFilterer + class StackTraceFiltererSpec extends Specification { - private filterer = new DefaultStackTraceFilterer() - private gcl = new GroovyClassLoader() + StackTraceFilterer filterer = new DefaultStackTraceFilterer() + ClassLoader gcl = new GroovyClassLoader() + + def 'retains application frames when filtering a stack trace'() { + given: 'a controller action that raises a missing property exception' + def controller = gcl.parseClass(''' + package test + + class FooController { + def show = { + display() + } + + void display() { + notHere + } + } + ''').getDeclaredConstructor().newInstance() + + when: 'the exception stack trace is filtered' + Throwable exception = null + try { + controller['show']() + } catch (e) { + filterer.filter(e) + exception = e + } - void "Test basic filter"() { - given: "A controller that should throw a MissingPropertyException" - def cls = gcl.parseClass(''' -package test + then: 'the exception is available for inspection' + exception != null -class FooController { - def show = { - display() - } - - void display() { - notHere + and: 'the controller action and helper method frames remain in the filtered stack trace' + with(exception.stackTrace) { + it.find { it.className == 'test.FooController' && it.lineNumber == 10 } + it.find { it.className.startsWith('test.FooController') && it.lineNumber == 6 } + } } -} -''') - when: "The stack trace is filtered with custom packages" - filterer.setCutOffPackage("org.spockframework.util") - Throwable exception + def 'retains controller frames across wrapped exceptions during recursive filtering'() { + given: 'a controller action that wraps a failure triggered during service interaction' + def controller = gcl.parseClass(''' + package test + + class FooController { + def fooService = new FooService() + def show = { + display() + } + + void display() { + try { + fooService.notThere() + } + catch(e) { + throw new RuntimeException("Bad things happened", e) + } + + } + } + class FooService { + void doStuff() { + notThere() + } + } + ''').getDeclaredConstructor().newInstance() + + when: 'recursive filtering is applied to the exception' + Throwable exception = null try { - cls.getDeclaredConstructor().newInstance().show() + controller['show']() } catch (e) { - filterer.filter(e) + filterer.filter(e, true) exception = e } - then: "Only valid stack elements are retained" + then: 'the wrapped exception is available for inspection' exception != null - when: - StackTraceElement[] stackTraces = exception.stackTrace - - then: - stackTraces.find { it.className == 'test.FooController' && it.lineNumber == 10 } - stackTraces.find { it.className.startsWith('test.FooController') && it.lineNumber == 6 } + and: 'the filtered stack trace retains the controller frames for the wrapper and action' + with(exception.stackTrace) { + it.find { it.className == 'test.FooController' && it.lineNumber == 15 } + it.find { it.className.startsWith('test.FooController') && it.lineNumber == 7 } + } } - void "Test deep filter"() { - given: "A controller that calls a service and rethrows an exception" - def cls = gcl.parseClass(''' -package test - -class FooController { - def fooService = new FooService() - def show = { - display() - } - - void display() { - try { - fooService.notThere() - } - catch(e) { - throw new RuntimeException("Bad things happened", e) + def 'recursive filtering sanitizes the full cause chain while logging the full stack trace once'() { + given: 'a cause chain with both application and internal stack frames' + def filterer = new CountingStackTraceFilterer() + def rootCause = new IllegalStateException('root cause') + rootCause.stackTrace = [ + new StackTraceElement('test.FooService', 'doStuff', 'FooService.groovy', 3), + new StackTraceElement('org.codehaus.groovy.runtime.InvokerHelper', 'invokeMethod', 'InvokerHelper.java', 12) + ] as StackTraceElement[] + + def wrappedCause = new RuntimeException('wrapped cause', rootCause) + wrappedCause.stackTrace = [ + new StackTraceElement('test.FooController', 'display', 'FooController.groovy', 11), + new StackTraceElement('org.codehaus.groovy.runtime.callsite.CallSiteArray', 'defaultCall', 'CallSiteArray.java', 15) + ] as StackTraceElement[] + + def exception = new RuntimeException('top level', wrappedCause) + exception.stackTrace = [ + new StackTraceElement('test.FooController', 'show', 'FooController.groovy', 7), + new StackTraceElement('org.codehaus.groovy.runtime.ScriptBytecodeAdapter', 'unwrap', 'ScriptBytecodeAdapter.java', 20) + ] as StackTraceElement[] + + when: 'recursive filtering is applied to the top-level exception' + filterer.filter(exception, true) + + then: 'the full stack trace logging path is invoked only for the top-level exception' + filterer.singleExceptionFilterInvocations == 1 + filterer.filteredSources == [exception] + + and: 'application stack frames are retained across the full cause chain' + with(exception) { + stackTrace*.className == ['test.FooController'] + stackTrace*.lineNumber == [7] + cause.stackTrace*.className == ['test.FooController'] + cause.stackTrace*.lineNumber == [11] + cause.cause.stackTrace*.className == ['test.FooService'] + cause.cause.stackTrace*.lineNumber == [3] } - - } -} -class FooService { - void doStuff() { - notThere() } -} -''') - - when: "The stack trace is filtered with custom packages" - filterer.setCutOffPackage("org.spockframework.util") - Throwable exception - try { - cls.getDeclaredConstructor().newInstance().show() - } catch (e) { - filterer.filter(e, true) - println getExceptionContents(e) - exception = e - } - then: "Only valid stack elements are retained" - exception != null + private static class CountingStackTraceFilterer extends DefaultStackTraceFilterer { - when: - StackTraceElement[] stackTraces = exception.stackTrace + int singleExceptionFilterInvocations + List filteredSources = [] - then: - stackTraces.find { it.className == 'test.FooController' && it.lineNumber == 15 } - stackTraces.find { it.className.startsWith('test.FooController') && it.lineNumber == 7 } - } + CountingStackTraceFilterer() { + super(true) + } - private String getExceptionContents(Throwable e) { - final sw = new StringWriter() - def pw = new PrintWriter(sw) - e.printStackTrace pw - return sw.toString() + @Override + Throwable filter(Throwable source) { + singleExceptionFilterInvocations++ + filteredSources << source + source + } } } From ce60438cd49c55bb9d30c5d8db8479bbf19d6741 Mon Sep 17 00:00:00 2001 From: Mattias Reichel Date: Thu, 9 Apr 2026 15:52:39 +0200 Subject: [PATCH 3/6] test: update StackTraceFiltererSpec Let `CountingStackTraceFilterer` call `super.filter(source)`. --- .../reporting/StackTraceFiltererSpec.groovy | 60 +++++++++---------- 1 file changed, 30 insertions(+), 30 deletions(-) diff --git a/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy b/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy index d2d71b024ed..45b6d787c98 100644 --- a/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy +++ b/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy @@ -112,41 +112,41 @@ class StackTraceFiltererSpec extends Specification { def 'recursive filtering sanitizes the full cause chain while logging the full stack trace once'() { given: 'a cause chain with both application and internal stack frames' - def filterer = new CountingStackTraceFilterer() - def rootCause = new IllegalStateException('root cause') - rootCause.stackTrace = [ - new StackTraceElement('test.FooService', 'doStuff', 'FooService.groovy', 3), - new StackTraceElement('org.codehaus.groovy.runtime.InvokerHelper', 'invokeMethod', 'InvokerHelper.java', 12) - ] as StackTraceElement[] - - def wrappedCause = new RuntimeException('wrapped cause', rootCause) - wrappedCause.stackTrace = [ - new StackTraceElement('test.FooController', 'display', 'FooController.groovy', 11), - new StackTraceElement('org.codehaus.groovy.runtime.callsite.CallSiteArray', 'defaultCall', 'CallSiteArray.java', 15) - ] as StackTraceElement[] - - def exception = new RuntimeException('top level', wrappedCause) - exception.stackTrace = [ - new StackTraceElement('test.FooController', 'show', 'FooController.groovy', 7), - new StackTraceElement('org.codehaus.groovy.runtime.ScriptBytecodeAdapter', 'unwrap', 'ScriptBytecodeAdapter.java', 20) - ] as StackTraceElement[] + def filterer = new CountingStackTraceFilterer() + def rootCause = new IllegalStateException('root cause') + rootCause.stackTrace = [ + new StackTraceElement('test.FooService', 'doStuff', 'FooService.groovy', 3), + new StackTraceElement('org.codehaus.groovy.runtime.InvokerHelper', 'invokeMethod', 'InvokerHelper.java', 12) + ] as StackTraceElement[] + + def wrappedCause = new RuntimeException('wrapped cause', rootCause) + wrappedCause.stackTrace = [ + new StackTraceElement('test.FooController', 'display', 'FooController.groovy', 11), + new StackTraceElement('org.codehaus.groovy.runtime.callsite.CallSiteArray', 'defaultCall', 'CallSiteArray.java', 15) + ] as StackTraceElement[] + + def exception = new RuntimeException('top level', wrappedCause) + exception.stackTrace = [ + new StackTraceElement('test.FooController', 'show', 'FooController.groovy', 7), + new StackTraceElement('org.codehaus.groovy.runtime.ScriptBytecodeAdapter', 'unwrap', 'ScriptBytecodeAdapter.java', 20) + ] as StackTraceElement[] when: 'recursive filtering is applied to the top-level exception' - filterer.filter(exception, true) + filterer.filter(exception, true) then: 'the full stack trace logging path is invoked only for the top-level exception' - filterer.singleExceptionFilterInvocations == 1 - filterer.filteredSources == [exception] + filterer.singleExceptionFilterInvocations == 1 + filterer.filteredSources == [exception] and: 'application stack frames are retained across the full cause chain' - with(exception) { - stackTrace*.className == ['test.FooController'] - stackTrace*.lineNumber == [7] - cause.stackTrace*.className == ['test.FooController'] - cause.stackTrace*.lineNumber == [11] - cause.cause.stackTrace*.className == ['test.FooService'] - cause.cause.stackTrace*.lineNumber == [3] - } + with(exception) { + stackTrace*.className == ['test.FooController'] + stackTrace*.lineNumber == [7] + cause.stackTrace*.className == ['test.FooController'] + cause.stackTrace*.lineNumber == [11] + cause.cause.stackTrace*.className == ['test.FooService'] + cause.cause.stackTrace*.lineNumber == [3] + } } private static class CountingStackTraceFilterer extends DefaultStackTraceFilterer { @@ -162,7 +162,7 @@ class StackTraceFiltererSpec extends Specification { Throwable filter(Throwable source) { singleExceptionFilterInvocations++ filteredSources << source - source + super.filter(source) } } } From 024b9c800455045ab552a32ce65cec5b14e0e075 Mon Sep 17 00:00:00 2001 From: Scott Murphy Heiberg Date: Sat, 11 Apr 2026 14:01:09 -0700 Subject: [PATCH 4/6] filterer no longer logs; exception logging is the resolver's job --- .../reporting/DefaultStackTraceFilterer.java | 27 ++++--- .../reporting/StackTraceFilterer.java | 6 ++ .../reporting/StackTraceFiltererSpec.groovy | 72 ++++++++++++++++--- 3 files changed, 81 insertions(+), 24 deletions(-) diff --git a/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java b/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java index 8bd60872ee5..88ff6247821 100644 --- a/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java +++ b/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/DefaultStackTraceFilterer.java @@ -33,6 +33,14 @@ */ public class DefaultStackTraceFilterer implements StackTraceFilterer { public static final String STACK_LOG_NAME = "StackTrace"; + /** + * Dedicated logger for exception stack traces. The filterer itself no longer writes + * to it — exception logging is driven by {@code GrailsExceptionResolver}, which emits + * to this logger in addition to its own request-context log entry when + * {@code grails.exceptionresolver.logFullStackTrace} is enabled. Exposed as a public + * constant so that subclasses and logback configurations can reference the logger + * name symbolically. + */ public static final Log STACK_LOG = LogFactory.getLog(STACK_LOG_NAME); private static final String[] DEFAULT_INTERNAL_PACKAGES = new String[] { @@ -81,27 +89,17 @@ public Throwable filter(Throwable source, boolean recursive) { if (recursive) { Throwable current = source; while (current != null) { - doFilter(current); + filter(current); current = current.getCause(); } + return source; } return filter(source); } public Throwable filter(Throwable source) { - if (shouldFilter) { - 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); - } - } - return source; - } - - private boolean doFilter(Throwable source) { if (!shouldFilter) { - return false; + return source; } StackTraceElement[] trace = source.getStackTrace(); List newTrace = filterTraceWithCutOff(trace, cutOffPackage); @@ -117,9 +115,8 @@ private boolean doFilter(Throwable source) { StackTraceElement[] clean = new StackTraceElement[newTrace.size()]; newTrace.toArray(clean); source.setStackTrace(clean); - return true; } - return false; + return source; } private List filterTraceWithCutOff(StackTraceElement[] trace, String endPackage) { diff --git a/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/StackTraceFilterer.java b/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/StackTraceFilterer.java index ff0d9b6786f..304b329c583 100644 --- a/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/StackTraceFilterer.java +++ b/grails-bootstrap/src/main/groovy/org/grails/exceptions/reporting/StackTraceFilterer.java @@ -26,6 +26,12 @@ */ public interface StackTraceFilterer { + /** + * Message used as the header for full stack trace log entries emitted on the + * dedicated {@code StackTrace} logger. The filterer itself does not log; + * {@code GrailsExceptionResolver} writes the entry when + * {@code grails.exceptionresolver.logFullStackTrace} is enabled. + */ String FULL_STACK_TRACE_MESSAGE = "Full Stack Trace:"; String SYS_PROP_DISPLAY_FULL_STACKTRACE = "grails.full.stacktrace"; diff --git a/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy b/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy index 45b6d787c98..d4819bd541f 100644 --- a/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy +++ b/grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy @@ -32,12 +32,12 @@ class StackTraceFiltererSpec extends Specification { given: 'a controller action that raises a missing property exception' def controller = gcl.parseClass(''' package test - + class FooController { def show = { display() } - + void display() { notHere } @@ -63,17 +63,41 @@ class StackTraceFiltererSpec extends Specification { } } + def 'filter does not emit a StackTrace log entry for a single throwable'() { + given: 'captured System.err' + def originalErr = System.err + def baos = new ByteArrayOutputStream() + System.setErr(new PrintStream(baos, true)) + + and: 'an exception whose stack trace mixes application and internal frames' + def exception = new RuntimeException('boom') + exception.stackTrace = [ + new StackTraceElement('test.FooController', 'show', 'FooController.groovy', 6), + new StackTraceElement('java.lang.reflect.Method', 'invoke', 'Method.java', 580) + ] as StackTraceElement[] + + when: 'the exception is filtered' + filterer.filter(exception) + + then: "no 'Full Stack Trace:' entry is emitted by the filterer" + System.err.flush() + !baos.toString().contains('Full Stack Trace:') + + cleanup: + System.setErr(originalErr) + } + def 'retains controller frames across wrapped exceptions during recursive filtering'() { given: 'a controller action that wraps a failure triggered during service interaction' def controller = gcl.parseClass(''' package test - + class FooController { def fooService = new FooService() def show = { display() } - + void display() { try { fooService.notThere() @@ -81,7 +105,7 @@ class StackTraceFiltererSpec extends Specification { catch(e) { throw new RuntimeException("Bad things happened", e) } - + } } class FooService { @@ -110,7 +134,37 @@ class StackTraceFiltererSpec extends Specification { } } - def 'recursive filtering sanitizes the full cause chain while logging the full stack trace once'() { + def 'filter does not emit a StackTrace log entry when walking the cause chain'() { + given: 'captured System.err' + def originalErr = System.err + def baos = new ByteArrayOutputStream() + System.setErr(new PrintStream(baos, true)) + + and: 'a wrapped exception whose wrapper and cause mix application and internal frames' + def rootCause = new IllegalStateException('root cause') + rootCause.stackTrace = [ + new StackTraceElement('test.FooService', 'doStuff', 'FooService.groovy', 3), + new StackTraceElement('java.lang.reflect.Method', 'invoke', 'Method.java', 580) + ] as StackTraceElement[] + + def exception = new RuntimeException('boom', rootCause) + exception.stackTrace = [ + new StackTraceElement('test.FooController', 'show', 'FooController.groovy', 6), + new StackTraceElement('java.lang.reflect.Method', 'invoke', 'Method.java', 580) + ] as StackTraceElement[] + + when: 'recursive filtering is applied to the top-level exception' + filterer.filter(exception, true) + + then: "no 'Full Stack Trace:' entry is emitted for any throwable in the chain" + System.err.flush() + !baos.toString().contains('Full Stack Trace:') + + cleanup: + System.setErr(originalErr) + } + + def 'recursive filtering visits every throwable in the cause chain and sanitizes each'() { given: 'a cause chain with both application and internal stack frames' def filterer = new CountingStackTraceFilterer() def rootCause = new IllegalStateException('root cause') @@ -134,9 +188,9 @@ class StackTraceFiltererSpec extends Specification { when: 'recursive filtering is applied to the top-level exception' filterer.filter(exception, true) - then: 'the full stack trace logging path is invoked only for the top-level exception' - filterer.singleExceptionFilterInvocations == 1 - filterer.filteredSources == [exception] + then: 'filter is invoked once per throwable in the cause chain, in cause-chain order' + filterer.singleExceptionFilterInvocations == 3 + filterer.filteredSources == [exception, wrappedCause, rootCause] and: 'application stack frames are retained across the full cause chain' with(exception) { From 7678cf4ca00ee2823c0fa4369233611683515729 Mon Sep 17 00:00:00 2001 From: Scott Murphy Heiberg Date: Sat, 11 Apr 2026 14:01:17 -0700 Subject: [PATCH 5/6] add grails.exceptionresolver.logFullStackTrace opt-in for pre-filter StackTrace logger --- .../main/groovy/grails/config/Settings.groovy | 7 ++ .../web/errors/GrailsExceptionResolver.java | 20 ++++ .../errors/GrailsExceptionResolverSpec.groovy | 99 ++++++++++++++++++- 3 files changed, 125 insertions(+), 1 deletion(-) diff --git a/grails-core/src/main/groovy/grails/config/Settings.groovy b/grails-core/src/main/groovy/grails/config/Settings.groovy index 004c66acede..b94754381ce 100644 --- a/grails-core/src/main/groovy/grails/config/Settings.groovy +++ b/grails-core/src/main/groovy/grails/config/Settings.groovy @@ -236,6 +236,13 @@ interface Settings { * The parameters to exclude from logging */ String SETTING_EXCEPTION_RESOLVER_PARAM_EXCLUDES = 'grails.exceptionresolver.params.exclude' + /** + * Whether the exception resolver should also emit the exception on the separate + * {@code StackTrace} logger in addition to its own request-context log entry. + * Defaults to {@code false}; set to {@code true} to restore the historical two-logger + * behaviour, which allows routing the trace to a separate appender via logback config. + */ + String SETTING_LOG_FULL_STACKTRACE = 'grails.exceptionresolver.logFullStackTrace' /** * The class to use for stacktrace filtering. Should be an instanceof {@link org.grails.exceptions.reporting.StackTraceFilterer} */ diff --git a/grails-web-mvc/src/main/groovy/org/grails/web/errors/GrailsExceptionResolver.java b/grails-web-mvc/src/main/groovy/org/grails/web/errors/GrailsExceptionResolver.java index 9d41a20e928..950df66ab4f 100644 --- a/grails-web-mvc/src/main/groovy/org/grails/web/errors/GrailsExceptionResolver.java +++ b/grails-web-mvc/src/main/groovy/org/grails/web/errors/GrailsExceptionResolver.java @@ -89,6 +89,8 @@ public ModelAndView resolveException(HttpServletRequest request, HttpServletResp ex = findWrappedException(ex); + logFullStackTraceIfEnabled(ex); + filterStackTrace(ex); ModelAndView mv = super.resolveException(request, response, handler, ex); @@ -261,6 +263,24 @@ protected void logStackTrace(Exception e, HttpServletRequest request) { LOG.error(getRequestLogMessage(e, request), e); } + /** + * When the {@code grails.exceptionresolver.logFullStackTrace} property is enabled, + * emits the unfiltered stack trace to the dedicated {@code StackTrace} logger. + * Must be invoked before {@link #filterStackTrace(Exception)} — once the + * filterer calls {@code setStackTrace(clean)}, the original frames are gone and + * this method can only log the already-trimmed trace. + */ + protected void logFullStackTraceIfEnabled(Exception e) { + if (shouldLogFullStackTrace()) { + DefaultStackTraceFilterer.STACK_LOG.error(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE, e); + } + } + + protected boolean shouldLogFullStackTrace() { + Config config = grailsApplication != null ? grailsApplication.getConfig() : null; + return config != null && config.getProperty(Settings.SETTING_LOG_FULL_STACKTRACE, Boolean.class, false); + } + protected Exception findWrappedException(Exception e) { if ((e instanceof InvokerInvocationException) || (e instanceof GrailsMVCException)) { Throwable t = getRootCause(e); diff --git a/grails-web-mvc/src/test/groovy/org/grails/web/errors/GrailsExceptionResolverSpec.groovy b/grails-web-mvc/src/test/groovy/org/grails/web/errors/GrailsExceptionResolverSpec.groovy index 0ef3ea062c9..6e38c6d3276 100644 --- a/grails-web-mvc/src/test/groovy/org/grails/web/errors/GrailsExceptionResolverSpec.groovy +++ b/grails-web-mvc/src/test/groovy/org/grails/web/errors/GrailsExceptionResolverSpec.groovy @@ -18,8 +18,11 @@ */ package org.grails.web.errors +import grails.config.Config +import grails.core.GrailsApplication import grails.web.mapping.UrlMappingsHolder import grails.web.mapping.exceptions.UrlMappingException +import org.grails.exceptions.reporting.DefaultStackTraceFilterer import org.springframework.mock.web.MockHttpServletRequest import spock.lang.Specification @@ -43,4 +46,98 @@ class GrailsExceptionResolverSpec extends Specification { noExceptionThrown() params.isEmpty() } -} \ No newline at end of file + + void "logStackTrace emits only the resolver log"() { + given: "Captured System.err" + def originalErr = System.err + def baos = new ByteArrayOutputStream() + System.setErr(new PrintStream(baos, true)) + + and: "A resolver with no grailsApplication wired" + def resolver = new GrailsExceptionResolver() + def request = new MockHttpServletRequest('GET', '/test') + def exception = new RuntimeException('boom') + + when: + resolver.logStackTrace(exception, request) + + then: "Only the GrailsExceptionResolver logger emits; StackTrace logger is silent" + System.err.flush() + def captured = baos.toString() + captured.contains('o.g.web.errors.GrailsExceptionResolver') || + captured.contains('org.grails.web.errors.GrailsExceptionResolver') + !captured.contains('ERROR StackTrace ') + + cleanup: + System.setErr(originalErr) + } + + void "logFullStackTraceIfEnabled is a no-op when the opt-in property is unset"() { + given: "Captured System.err" + def originalErr = System.err + def baos = new ByteArrayOutputStream() + System.setErr(new PrintStream(baos, true)) + + and: "A resolver with no grailsApplication wired" + def resolver = new GrailsExceptionResolver() + def exception = new RuntimeException('boom') + + when: + resolver.logFullStackTraceIfEnabled(exception) + + then: "No StackTrace log entry is emitted" + System.err.flush() + !baos.toString().contains('ERROR StackTrace ') + + cleanup: + System.setErr(originalErr) + } + + void "logFullStackTraceIfEnabled emits the unfiltered trace when opt-in is enabled, and filterStackTrace then removes internal frames so the resolver log only sees the filtered trace"() { + given: "Captured System.err" + def originalErr = System.err + def baos = new ByteArrayOutputStream() + System.setErr(new PrintStream(baos, true)) + + and: "A resolver whose config opts in to full stack trace logging" + def config = Mock(Config) + config.getProperty('grails.exceptionresolver.logFullStackTrace', Boolean, false) >> true + config.getProperty('grails.exceptionresolver.logRequestParameters', Boolean, _) >> false + config.getProperty('grails.logging.stackTraceFiltererClass', Class, _) >> + DefaultStackTraceFilterer + def grailsApp = Mock(GrailsApplication) + grailsApp.getConfig() >> config + def resolver = new GrailsExceptionResolver() + resolver.grailsApplication = grailsApp + + and: "An exception with a mix of internal (filterable) and application frames" + def exception = new RuntimeException('boom') + exception.stackTrace = [ + new StackTraceElement('java.lang.reflect.Method', 'invoke', 'Method.java', 580), + new StackTraceElement('com.example.MyController', 'show', 'MyController.groovy', 10), + ] as StackTraceElement[] + def request = new MockHttpServletRequest('GET', '/test') + + when: "The real resolveException ordering runs: log full trace, filter, then log with request context" + resolver.logFullStackTraceIfEnabled(exception) + resolver.filterStackTrace(exception) + resolver.logStackTrace(exception, request) + + then: "Both loggers emit" + System.err.flush() + def captured = baos.toString() + captured.contains('ERROR StackTrace ') + captured.contains('Full Stack Trace:') + captured.contains('o.g.web.errors.GrailsExceptionResolver') || + captured.contains('org.grails.web.errors.GrailsExceptionResolver') + + and: "The application frame appears in both log entries" + captured.count('com.example.MyController.show(MyController.groovy:10)') == 2 + + and: "The internal frame appears only once — in the unfiltered StackTrace entry, not in the filtered resolver entry" + captured.count('java.lang.reflect.Method.invoke(Method.java:580)') == 1 + + cleanup: + System.setErr(originalErr) + } +} From 2963cd98222ddeddf4ad4bc35a7fff680be4f2a8 Mon Sep 17 00:00:00 2001 From: Scott Murphy Heiberg Date: Sat, 11 Apr 2026 14:01:22 -0700 Subject: [PATCH 6/6] document grails.exceptionresolver.logFullStackTrace --- .../logging/loggingFullStackTraces.adoc | 88 +++++++++++++++++++ grails-doc/src/en/guide/index.adoc | 5 ++ grails-doc/src/en/guide/toc.yml | 1 + 3 files changed, 94 insertions(+) create mode 100644 grails-doc/src/en/guide/conf/config/logging/loggingFullStackTraces.adoc diff --git a/grails-doc/src/en/guide/conf/config/logging/loggingFullStackTraces.adoc b/grails-doc/src/en/guide/conf/config/logging/loggingFullStackTraces.adoc new file mode 100644 index 00000000000..74703c56a5f --- /dev/null +++ b/grails-doc/src/en/guide/conf/config/logging/loggingFullStackTraces.adoc @@ -0,0 +1,88 @@ +//// +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 + +https://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. +//// + +When a request-handling exception reaches `GrailsExceptionResolver`, Grails emits a single log record to the +`org.grails.web.errors.GrailsExceptionResolver` logger at `ERROR` level. That record contains the HTTP method and +request URI alongside a _filtered_ stack trace — framework internals such as `java.lang.reflect`, `jakarta.servlet`, +`org.codehaus.groovy.runtime`, and similar dispatch/plumbing frames are trimmed out so that application code is the +first thing visible on the trace. + +For most operational use the filtered trace is what you want: it surfaces the application frames that actually matter +and keeps the log readable. For cases that need the untrimmed trace — routing the raw frames to a separate audit +file, correlating with an APM tool, or debugging dispatcher internals — Grails exposes an opt-in: + +[source, yaml] +.grails-app/conf/application.yml +---- +grails: + exceptionresolver: + logFullStackTrace: true +---- + +The setting defaults to `false`. + +When enabled, Grails emits an additional log record to a dedicated logger named `StackTrace`, containing the +_unfiltered_ stack trace as it was captured at throw time. This record is written _before_ the filter step runs, +so no frames are lost. Each request-handling exception therefore produces two log records: + +* A `StackTrace` logger record with the full, unfiltered trace (header `Full Stack Trace:`). +* A `GrailsExceptionResolver` logger record with the filtered trace and the request-context headline +(` occurred when processing request: [] `). + +The two records carry different trace content — that is the value of the opt-in. The `StackTrace` record includes +every reflection, dispatch, and servlet frame; the `GrailsExceptionResolver` record shows only application code. + +==== Routing the StackTrace Logger To a Separate Appender + +Enabling `logFullStackTrace` alone will cause the unfiltered trace to appear on whatever appender the root logger +is configured with — typically the console — in addition to the filtered trace from the resolver logger. If that is +not what you want, pair the opt-in with a Logback configuration that routes the `StackTrace` logger to its own +appender and disables additivity so it does not bubble up to the root: + +[source, xml] +.grails-app/conf/logback.xml +---- + + logs/stacktraces.log + + %date %msg%n%ex%n + + + + + + +---- + +With this configuration the unfiltered trace is written only to `logs/stacktraces.log`, which you can rotate and +retain independently. The console continues to show the concise, filtered resolver record as before. + +==== Suppressing the StackTrace Logger + +Setting the `StackTrace` logger level to `OFF` in Logback makes the opt-in a no-op, regardless of the +`logFullStackTrace` property value: + +[source, xml] +.grails-app/conf/logback.xml +---- + +---- + +This is useful if the property is enabled in a shared `application.yml` but a particular environment needs to +silence the extra record. diff --git a/grails-doc/src/en/guide/index.adoc b/grails-doc/src/en/guide/index.adoc index 323a3efd2eb..588a469b2a3 100644 --- a/grails-doc/src/en/guide/index.adoc +++ b/grails-doc/src/en/guide/index.adoc @@ -165,6 +165,11 @@ include::conf/config/logging/loggerName.adoc[] include::conf/config/logging/maskingRequestParametersFromStacktraceLogs.adoc[] +[[loggingFullStackTraces]] +===== Logging Full Stack Traces + +include::conf/config/logging/loggingFullStackTraces.adoc[] + [[externalLoggingConfiguration]] ===== External Logging Configuration diff --git a/grails-doc/src/en/guide/toc.yml b/grails-doc/src/en/guide/toc.yml index e2aa4687128..9b04b5e7118 100644 --- a/grails-doc/src/en/guide/toc.yml +++ b/grails-doc/src/en/guide/toc.yml @@ -52,6 +52,7 @@ conf: title: Logging loggerName: Logger Names maskingRequestParametersFromStacktraceLogs: Masking Request Parameters From Stacktrace Logs + loggingFullStackTraces: Logging Full Stack Traces externalLoggingConfiguration: External Configuration File configGORM: GORM proxyConfig: Configuring an HTTP proxy