Repository navigation
HADOOP-19979. Fix four flaky tests that race with work on other threads. - #8717
joseluisll wants to merge 9 commits into
Conversation
|
💔 -1 overall
This message was automatically generated. |
|
💔 -1 overall
This message was automatically generated. |
pan3793
left a comment
There was a problem hiding this comment.
Pre-existing, but the leak fix now relies on it: TimelineReaderServer.serviceStop() calls readerWebServer.stop() before super.serviceStop() with no try/finally. HttpServer2.stop() rethrows its MultiException, and the service is already STOPPED by then so a retry is a no-op, leaving the storage monitor running. try { readerWebServer.stop(); } finally { super.serviceStop(); } closes it; fine as a follow-up if this PR stays test-only.
TestStandbyCheckpoints.java L844: testPutFsimagePartFailed has the same shape: snnCheckpointTime2 is read right after waitForCheckpoint(cluster, 0, [23]) and asserted > snnCheckpointTime1, but nns[1] stamps lastCheckpointTime only after doCheckpoint() returns, which here is after the upload to the stopped nns[2] fails. The same wait fixes it.
|
can some entries in |
Only TestLogAggregationService is listed (line 106); the other three aren't. I will create a new JIRA for GHA exclusions testing improvements and reactivation of fixed tests like TestLogAggregationService. |
TestStandbyCheckpoints.testPutFsimagePartFailed — good catch, it's the same race. Fixed here rather than deferred: nns[2] is shut down in that test, so nns[1] is the uploader and the anchor is the same one used in testLastCheckpointTime — waitForCheckpoint(cluster, 1, ImmutableList.of(23)) followed by a wait on getStandbyLastCheckpointTime() moving past the baseline. TimelineReaderServer.serviceStop() — fixed here too, since the leak fix depends on it: try { readerWebServer.stop(); } finally { super.serviceStop(); }, so a web server that fails to stop can't leave the storage monitor's polling executor behind. |
|
💔 -1 overall
This message was automatically generated. |
|
💔 -1 overall
This message was automatically generated. |
|
Debugging the errors reported by Yetus, I have created two subtasks for the "HADOOP-19979 Fix four tests that assert on work owned by another thread", PR-8717:
@pan3793 @slfan1989 @Hexiaoqiao I will attach PR to both subtasks. The order to solve this is to solve 19986, then solve 19987, rebase 19979 to trunk including those fixes, then solve 19979. Another alternative can be to solve and merge independently. |
…erMTLS. Two tests assert on work that finishes on another thread, without waiting for it. Both fail intermittently. TestSSLHttpServerMTLS.testUntrustedClientIsRejected expects an SSLHandshakeException. The server drops the connection as soon as it rejects the client certificate, racing the client's last handshake flight; when the close wins, the client fails writing it and gets a SocketException instead. 7 of 25 runs fail. The server guarantees the request is refused, not which exception the client sees, so assert that. TestLogAggregationService.testLocalFileDeletionAfterUpload waits for each log file to disappear, then asserts on the enclosing directory with no wait. DeletionService removes files before the directories holding them, so the assertion can run in between. Hit 4 of the 60 most recent PRs, including unrelated ones. Wait for the directory too. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
The test waits for the active to hold the new image and then reads a standby's checkpoint time, which that wait says nothing about. Every standby builds its own checkpoint and any of them may be the one that uploads it, so the active holding image 23 does not mean nns[1] was involved. The standby that did upload stamps its own lastCheckpointTime only after doCheckpoint() has returned, while the active stamps its own while it is still receiving the upload inside that call. Either way nns[1] can still be reporting the previous checkpoint when the test reads it, and the interval comes out as zero against an expected 3000. Instrumented, a failing run reads a standby interval of 0 where a passing one reads 4242, and the same value is 7272 five seconds later. Waiting for it to move first turns that run into a pass. It reproduced 2 times in 20 unloaded runs, and once in 6 with the box oversubscribed. Waiting on the standby is enough for both: the active's time is stamped during the upload, inside the same doCheckpoint() that the standby only stamps after, so it has always moved by then. Also split the compound assertion so a failure reports which side missed and by how much, rather than just expected true but was false. Co-Authored-By: Claude <noreply@anthropic.com>
The five tests each start a TimelineReaderServer and none of them stop it. Starting the server starts an HBaseTimelineReaderImpl, whose serviceStart schedules a TimelineStorageMonitor; serviceStop, reached only through the server, is the one thing that cancels it. So every test leaves behind a scheduled executor polling healthCheck() against the minicluster the test then tears down, and those threads are not daemons. The module builds with forkCount 0, so its eleven test classes share the Maven JVM and the leaks accumulate across the whole run. A failing run of the "other" shard dumped 337 threads, among them fourteen copies of each minicluster's regionserver chores and monitor threads stuck in HBaseStorageMonitor.healthCheck -> locateRegionInMeta, retrying against clusters that had already gone. The tests also set the monitor interval to 5s rather than the 60s default, so each leaked monitor polls twelve times as often. Every other test in the module already stops what it starts, through AbstractTimelineReaderHBaseTestBase, TestTimelineWriterHBaseDown or DataGeneratorForTest. This one was the exception. Stop the server in a finally, before the minicluster goes down so the monitor is not still scanning while HBase is torn down underneath it. That needs the server hoisted out of the try, and one test that had no finally at all now gets one. Instrumented, the class starts 9 monitors and now stops all 9. Co-Authored-By: Claude <noreply@anthropic.com>
Review feedback on the earlier leak fix: stopping the server as the first unguarded statement of the finally block can itself throw, and then util.shutdownMiniCluster() never runs. AbstractService.stop() rethrows a serviceStop() failure as a ServiceStateException, and TimelineStorageMonitor.stop() throws InterruptedException out of awaitTermination if a @timeout interrupt lands there. The base code reached shutdownMiniCluster() unconditionally, so that traded a leaked storage monitor for a leaked minicluster. Use ServiceOperations.stopQuietly(), the existing null-safe helper, and drop the local stopServer() wrapper. The server is now built before the try block rather than assigned inside it, so the finally can see it without a null local; a server whose init() never ran is still safe to stop, since uninited -> stopped is a legal transition in ServiceStateModel. The explanation of what the stop is for moves to the class javadoc. Also guard TimelineReaderServer.serviceStop() itself: super.serviceStop() is what stops the reader and, with it, the storage monitor's polling executor, so a readerWebServer.stop() that throws must not skip it. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Review feedback on the earlier testLastCheckpointTime fix. Waiting only for the standby's lastCheckpointTime to move does not tie the reading to the checkpoint the test cares about. doWork() stamps the time after every doCheckpoint() call, including the "Skipping..." early return taken when no new transactions arrived, so the timestamp can also advance on a period tick that checkpointed nothing. Wait for nns[1] to hold checkpoint 23 first. This costs nothing at runtime: the existing wait on nns[0] already implies the standby saved 23 locally before uploading it. The anchor narrows that window rather than closing it. The image is saved inside doCheckpoint() while the stamp happens after it returns, so a reading taken between the two still sees the previous stamp. The assertion holds either way: a tick only stamps once the period has elapsed, and the transaction threshold of 1000 is out of reach for nine edits, so any advance at all is already at least one period wide. The active's time cannot be inferred from the standby's either. FSImage does the rename that waitForCheckpoint observes and only then stamps mostRecentCheckpointInfo, in the same saveDigestAndRenameCheckpointImage the active runs on receiving the upload, so wait for it in its own right. Correct the comment while here: nns[2] is transitioned to observer before the edits, and startStandbyServices creates a StandbyCheckpointer only when the node is not an observer, so nns[1] is the only possible uploader. The gap is between ImageServlet stamping the active during the upload and nns[1] stamping itself once doCheckpoint() returns. testPutFsimagePartFailed reads the standby's stamp straight after the same waitForCheckpoint and races the same way; give it the same anchor. Use the four-argument GenericTestUtils.waitFor throughout. waitFor throws on timeout, so an assertion placed after it is unreachable on the failure path and its message never reaches the report. The overload takes a String built at call time, so the message carries the baseline being compared against but not the value seen at timeout. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
Review feedback on the earlier fixes for these two tests. TestLogAggregationService: the container files and the application directory are removed by two independent FileDeletionTasks, both queued on the DeletionService pool with no ordering between them, so "removes the files before the directories" was not the mechanism -- the directory task can run first or concurrently. Waiting for the application directory subsumes the four per-file waits, since the files live inside it. TestSSLHttpServerMTLS: how the rejection surfaces also depends on the protocol, not only on who wins the race. Under TLSv1.3 the handshake completes client-side before the server has verified the certificate, so the failure lands on the request write as a bare IOException with neither an SSLException nor a SocketException in hand. Assert the refusal and exclude only ConnectException, which is the case that would mean the server was never reached. This is weaker than the SSLException/SocketException pair it replaces, in one way worth naming: SocketTimeoutException extends InterruptedIOException rather than SocketException, so a timeout used to fail this assertion and now passes it. The trade is still worth making, because the assertion it replaces depended on hadoop.ssl.enabled.protocols, and that dependence is the flakiness being removed. A server that wrongly accepted the untrusted certificate is still caught, since getInputStream() would then not throw at all. Both waits now carry their message in the four-argument GenericTestUtils.waitFor, since waitFor throws on timeout and an assertion after it never runs. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
d44411a to
e422800
Compare
|
💔 -1 overall
This message was automatically generated. |
slfan1989
left a comment
There was a problem hiding this comment.
Small documentation nit: could you update “Existing tests; test-only change”
in the PR description?
This patch also changes the production shutdown behavior in
TimelineReaderServer.serviceStop(), so it is no longer a test-only change.
|
Thanks for the review @slfan1989 - all three addressed in 822d705.
You're right, and it was understating the change rather than just mis-wording it. The description now carries the The other two are answered in their threads: |
|
💔 -1 overall
This message was automatically generated. |
… web server stop. getResponseCode() rather than getInputStream() in TestSSLHttpServerMTLS.testUntrustedClientIsRejected: getInputStream() also throws for an HTTP error status, so it would have accepted a 403 or a 500 reached over a handshake the server should have refused. TimelineReaderServer.serviceStop() now stops the web server through stopTimelineReaderWebApp(), a seam a test can make throw, and TestTimelineReaderServer covers that path: the child services - the reader, which owns the storage monitor's polling executor - must still reach STOPPED. Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
822d705 to
56baa14
Compare
|
Force-pushed 56baa14 over the previous 822d705: that commit accidentally carried two build artifacts, That is almost certainly what Yetus tripped on in run 6 ( The PR content is unchanged from what I described in the review threads — it is back to the intended 6 files. Sorry for the noise. |
|
💔 -1 overall
This message was automatically generated. |
…er finish reopening before shutdown. testTimelineReaderRecoversAfterHBaseReturns restarts HBase and waits until the storage monitor reports it up. That only takes one read of the flow activity table, so the test could shut the minicluster down while the region server was still reopening the regions of the other timeline tables. Those opens then failed with RegionServerStoppedException and the region server aborted. An abort schedules a timer that halts the JVM once hbase.regionserver.abort.timeout (20 minutes) passes, and the timer is never cancelled. This module runs with forkCount 0, so that halt took down Maven's own JVM in a later, unrelated module. Wait for no regions to be in transition before shutting down, and set hbase.regionserver.abort.timeout.task to a task that does nothing, so an abort in this in-process module is still logged but can no longer halt the shared JVM. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WyUSFmtLG5L3cfQyz31Ddg
|
💔 -1 overall
This message was automatically generated. |
…final. Checkstyle's FinalClass rule flagged NoOpAbortTimeoutTask: its only constructor is private, so it can never be subclassed and should say so. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com> Claude-Session: https://claude.ai/code/session_01WyUSFmtLG5L3cfQyz31Ddg
|
💔 -1 overall
This message was automatically generated. |
|
This PR touches several components of hadoop, so I cut it down into several JIRAs & PR's, one per component and test. |
Description of PR
Four tests assert on, or tear down around, work owned by another thread without
waiting for it or stopping it. All four fail intermittently.
TestSSLHttpServerMTLS.testUntrustedClientIsRejected(common) expects anSSLHandshakeException, but the server's close races the client's lasthandshake flight, and when it wins the client gets a
SocketExceptioninstead. 7 of 25 runs fail. Assert that the request is refused rather than
which exception carries it.
TestLogAggregationService.testLocalFileDeletionAfterUpload(nodemanager)waits for each log file to go, then asserts on the parent directory with no
wait; the container-file and app-dir deletes are independent
FileDeletionTasks and either can run first. Hit 4 of the 60 most recent PRs,including unrelated ones. Wait for the directory too.
TestStandbyCheckpoints.testLastCheckpointTime(hdfs) waits for the activeto hold the new image, then reads a standby's checkpoint time, which that wait
does not cover: the standby stamps
lastCheckpointTimeonly afterdoCheckpoint()returns, so the interval can read 0 against an expected 3000.Wait for that value to move.
testPutFsimagePartFailedhas the same shape andgets the same wait.
TestTimelineReaderHBaseDown(timelineservice-hbase-tests) starts aTimelineReaderServerin all five tests and never stops one, leaking theTimelineStorageMonitorit schedules: non-daemon threads polling a miniclusterthe test has torn down. The module builds with
forkCount 0, so theseaccumulate across its eleven test classes. Stop the server in a finally, as
every other test in the module already does.
The last one rests on
TimelineReaderServer.serviceStop()actually stopping thereader, so this PR also carries one production change: that method stopped the
web server before
super.serviceStop()with notry/finally, andHttpServer2.stop()rethrows itsMultiException. The service is alreadySTOPPED by then, so a retry is a no-op and the storage monitor's polling
executor is left running. The stop is now in a
trywithsuper.serviceStop()in the
finally.How was this patch tested?
Existing tests, plus one new test for the production change. Measured before and
after:
testLastCheckpointTime: 2 failures in 20 runs before. After, 18 runs passed(12 idle, 6 with the box oversubscribed), with the new wait observed rescuing
a read that would otherwise have been 0.
TestTimelineReaderHBaseDown: 5/5 pass; instrumented, the class starts 9storage monitors and now stops all 9.
TestTimelineReaderServer.testChildServicesStoppedWhenWebAppStopFailsis theregression test for the
serviceStop()change: it makes the web server stopthrow and asserts the child services still reach STOPPED. Confirmed failing
without the
finally("FileSystemTimelineReaderImpl was left running by thefailed stop ... expected: but was: ") and passing with it.
testUntrustedClientIsRejected: 30/30 under bothTLSv1.2andTLSv1.3,on JDK 21.
The timeline thread leak is measured, but is an unproven cause of the CI shard
failure it was found in.
For code changes:
LICENSE/LICENSE-binary/NOTICE-binary: not applicable.AI Tooling
Contains content generated by Claude Code.
https://www.apache.org/legal/generative-tooling.html