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: [email protected]
For queries about this service, please contact Infrastructure at:
[email protected]
