Siyao Meng created HDDS-17396:
---------------------------------
Summary: BackgroundService.start on a running service schedules a
second loop, which can deadlock a new DirectoryDeletingService started by a
reconfiguration
Key: HDDS-17396
URL: https://issues.apache.org/jira/browse/HDDS-17396
Project: Apache Ozone
Issue Type: Bug
Reporter: Siyao Meng
Attachments: CR-7-ignore-start-on-running-background-service.patch,
TestBugCR7DirDeletingServiceStartedTwice.java
h3. Mechanism
{{BackgroundService.start}} creates a new executor only when the current one is
shut down, and otherwise always calls {{scheduleWithFixedDelay}} again. It
keeps no handle to the loop it already scheduled, so a second {{start()}} on a
running service adds a second periodic loop on the same executor.
Services that register a reconfiguration restart callback in their constructor
can be started by that callback before their owner calls {{start()}}.
{{KeyManagerImpl.start}} builds a new {{DirectoryDeletingService}} and calls
{{start()}} on it in the next statement. The constructor has already registered
the complete callback ({{registerReconfigCallbacks}}), and that callback calls
{{updateAndRestart}}, which does {{shutdown()}} and then {{start()}}. If the
callback runs on the new instance after construction and before
{{KeyManagerImpl.start}} reaches {{start()}}, the callback starts the service,
and the following {{start()}} from {{KeyManagerImpl}} sees a live executor and
schedules a second loop.
Since HDDS-16164 the {{DirectoryDeletingService}} executor has one thread.
{{PeriodicalTask.run}} submits its batch to that same executor and returns, and
the next run first calls {{future.join()}} on that batch. When the second loop
is scheduled before the first loop has submitted its batch, it is ahead of the
batch in the delay queue. It then joins a batch that can only run on the thread
it is blocking. {{join()}} cannot be interrupted, so the thread waits forever
and no batch runs again.
h3. Trigger
The worst case is the {{DirectoryDeletingService}} race during a checkpoint
install:
# A reconfiguration of {{ozone.directory.deleting.service.interval}} or
{{ozone.thread.number.dir.deletion}} ({{ozone admin reconfig --service=OM
--address=<om> start}}, admin only) reaches its complete callbacks just after
the new instance registered its own. A callback registered while the callbacks
are already running is skipped, see HDDS-17394.
# At that moment the same OM is in {{OzoneManager.installCheckpoint}} and calls
{{KeyManager.start}}: after a checkpoint that is not newer, after a failure to
stop the services, or after reloading the state. On the reload outcome the RPC
server is stopped, so only a reconfiguration started earlier can reach it; the
other two outcomes keep it running.
# The new callback is the last one in the list, so it runs after the OM's own
callbacks and after the callbacks of every instance replaced by an earlier
install (HDDS-17296), each of which does a full shutdown and start. Its
{{shutdown()}} must still read the executor before {{KeyManagerImpl.start}}
calls {{start()}}, a few statements later, so the install thread has to stall
at exactly that point. The race is very rare. It is not reachable at OM
startup, because the OM RPC server, which takes the reconfiguration request,
starts after {{KeyManager.start}}.
h3. Impact
* On master: the new {{DirectoryDeletingService}} stops for good. Deleted
directories are not purged on that OM while it is leader, so their space and
metadata are not reclaimed. Shown in the reproduction.
* A later reconfiguration restart does not recover it at this commit, because
{{shutdownNow()}} drops the batch without completing it and the shared
{{future}} still waits for it; only the next install or an OM restart replaces
the instance (code reading, not run). Once the fix proposed on HDDS-17395
lands, such a restart recovers after its 60 second wait (code reading, not
run). Each {{shutdown()}} of the stuck instance waits 60 seconds before it
gives up, which delays the next install or OM stop (the 60 second wait is
visible in the reproduction).
* If the first loop does submit its batch before the second loop is scheduled,
every round runs twice per interval, and a later round deadlocks the same way
once a round takes longer than the interval (argued, not run).
* In 2.1.0 to 2.2.1 the executor has {{ozone.thread.number.dir.deletion}}
threads (default 10), so the result there is two loops and rounds twice per
interval, with a deadlock only when that key is 1 (code reading, not run).
h3. Reproduction
PASS, deterministic, unmodified source.
[^TestBugCR7DirDeletingServiceStartedTwice.java]
({{hadoop-ozone/ozone-manager}}) starts one OM through {{OmTestManagers}},
builds a {{DirectoryDeletingService}} as {{KeyManagerImpl.start}} does, calls
{{updateAndRestart}} on it (what the callback does) and then {{start()}} (what
{{KeyManagerImpl.start}} does next). The only timing control is that the test
holds the service monitor across both calls, so the first loop submits its
batch after the second loop is scheduled. That is also the likely order in
production, since the worker thread must start and build its task queue first.
While the OM's own {{DirectoryDeletingService}} runs three rounds, the new one
runs no task and its only worker stays busy, blocked in {{PeriodicalTask.run}}
at {{future.join()}}. A passing test means the defect is present. The
reconfiguration task itself and a concurrent install were not run.
h3. Patch
[^CR-7-ignore-start-on-running-background-service.patch], against
9c3e5477ffb9f41da639051aaa5e9d7bd8b53fe4. It also applies to master at
c521a16af75.
{{BackgroundService.start}} keeps the {{ScheduledFuture}} of its loop and
returns with a warning when that loop is still scheduled on the current
executor. A {{start()}} after {{shutdown()}} still creates a new executor and
schedules a loop, so {{updateAndRestart}} and the other restart paths behave as
before. The guard is in the base class, so it covers every subclass. The
datanode {{BlockDeletingService}} has the same pattern: its constructor
registers a restart callback, the datanode RPC server that serves
reconfiguration starts before the first SCM handshake, and
{{OzoneContainer.start}} calls {{start()}} only after that handshake, so a
reconfiguration of the block deleting interval, timeout or workers in that
window adds a second loop; the guard covers it too (code reading, not run).
Covered by {{testStartOnRunningServiceIsIgnored}} in the existing
{{TestBackgroundService}}: it starts a one thread service twice while holding
its monitor, then checks that tasks keep running, that the second {{start()}}
logged that the service is already started, and that a {{start()}} after
{{shutdown()}} restarts the service. Without the change it times out with the
only worker blocked in {{future.join()}}. With the change
{{TestBackgroundService}}, {{TestDirectoryDeletingService}} and the other OM
deleting service suites pass, and checkstyle is clean. With the patch the
reproduction fails at its first assertion, because the new service runs its
tasks. The patch and the one proposed on HDDS-17395 change the same line of
{{start()}}, so whichever lands second needs a one line rebase.
Found by code review of the BackgroundService restart and shutdown paths and
the reconfiguration callback handling, as part of the TLA+ verification effort
under HDDS-15926, on commit 9c3e5477ffb9f41da639051aaa5e9d7bd8b53fe4. Checked
against HDDS issues and apache/ozone pull requests for duplicates before
filing. Related but not duplicates: HDDS-17296 (a replaced service's callback
restarts it after an install; its patch moves the callback to {{OzoneManager}},
which reads the service field that {{KeyManagerImpl.start}} assigns one
statement before {{start()}}, so this window stays open), HDDS-17394 (a
callback registered while callbacks run is skipped, which narrows the trigger),
HDDS-17395 (a restarted service can stop for good after a forced shutdown; its
fix lets a later restart recover from this deadlock), HDDS-16164 (made the
executor one thread, which turns the second loop into a deadlock), HDDS-11513
(registered the callbacks in the constructors), HDDS-14236 and HDDS-6696 (how a
single loop is scheduled). 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: [email protected]
For additional commands, e-mail: [email protected]
