codeconsole opened a new pull request, #16220: URL: https://github.com/apache/grails-core/pull/16220
Instrumentation for the three CI flakes that are currently untraceable: #16217, #16218 and #16219. No production code, no behaviour change, and each piece removable when its issue closes. They are together rather than in three pull requests because each run of this branch exercises all three, and these failures are rare enough that coverage per run is what decides whether the next one is diagnosable. ## Why instrumentation rather than a fix Each of the three has occurrences but no evidence beyond a client-side stack trace, and each has already had a fix proposed on a mechanism that turned out to be wrong. What follows is designed to make the *next* occurrence say which layer is responsible - not to guess at it now. ## #16219 - a request that never answers `AsyncPromiseSpec` fails with `HttpTimeoutException` after 120 seconds against `/asyncTest/useAsyncService`, an action that waits on a future for five seconds and answers. Four occurrences, three different features, two applications, one of them on `8.0.x`; all say only that the client gave up. An integration test runs the application in the test's own JVM, so the threads that would serve the request are available to be asked. A request that passes 90 seconds now prints every thread in the JVM while it is *still outstanding*; after the client times out, those threads have moved on. Every request also carries `X-Grails-Test-Correlation-Id`. That distinguishes: never served, queued and starved, blocked in the controller, or answered but not read. - `-Dgrails.http.client.diagnostics=false` turns it off; `-Dgrails.http.client.diagnostics.seconds` moves the threshold. - The timer thread is a daemon deliberately - a build has already hung on a test JVM that could not exit (#16218). **Checked:** with the threshold at zero, 17 reports, 36 threads each including Tomcat's acceptor and every `http-nio-auto-1-exec-*`. With it at one second, none, because no request was that slow. 800 functional tests pass unchanged either way. ## #16217 - a login form submitted without a session The page captured at that failure is a fresh login form: empty fields, no error. Three explanations fit it and the page cannot tell them apart - no cookie was issued, one was issued for another host, or one was issued and then lost. The browser is now reported at three moments - login page loaded, about to submit, and whatever follows - with cookie names, hashes, domain and path, plus the url. Hashed rather than printed: enough to see a session replaced or lost, without putting a session id in a public log. Spring Security logs at debug in this application for the server half. **Checked**, on a passing run: ``` [16217] login page loaded: url=.../login cookies=[JSESSIONID#[email protected]/] [16217] about to submit: url=.../login cookies=[JSESSIONID#[email protected]/] [16217] signed in: url=.../book/index?continue cookies=[JSESSIONID#5289051f@...] ``` The same session through the submit, a new one after it - session fixation protection working. A failure will differ in exactly one of those places. ## #16218 - a build that stops after its last task Twice this job has stopped producing output after `:grails-test-examples-aot:check` and held a runner to the six hour ceiling, leaving only the process list the runner prints while cleaning up. A step placed after the build cannot help: while the build is hung, a later step never arrives. The watchdog is therefore armed *before* it, sleeps past the point where the job should have finished, and reports every JVM twice a minute apart - command line, heap, threads with locks - plus the process tree and the tail of the Gradle daemon logs. One dump says what a thread is doing; two say whether it is doing anything at all. The job is also capped at `timeout-minutes: 120`. It normally finishes in 40 to 65 minutes, so a hang costs a fifth of what it did, and the watchdog has reported long before. Its output is printed by a step marked `always()`, which is reached when the cap cancels the job. **Checked:** the script runs locally, finds the JVMs through `jps` and dumps them; `./gradlew validateActions` passes and the workflow parses with the steps in the intended order. ## Removing it Each commit is self-contained and revertible on its own. When an issue closes, its commit goes. -- 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]
