You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@grails.apache.org by "borinquenkid (via GitHub)" <gi...@apache.org> on 2026/07/29 20:59:13 UTC

[PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

borinquenkid opened a new pull request, #16067:
URL: https://github.com/apache/grails-core/pull/16067

   ## Summary
   
   `GrailsUtilStackFiltererSpec` and `GrailsBootstrapRegistryInitializerSpec` each have a positive-control
   test asserting that `DefaultStackTraceFilterer` emits a `Full Stack Trace:` message by default. Both
   capture that output by swapping `System.err` for a `ByteArrayOutputStream` around the call.
   
   `DefaultStackTraceFilterer.STACK_LOG` is obtained via commons-logging
   (`LogFactory.getLog(STACK_LOG_NAME)`), which on this classpath resolves to a jcl-over-slf4j binding
   (`SLF4JLocationAwareLog`) rather than a bare console writer. The message is routed through SLF4J/Logback,
   so it never reaches `System.err` at all -- the `System.err` swap never observes anything, regardless of
   timing or test ordering. This makes the two "emits by default" tests fail deterministically:
   
   ```
   Condition not satisfied:
   baos.toString().contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE)
   |    |          |        |
   |    ""         false
   ```
   
   This is reproducible on plain `8.0.x` today (no other changes needed) and is not related to any
   in-flight feature branch -- it surfaced as a CI failure on PR #16066 simply because that PR's CI run
   happened to exercise this module's full test suite.
   
   - Replaced the `System.err` capture in both tests with a Logback `ListAppender` attached directly to
     the `StackTrace` logger (`DefaultStackTraceFilterer.STACK_LOG_NAME` -- a public constant exposed
     specifically so tests and logging config can hook into it), detached in `cleanup`.
   - No production code changes; behavior of `DefaultStackTraceFilterer` is unchanged.
   
   ## Test plan
   
   - [x] `:grails-core:test --tests grails.util.GrailsUtilStackFiltererSpec --tests org.apache.grails.core.GrailsBootstrapRegistryInitializerSpec` -- all pass
   - [x] `:grails-core:test` (full module) -- all pass
   - [x] `:grails-core:codeStyle` -- passes
   
   🤖 Generated with [Claude Code](https://claude.com/claude-code)


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "Copilot (via GitHub)" <gi...@apache.org>.
Copilot commented on code in PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#discussion_r3678006622


##########
grails-core/src/test/groovy/org/apache/grails/core/GrailsBootstrapRegistryInitializerSpec.groovy:
##########
@@ -225,39 +229,54 @@ class GrailsBootstrapRegistryInitializerSpec extends Specification {
         def context = contextWithProperties([
                 (Settings.SETTING_LOG_FULL_STACKTRACE_ON_FILTER): 'false'
         ])
-        def originalErr = System.err
-        def baos = new ByteArrayOutputStream()
-        System.setErr(new PrintStream(baos, true))
+        def appender = attachRecordingAppender()
 
         when:
         closeBootstrapContext(context)
         GrailsUtil.deepSanitize(exceptionWithApplicationFrame())
 
         then: "no 'Full Stack Trace:' entry is emitted"
-        System.err.flush()
-        !baos.toString().contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE)
+        appender.list.every { !it.formattedMessage.contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE) }
 
         cleanup:
-        System.setErr(originalErr)
+        detachAppender(appender)
     }
 
     def 'defaults logFullStackTraceOnFilter to true on the promoted DefaultStackTraceFilterer'() {
         given:
         def context = contextWithProperties([:])
-        def originalErr = System.err
-        def baos = new ByteArrayOutputStream()
-        System.setErr(new PrintStream(baos, true))
+        def appender = attachRecordingAppender()
 
         when:
         closeBootstrapContext(context)
         GrailsUtil.deepSanitize(exceptionWithApplicationFrame())
 
         then: 'the positive control proving the negative case above is meaningful'
-        System.err.flush()
-        baos.toString().contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE)
+        appender.list.any { it.formattedMessage.contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE) }
 
         cleanup:
-        System.setErr(originalErr)
+        detachAppender(appender)
+    }
+
+    /**
+     * {@link DefaultStackTraceFilterer#STACK_LOG} routes through commons-logging, which on this
+     * classpath resolves to a jcl-over-slf4j binding rather than a bare console writer -- so the
+     * emitted message never touches {@code System.err} for capture there. The logger name is a
+     * public constant precisely so tests and logging config can attach to it directly instead.
+     */
+    private static ListAppender<ILoggingEvent> attachRecordingAppender() {
+        def logger = LoggerFactory.getLogger(DefaultStackTraceFilterer.STACK_LOG_NAME) as Logger
+        def appender = new ListAppender<ILoggingEvent>()

Review Comment:
   This spec introduces custom Logback ListAppender attach/detach helpers. There is already an established test fixture for capturing Logback output in this module: org.apache.grails.core.testing.support.LogCapture (see grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy). Using LogCapture here would avoid duplicating helper logic and ensures logger level/additivity are restored after the test, keeping the suite more consistent and resilient to logging config changes.



##########
grails-core/src/test/groovy/grails/util/GrailsUtilStackFiltererSpec.groovy:
##########
@@ -139,11 +138,31 @@ class GrailsUtilStackFiltererSpec extends Specification {
         GrailsUtil.deepSanitize(exceptionWithApplicationFrame())
 
         then: "a 'Full Stack Trace:' entry is emitted -- the positive control proving the negative case above is meaningful"
-        System.err.flush()
-        baos.toString().contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE)
+        appender.list.any { it.formattedMessage.contains(StackTraceFilterer.FULL_STACK_TRACE_MESSAGE) }
 
         cleanup:
-        System.setErr(originalErr)
+        detachAppender(appender)
+    }
+
+    /**
+     * {@link DefaultStackTraceFilterer#STACK_LOG} routes through commons-logging, which on this
+     * classpath resolves to a jcl-over-slf4j binding rather than a bare console writer -- so the
+     * emitted message never touches {@code System.err} for capture there. The logger name is a
+     * public constant precisely so tests and logging config can attach to it directly instead.
+     */
+    private static ListAppender<ILoggingEvent> attachRecordingAppender() {
+        def logger = LoggerFactory.getLogger(DefaultStackTraceFilterer.STACK_LOG_NAME) as Logger
+        def appender = new ListAppender<ILoggingEvent>()

Review Comment:
   This spec adds custom Logback ListAppender attach/detach helpers, but grails-core already provides a reusable test fixture for this: org.apache.grails.core.testing.support.LogCapture (see grails-core/src/test/groovy/org/grails/exception/reporting/StackTraceFiltererSpec.groovy). Reusing LogCapture would remove duplicated helper code, and it also normalizes logger level/additivity and restores prior logger state on close, keeping tests better isolated from logging configuration changes.



-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "codecov[bot] (via GitHub)" <gi...@apache.org>.
codecov[bot] commented on PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#issuecomment-5805255575

   ## [Codecov](https://app.codecov.io/gh/apache/grails-core/pull/16067?dropdown=coverage&src=pr&el=h1&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache) Report
   :white_check_mark: All modified and coverable lines are covered by tests.
   :white_check_mark: Project coverage is 57.4364%. Comparing base ([`2da4fa1`](https://app.codecov.io/gh/apache/grails-core/commit/2da4fa140b0a59ff4ae2b1e2a2c428a6f0187ae2?dropdown=coverage&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)) to head ([`64da415`](https://app.codecov.io/gh/apache/grails-core/commit/64da4159997dc2d91d046bf7652330d13bea2692?dropdown=coverage&el=desc&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)).
   :warning: Report is 11 commits behind head on 8.0.x.
   
   <details><summary>Additional details and impacted files</summary>
   
   
   
   [![Impacted file tree graph](https://app.codecov.io/gh/apache/grails-core/pull/16067/graphs/tree.svg?width=650&height=150&src=pr&token=qJrryhpk7u&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)](https://app.codecov.io/gh/apache/grails-core/pull/16067?src=pr&el=tree&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)
   
   ```diff
   @@                Coverage Diff                 @@
   ##                8.0.x     #16067        +/-   ##
   ==================================================
   - Coverage     57.4384%   57.4364%   -0.0019%     
     Complexity      22555      22555                
   ==================================================
     Files            2129       2129                
     Lines          103840     103840                
     Branches        18646      18646                
   ==================================================
   - Hits            59644      59642         -2     
   - Misses          35935      35938         +3     
   + Partials         8261       8260         -1     
   ```
   [see 5 files with indirect coverage changes](https://app.codecov.io/gh/apache/grails-core/pull/16067/indirect-changes?src=pr&el=tree-more&utm_medium=referral&utm_source=github&utm_content=comment&utm_campaign=pr+comments&utm_term=apache)
   </details>
   <details><summary> :rocket: New features to boost your workflow: </summary>
   
   - :snowflake: [Test Analytics](https://docs.codecov.com/docs/test-analytics): Detect flaky tests, report on failures, and find test suite problems.
   - :package: [JS Bundle Analysis](https://docs.codecov.com/docs/javascript-bundle-analysis): Save yourself from yourself by tracking and limiting bundle sizes in JS merges.
   </details>


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "testlens-app[bot] (via GitHub)" <gi...@apache.org>.
testlens-app[bot] commented on PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#issuecomment-5123691171

   ## 🚨 TestLens detected 1 failed test 🚨
   
   Here is what you can do:
   
   1) Inspect the test failures carefully.
   2) If you are convinced that some of the tests are flaky, you can mute them below.
   3) Finally, trigger a rerun by checking the rerun checkbox.
   
   ### Test Summary
   
   #### [CI / Functional Tests \(Java 21, indy\=true\)](https://github.com/apache/grails-core/actions/runs/30490581773/job/90707184695?pr=16067) > :grails-test-examples-app1:integrationTest
   
   | Test | Runs | Flakiness |
   |---|---|--:|
   | RedirectWithAndWithoutParamsFunctionalSpec > Params are not added to the url after a redirect even if they are passed to the redirect | ❌ | [1%&nbsp;🟡](https://github.com/apache/grails-core/issues/16030) |
   
   🏷️ Commit: 335a5b1f2dde2c6c4fbc6ec2caae322b2beb8c8d
   ▶️ Tests:  18035 executed
   🟡 Checks: 38/55 completed
   
   ### Test Failures
   
   <details>
   
   <summary><strong>RedirectWithAndWithoutParamsFunctionalSpec > Params are not added to the url after a redirect even if they are passed to the redirect</strong> (:grails-test-examples-app1:integrationTest in <a href="https://github.com/apache/grails-core/actions/runs/30490581773/job/90707184695?pr=16067">CI / Functional Tests (Java 21, indy=true)</a>)</summary>
   
   ```
   Condition not satisfied:
   
   pageSource.contains('"id":')
   |          |
   |          false
   <html><head></head><body><form action="save" method="post">
       <input type="text" name="name">
       <input type="submit">
   </form>
   </body></html>
   
   	at functionaltests.RedirectWithAndWithoutParamsFunctionalSpec.$tt__$spock_feature_1_0(RedirectWithAndWithoutParamsFunctionalSpec.groovy:41)
   	at functionaltests.RedirectWithAndWithoutParamsFunctionalSpec.Params are not added to the url after a redirect even if they are passed to the redirect_closure1(RedirectWithAndWithoutParamsFunctionalSpec.groovy)
   	at grails.gorm.transactions.GrailsTransactionTemplate$1.doInTransaction(GrailsTransactionTemplate.groovy:72)
   	at org.springframework.transaction.support.TransactionTemplate.execute(TransactionTemplate.java:137)
   	at grails.gorm.transactions.GrailsTransactionTemplate.executeAndRollback(GrailsTransactionTemplate.groovy:69)
   	at functionaltests.RedirectWithAndWithoutParamsFunctionalSpec.Params are not added to the url after a redirect even if they are passed to the redirect(RedirectWithAndWithoutParamsFunctionalSpec.groovy)
   ```
   
   </details>
   
   ### Muted Tests
   > [!NOTE]
   > Checks are currently running using the configuration below.
   
   Select tests to mute in this pull request:
   
   🔲 RedirectWithAndWithoutParamsFunctionalSpec > Params are not added to the url after a redirect even if they are passed to the redirect <!-- uniqueId=[engine:spock]/[spec:functionaltests.RedirectWithAndWithoutParamsFunctionalSpec]/[feature:$spock_feature_1_0] -->
   
   Reuse successful test results:
   
   🔲 ♻️ Only rerun the tests that failed or were muted before
   
   Click the checkbox to trigger a rerun:
   
   🔲 **Rerun jobs**
   
   ---
   _Learn more about TestLens at [testlens.app](https://testlens.app)._
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "jamesfredley (via GitHub)" <gi...@apache.org>.
jamesfredley commented on PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#issuecomment-5124138929

   Heads up - #16011 was merged (`301b40c20a`), and it carried its own fix for these same two specs, so this PR is now `CONFLICTING` against `8.0.x`.
   
   On `8.0.x` today, `GrailsUtilStackFiltererSpec` and `GrailsBootstrapRegistryInitializerSpec` already capture via the shared `LogCapture` test fixture (`grails-core/src/testFixtures/groovy/org/apache/grails/core/testing/support/LogCapture.groovy`) rather than the inline `attachRecordingAppender()` / `detachAppender()` helpers proposed here. Both approaches were correct; `LogCapture` won on the tiebreak that it already existed and is already the house pattern (`StackTraceFiltererSpec`, `DefaultGrailsPluginManagerSpec`, `PluginDiscoverySpec`, `GlobalGrailsClassInjectorTransformationSpec`), and it additionally forces the logger to `TRACE`, sets `additive = false`, and restores both on `close()` - which is what makes it independent of whatever root level and appender set a given module happens to configure.
   
   Rather than close this, I'd like to repurpose it as the **definitive cleanup** for this failure mode. It has now surfaced two or three separate times, and there is still a live latent instance.
   
   ### 1. Diagnosis is slightly off, and the correction matters
   
   The description attributes the failure to `STACK_LOG` resolving to a jcl-over-slf4j binding so the message "never reaches `System.err` at all." That is true as far as it goes, but it is not the proximate trigger. The actual trigger is `d1c8d0e439` ("test: add deterministic test logging configuration"), which added `grails-core/src/test/resources/logback-test.xml`:
   
   ```xml
   <configuration>
       <root level="WARN" />
   </configuration>
   ```
   
   Root at `WARN` with **zero appenders** - so the event is not merely routed away from `System.err`, it is written nowhere at all.
   
   The evidence that this is the real cause: `GrailsExceptionResolverSpec` in `grails-web-mvc` uses the *identical* `System.setErr` + `captured.contains('Full Stack Trace:')` pattern against the same `STACK_LOG`, and it **passes today**. `grails-web-mvc` has no `src/test/resources` at all, so it falls through to a default console configuration and the capture happens to work. Same binding, same logger, opposite result - the difference is purely the per-module logback test config.
   
   ### 2. Remaining latent instance
   
   `grails-web-mvc/src/test/groovy/org/grails/web/errors/GrailsExceptionResolverSpec.groovy` still has three `System.setErr` capture sites (L59, L84, L270), two of which assert on `StackTrace` logger output including `'Full Stack Trace:'` and the literal `'ERROR StackTrace '` console prefix. That last assertion is coupled to a console appender's *layout pattern*, which is about as brittle as it gets. It will break the same way the moment `grails-web-mvc` gets the same deterministic `logback-test.xml` treatment `grails-core` received.
   
   ### 3. Suggested scope for this PR
   
   1. Convert those three sites in `GrailsExceptionResolverSpec` to `LogCapture`, keyed on `DefaultStackTraceFilterer.STACK_LOG_NAME` and the resolver's own logger, asserting on `formattedMessage` / `level` instead of a rendered console line.
   2. Switch the two already-merged specs from the `'StackTrace'` string literal to `DefaultStackTraceFilterer.STACK_LOG_NAME` - this PR had that right and #16011 did not.
   3. Once no test in the module asserts on incidental console output, roll the deterministic `logback-test.xml` out to `grails-web-mvc` (and ideally the other test modules) so this cannot regress a fourth time. That converts "it happens to pass because this module has no logging config" into "it passes because the test attaches its own appender."
   
   Optionally, a short note in the `LogCapture` javadoc stating that tests must never assert on `System.out`/`System.err` for anything emitted through a logger would give reviewers something concrete to point at.
   
   ### 4. Re: the logging changes that just merged
   
   #15757 (stop scaffolding `logback-spring.xml`, add the opt-in Forge feature) and the earlier content fixes in #15973 are app-generation scope only - they do not touch any module's test classpath, so there is no direct collision with this work. But they do reinforce the same direction: rely on the framework's default logging configuration rather than a checked-in file, and correspondingly stop writing tests that depend on what that default configuration happens to render to a stream.
   
   ### Rebase note
   
   Since the two specs already changed on `8.0.x`, the cleanest path is to rebase onto current `8.0.x` and drop the parts of this diff that #16011 already covers, keeping the constant-vs-literal fix, then add the `grails-web-mvc` conversion and the config rollout on top.
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "jdaugherty (via GitHub)" <gi...@apache.org>.
jdaugherty merged PR #16067:
URL: https://github.com/apache/grails-core/pull/16067


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "borinquenkid (via GitHub)" <gi...@apache.org>.
borinquenkid commented on PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#issuecomment-5308156162

   @jamesfredley nudge


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "testlens-app[bot] (via GitHub)" <gi...@apache.org>.
testlens-app[bot] commented on PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#issuecomment-5125258586

   ## ✅ All tests passed ✅
   
   🏷️ Commit: a8227fdbbba475c5ae53e41d6e59daeced53f4d1
   ▶️ Tests:  49409 executed
   ⚪️ Checks: 60/60 completed
   
   ---
   _Learn more about TestLens at [testlens.app](https://testlens.app)._
   


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org


Re: [PR] fix: capture STACK_LOG output via a Logback appender instead of System.err [grails-core]

Posted by "borinquenkid (via GitHub)" <gi...@apache.org>.
borinquenkid commented on PR #16067:
URL: https://github.com/apache/grails-core/pull/16067#issuecomment-5124511282

   Thanks for the correction and for pushing this further -- addressed all three points:
   
   **1. Diagnosis corrected** -- updated the PR description to point at the actual trigger (`grails-core`'s `logback-test.xml` shipping `root level=\"WARN\"` with zero appenders, so the event goes nowhere, not merely \"routed away from System.err\"). Good catch on `GrailsExceptionResolverSpec` being the control case that proves it.
   
   **2. Rebased** onto current `8.0.x` past #16011's merge. Kept `STACK_LOG_NAME` over the string literal in the two already-landed specs.
   
   **3. `GrailsExceptionResolverSpec` converted** -- all three `System.setErr` sites now use `LogCapture` (one keyed on `GrailsExceptionResolver`, one on `DefaultStackTraceFilterer.STACK_LOG_NAME`). The combined test that used to count substrings in rendered console output (including the brittle `'ERROR StackTrace '` layout match) now inspects each captured `ILoggingEvent`'s `throwableProxy` stack frames directly. This required swapping the module's test logging binding from `slf4j-simple` to `grails-core`'s test fixtures (transitively brings `logback-classic`, which `LogCapture` needs to attach a real Logback `Logger`) -- verified no other test in the module depended on `slf4j-simple` specifically.
   
   Held off on rolling the deterministic `logback-test.xml` out to `grails-web-mvc` itself (your point 3) -- `LogCapture` forces the target logger's own level to `TRACE` and attaches its own appender directly, so the module's tests are now independent of root logger config either way, and adding that file felt like a separate, broader change (affects visible output for every test in the module, not just these). Happy to do it here too if you'd rather bundle it.


-- 
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.

To unsubscribe, e-mail: notifications-unsubscribe@grails.apache.org

For queries about this service, please contact Infrastructure at:
users@infra.apache.org