[jira] [Created] (HDDS-17395) Restarted BackgroundService can stop for good or run batches from its old executor after a forced shutdown

["Siyao Meng (Jira)" <ji...@apache.org>]

Siyao Meng created HDDS-17395:
---------------------------------

             Summary: Restarted BackgroundService can stop for good or run batches from its old executor after a forced shutdown
                 Key: HDDS-17395
                 URL: https://issues.apache.org/jira/browse/HDDS-17395
             Project: Apache Ozone
          Issue Type: Bug
            Reporter: Siyao Meng


h3. Mechanism
{{BackgroundService.PeriodicalTask.run}} waits for the previous batch with {{future.join()}} on the instance field {{future}}, then calls {{getTasks()}} and submits every task with {{CompletableFuture.runAsync(..., exec)}}, folding each task's future into {{future}}. {{join()}} ignores interrupts. The submit reads the field {{exec}}, not the executor the run was scheduled on.

{{shutdown()}} calls {{exec.shutdown()}}, waits 60 seconds in {{awaitTermination}}, and calls {{shutdownNow()}} when that wait runs out or the calling thread is interrupted. {{start()}} creates a new executor when the old one is shut down, but keeps {{future}}. Three things follow:
* {{shutdownNow()}} removes the queued {{runAsync}} wrappers from the executor without running them, so their futures never complete, and neither does {{future}}. The first run of the restarted service waits on it forever.
* A run that was waiting in {{join()}} during the restart is not stopped by {{shutdownNow()}}. When the slow task ends, it calls {{getTasks()}} and submits into {{exec}}, which is now the new executor, while the new executor's own run does the same.
* Since HDDS-14645, {{shutdown()}} calls {{exec.shutdown()}} outside the monitor that the submit loop holds, so it can land between {{getTasks()}} and the submit. {{runAsync}} then throws {{RejectedExecutionException}}, which ends the run with no log line; the polled task is lost and the rest of the batch is abandoned.

h3. Trigger
{{BlockDeletingService.updateAndRestart}} and {{DirectoryDeletingService.updateAndRestart}} are the only callers that restart a service instance in place. They run when {{ozone admin reconfig}} changes {{hdds.datanode.block.deleting.service.interval}} ({{ozone.block.deleting.service.interval}} in 2.1 and 2.2), {{ozone.block.deleting.service.timeout}} or {{ozone.block.deleting.service.workers}} on a datanode, or {{ozone.directory.deleting.service.interval}} or {{ozone.thread.number.dir.deletion}} on an OM. The restart reaches {{shutdownNow()}} when the tasks still running or queued at that moment do not finish within 60 seconds. The interrupt path of {{shutdown()}} exists in the code, but nothing in Ozone interrupts the reconfiguration thread. After a plain {{exec.shutdown()}} the queued tasks still run, so a task is dropped only if it has not started when the 60 seconds run out.

For {{BlockDeletingService}}, a batch has one task per container with pending deletes, up to {{hdds.datanode.block.deleting.limit.per.interval}} (20000 blocks by default) in total, so on a datanode with a deletion backlog it often has more tasks than the 10 default workers. {{BlockDeletingTask}} does not check for interrupts. Tasks are dropped when such a batch is still running 60 seconds after the reconfiguration started, which is also when an operator is likely to retune deletion. This is argued from the code, not measured on a datanode. {{DirectoryDeletingService}} runs one worker since HDDS-16164, but its own {{shutdown()}} first shuts its deletion pool down, after which queued tasks return quickly, so it reaches {{shutdownNow()}} only when a task outlives that as well (argued from the code).

h3. Impact
All of the following were run on unmodified source against {{BackgroundService}} through its public methods, with a test subclass that restarts in the same order as {{updateAndRestart}}. No production service was run.
* *Restarted service never runs again.* Pool size 1, first batch of two tasks, one running and one queued. After a restart whose {{shutdown()}} was interrupted, and after one whose 60 second wait really ran out, the restarted service called {{getTasks()}} zero times in 3 seconds at a 50 ms interval, with its only worker parked in {{CompletableFuture.join}} from {{PeriodicalTask.run}}. Nothing reassigns {{future}}, so this lasts until the process restarts, and by code reading every later {{shutdown()}} waits the full 60 seconds for the parked thread. For {{BlockDeletingService}} this means block deletion on that datanode stops while the service still counts as started. [^TestBugMC1RestartAfterForcedShutdown.java]
* *Two batches at once.* Pool size 2, one task holding a worker through the restart and the next run waiting for it. After the task ended, both the old executor's run and the new executor's run fetched a batch, and the two batches ran at the same time on the new executor, against the class contract of one batch per interval. In {{BlockDeletingService}} the duplicate batch is absorbed ({{getTasks()}} only reads, and each task re-reads the container under its write lock), so this is a latent defect today (argued from the code). [^TestBugMC2StaleLoopOverlapsRestartedBatch.java]
* *Single worker deadlock.* Pool size 1 and two restarts that both reach {{shutdownNow()}}: the run that survived the second restart submitted its task into the third executor, behind that executor's next run, which then waited in {{join()}} for a task that could only run on its own thread. {{getTasks()}} was not called again. The test orders the steps with latches, so it shows that the interleaving exists, not how often it occurs. [^TestBugMC3SingleWorkerSelfDeadlock.java]
* *Batch dropped without a log line.* A {{shutdown()}} that landed after {{getTasks()}} had returned four tasks: one task was polled and neither ran nor was handed back, three were abandoned, and only the start and shutdown INFO lines were logged. The services restarted in place rebuild their batch from durable state on the next run, and the services whose {{getTasks()}} reserves state ({{KeyLifecycleService}}, {{DiskBalancerService}}) are only stopped together with their owner and then discarded, so no wrong result follows today (argued from the code). [^TestBugMC4ShutdownDuringSubmit.java]

h3. Reproduction
The four attached JUnit classes belong in {{hadoop-hdds/framework/src/test/java/org/apache/hadoop/util/}} (Maven command in each class comment) and pass on unmodified source while the bug is present. They only use {{start()}}, {{shutdown()}}, {{setInterval()}} and {{getExecutorService()}}. Except for one case of the first class, the forced shutdown is reached by interrupting the restarting thread, which takes the same {{shutdownNow()}} path as a 60 second wait that runs out, without waiting for it.

h3. Patch
[^MC-1-complete-dropped-tasks-and-stop-stale-background-service-loops.patch], against 9c3e5477ffb9f41da639051aaa5e9d7bd8b53fe4. It also applies to master at c521a16af75.

All changes are in {{BackgroundService}}:
* {{start()}} schedules a new {{PeriodicalTask}}, which keeps the executor it was scheduled on. A run whose executor has been shut down returns after {{join()}} without calling {{getTasks()}}, and the submit loop stops when its executor is shut down. So no run of an old executor reaches the new one.
* Each submitted task registers its future in a set kept per executor and removes it when it starts. After {{shutdownNow()}}, {{shutdown()}} completes the futures still in the set, which belong to the tasks that were dropped and will never run. A task that had started is still waited for, so the restarted service does not run its first batch next to a task of the old executor that is still running.
* {{shutdown()}} calls {{exec.shutdown()}} under the monitor, so it cannot land halfway through the submit loop. {{awaitTermination}} stays outside the monitor, as HDDS-15429 requires. {{exec.shutdown()}} does not wait for workers, and the submit loop already takes the executor's lock while holding the monitor, so this adds no new lock order. A batch fetched before the shutdown and not submitted is logged at INFO with its size.

A service that is never restarted and whose shutdown finishes in time behaves as before. Resetting {{future}} in {{start()}} was not chosen: the new batch would then run next to tasks of the old executor that are still running, and a run of the old executor parked on a dropped task would stay parked.

Covered by three new cases in the existing {{TestBackgroundService}}: {{testRestartAfterForcedShutdownSkipsDroppedTasks}}, {{testLoopOfReplacedExecutorDoesNotFetchTasks}} and {{testShutdownWhileFetchingTasksDropsWholeBatch}}. Without the change they fail with a {{TimeoutException}} (the restarted run parked in {{join()}}), "Expecting AtomicInteger(2) to have value: 1" and "expected: 4 but was: 3". With it they pass, the existing suites of the {{BackgroundService}} subclasses in {{hadoop-hdds/container-service}} and {{hadoop-ozone/ozone-manager}} pass, checkstyle is clean, and the four attached classes no longer show the bug.

Found by TLA+ model checking and code review of the BackgroundService restart and shutdown paths and the reconfiguration callback handling under HDDS-15926, on commit 9c3e5477ffb9f41da639051aaa5e9d7bd8b53fe4. Checked against HDDS issues and apache/ozone pull requests for duplicates before filing. Related but not duplicates: HDDS-15429 (monitor deadlock in {{updateAndRestart}}, whose fix stopped calling {{shutdown()}} under the monitor), HDDS-14645 (moved {{exec.shutdown()}} and {{awaitTermination}} out of the monitor), HDDS-14020 (open, the same lock shared by shutdown and the submit loop), HDDS-13773 (open, timeout and interrupt for background tasks), HDDS-14236 (fixed delay scheduling of {{PeriodicalTask}}, in progress, its PR closed), HDDS-16949 (an exception from {{getTasks()}} cancelled the periodic task) and HDDS-17296 (a replaced {{DirectoryDeletingService}} is restarted by its reconfiguration callback). The attached patch is a proposal for review. Generated with Specula (Claude Opus 5.5).



--
This message was sent by Atlassian Jira
(v10.3.26#10030026)

---------------------------------------------------------------------
To unsubscribe, e-mail: issues-unsubscribe@ozone.apache.org
For additional commands, e-mail: issues-help@ozone.apache.org