codeconsole commented on PR #16220: URL: https://github.com/apache/grails-core/pull/16220#issuecomment-5414510946
## The failing run on this branch is #16217 [SiteMesh 2 Functional Tests (Java 21, indy=false)](https://github.com/apache/grails-core/actions/runs/32830492513/job/97747841675) failed on `:grails-test-examples-scaffolding:integrationTest` - `UserControllerSpec > User list`, `WaitTimeoutException` after 30 seconds at `LoginPage.groovy:48`. Three tests in that task, one failed; the build otherwise ran to completion under `--continue`. That is not a regression from this branch. It is #16217 occurring on the branch that instruments it, and the instrumentation caught it. What follows is the first evidence on this issue beyond a client-side stack trace. ## What the browser held Three logins ran back to back in the same test JVM against the same application. The two that passed: ``` [16217] login page loaded: JSESSIONID#[email protected]/ [16217] about to submit: JSESSIONID#[email protected]/ [16217] signed in: JSESSIONID#[email protected]/ url=.../book/index?continue [16217] login page loaded: JSESSIONID#[email protected]/ [16217] about to submit: JSESSIONID#[email protected]/ [16217] signed in: JSESSIONID#[email protected]/ url=.../community/user/index?continue ``` The one that failed: ``` [16217] login page loaded: JSESSIONID#[email protected]/ [16217] about to submit: JSESSIONID#[email protected]/ [16217] login page never left: JSESSIONID#[email protected]/ url=.../login ``` ## What that settles The description offered three explanations: no cookie was issued, one was issued for another host, or one was issued and then lost. **None of them holds.** A cookie was issued, it carried the right domain and path, and it was still held - unchanged, same hash - for the full thirty seconds after the submit. What is absent is the change both successful logins show. `#24f8c0a2 -> #a5eefb0a` and `#3802ec7f -> #60614cd` are session fixation protection rotating the session on successful authentication. The failing login's session never rotated, so Spring Security never authenticated anyone. The url is consistent with that. This application has no `SecurityFilterChain` of its own, so Spring Boot's default form login applies and a rejected credential redirects to `/login?error`. The browser sat on `/login` with no query string at all. So the fault is upstream of the cookie, and two possibilities remain: 1. the POST never left the browser - `loginButton.click()` returned without navigating; 2. the POST arrived and something answered with the login page again. The report as it stood cannot separate those two. ## Why it could not go further Two pieces of evidence existed on the runner and neither reached us. **The server half never ran.** The `org.springframework.security` DEBUG logger this branch added sits inside `<springProfile name="development">`. Integration tests run under the `test` profile - `GrailsApp` does `environment.addActiveProfile(env.name)`, and the banner in this same log reads `in environment: test` - so the logger was never applied and `<root level="ERROR">` silenced it. Across 49,134 lines of job log there is not one `org.springframework.security` line, against 4,284 DEBUG lines from other applications. The question that would have settled it, *did the POST reach the filter chain*, went unasked. **The page was captured and then discarded.** `UserControllerSpec` is annotated `@ContainerGebConfiguration(reporting = true)`, and `GebOnFailureReporter` calls `testManager.reportFailure()`, so Geb wrote the page source and a screenshot of the failing browser into `build/geb-reports`. `gradle.yml` uploads that directory on failure; `sitemesh2.yml` had no upload step at all, so on this workflow it dies with the runner. ## Changes **`logback-spring.xml`** - the security logger moves out of the `development` profile block, so it applies under `test`. `UserControllerSpec` run locally now produces the server half: ``` DEBUG o.s.security.web.FilterChainProxy : Securing POST /login DEBUG o.s.s.a.dao.DaoAuthenticationProvider : Authenticated user DEBUG .s.ChangeSessionIdAuthenticationStrategy : Changed session id from 7E63940B... DEBUG o.s.s.web.DefaultRedirectStrategy : Redirecting to .../user/index?continue ``` `Securing POST /login` is the line that settles it. Present at the next occurrence, the request reached the filter chain and the answer is on the server; absent, the submit never left the browser. **`sitemesh2.yml`** - uploads `**/build/geb-reports/` on failure, matching what `gradle.yml` already does for the same suites. The page and screenshot from a failure on this workflow now survive the job. **`LoginPage`** - each report carries `form=`: `retained` when the username field still holds what was typed, `empty` when the field is there but blank, `gone` when it is absent. On a passing login that reads `empty -> retained -> gone`. A `retained` at the failure means the document was never replaced and the POST did not leave the browser; an `empty` means a new login page was served, so it did. That separates the two remaining possibilities without waiting on the server logs. One asymmetry worth naming: the client-side report hashes session ids deliberately, and Spring Security at DEBUG prints them in full. These are sessions of a throwaway test application with hardcoded credentials, running in a container for the length of one test, so there is nothing there to protect - but it is not the same standard on both sides, and it is another reason this logger comes out when #16217 closes. Each change remains revertible on its own. -- 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]
