Skip to content

Interrupt the auditor tasks right away when shutting down the auditor - #4926

Open
merlimat wants to merge 4 commits into
apache:masterfrom
merlimat:mmerli/auditor-shutdown-interrupt
Open

merlimat wants to merge 4 commits into
apache:masterfrom
merlimat:mmerli/auditor-shutdown-interrupt

Conversation

@merlimat

@merlimat merlimat commented Nov 2, 2026 •

Copy link
Copy Markdown
Contributor

Problem

Auditor.shutdown() shuts its executor down and waits up to 30 seconds for it to terminate before interrupting the
running task (Executor not shutting down, interrupting). It waits, up to the whole 30 seconds, when:

  • an audit waits for the ledger replication to be enabled: the bookie check, a lost bookie audit and a
    lostBookieRecoveryDelay change all start with waitIfLedgerReplicationDisabled(), which waits until an operator
    enables it again (e.g. during a rolling restart done with the auto recovery disabled);
  • the audit of a lost bookie is delayed by lostBookieRecoveryDelay: a ScheduledThreadPoolExecutor still runs
    delayed tasks after shutdown(), so the auditor waits for the delay, and when it is shorter than 30 seconds, runs
    the audit after it was shut down.

Example

// Auditor.shutdown(), master
executor.shutdown();   // keeps running the delayed audit, doesn't interrupt a blocked one
try {
    while (!executor.awaitTermination(30, TimeUnit.SECONDS)) {
        log.warn("Executor not shutting down, interrupting");
        executor.shutdownNow();
    }

To reproduce: disable the auto recovery (bin/bookkeeper shell autorecovery -disable), stop a bookie that is not the
auditor (the auditor's audit of the lost bookie now waits for the replication to be enabled), then stop the auditor's
bookie: it takes 30 seconds.

Change

shutdown() calls shutdownNow() instead of shutdown(): it interrupts the running task and drops the pending and
delayed ones right away, then waits for the executor to terminate as before.

// Interrupt the running audit rather than wait for it: an audit can wait for the ledger
// replication to be enabled for as long as it stays disabled, and shutdown() would still
// run the audit delayed for a lost bookie. The next auditor runs the audits again.
executor.shutdownNow();

An audit in progress is cut short instead of getting up to 30 seconds to finish: the next auditor runs its bookie
check as soon as it starts and the periodic checks on their schedule, and audits longer than 30 seconds were already
interrupted. Before BOOKKEEPER-496 the auditor ran on its own thread and shutdown() interrupted it right away.

The full-ledger check closes the BookKeeper client it creates for the check on another thread, which shutdown()
doesn't interrupt, and waits for it without giving up when interrupted, then restores the interrupt status. An
interrupted BookKeeper.close() stops at the wait it is in, and closing the client again returns at once, so a check
that shutdown() interrupted, before or while it closed that client, left the client's threads and ZooKeeper session
behind, as checks longer than 30 seconds already did on master (third and fourth commits, from the review). A failure
to close that client is now logged rather than counted as a failed check.

// AuditorCheckAllLedgersTask.checkAllLedgers()
} finally {
    // Close the check's own client on another thread, and wait for it: Auditor.shutdown() interrupts
    // a running check, also while it closes the client, and an interrupted BookKeeper.close() stops at
    // the wait it is in, leaving the client's threads and ZooKeeper session behind for good
    Thread closer = new Thread(() -> {
        try {
            localAdmin.close();
            localClient.close();
        } catch (BKException | InterruptedException e) {
            log.warn().exception(e).log("Failed to close the client of the check of all ledgers");
        }
    }, "AuditorCheckAllLedgers-close");
    closer.start();
    Uninterruptibles.joinUninterruptibly(closer);
}

Testing

  • New AuditorPeriodicCheckTest.testShutdownWithDelayedBookieAudit: an auditor whose audit of a lost bookie is
    delayed by lostBookieRecoveryDelay (Integer.MAX_VALUE) must shut down within 10 seconds. Fails on master
    (TimeoutException).
  • New AuditorPeriodicCheckTest.testShutdownWithAuditWaitingForReplication: with the ledger replication disabled, an
    auditor whose bookie check waits for it must shut down within 10 seconds. Fails on master (TimeoutException).
  • New AuditorPeriodicCheckTest.testShutdownDuringCheckAllLedgersClosesItsClient: shuts an auditor down while its
    full-ledger check waits for the ledgers to be processed. The auditor must shut down within 10 seconds, and the
    check's client must have stopped its worker threads and closed its ZooKeeper session. Fails on master
    (TimeoutException) and without the third and fourth commits (The check's client still runs its worker threads:
    its close threw InterruptedException at its first wait, scheduler.awaitTermination()).
  • New AuditorPeriodicCheckTest.testShutdownWhileCheckAllLedgersClosesItsClient: shuts an auditor down while its
    full-ledger check closes its client, the close waiting for a task still running on the client's scheduler, which
    ends once the auditor has stopped running. The auditor must shut down within 10 seconds, and the check's client must
    have stopped its worker threads and closed its ZooKeeper session. Fails without the fourth commit (The check's client still runs its worker threads: the shutdown's interrupt stopped the close at scheduler.awaitTermination()).
  • With the first commit, the org.apache.bookkeeper.replication tests (19 classes) plus BookKeeperAdminTest,
    BookieDecommissionTest, TestHttpService and BookieInitializationTest pass, except 4 BookieInitializationTest
    tests that fail locally on master too (they can't resolve the machine's hostname). With all four commits,
    AuditorPeriodicCheckTest (16 tests) and AuditorCheckAllLedgersTaskTest pass. Checkstyle and SpotBugs pass.

Those 23 classes on master and with this change, one run each (other test runs were going on at the same time; the
waits removed have fixed lengths):

Class master (s) this change (s)
AuditorRollingRestartTest 96.1 5.9
AuditorPeriodicCheckTest 269.9 102.9
TestAutoRecoveryAlongWithBookieServers 42.4 13.7
all 23 classes 1,777 1,522

Executor not shutting down, interrupting appears 7 times in master's logs of these classes, and never with this
change. On its own, this change makes AuditorLedgerCheckerTest slower (212 to 274 s): the auditor now stops at once,
so the tests more often stop the next elector before it has become the auditor, and that stop waits 10 seconds, which
#4925 fixes. With both changes the logs have neither wait, and the 23 classes take 919 s instead of 1,777 s:

Class master (s) #4925 (s) this change (s) both (s)
AuditorBookieTest 217.2 21.1 177.2 20.8
AuditorPeriodicCheckTest 269.9 198.8 102.9 51.1
AuditorLedgerCheckerTest 212.1 77.6 274.0 72.5
AuditorRollingRestartTest 96.1 96.1 5.9 5.9
BookieAutoRecoveryTest 136.3 68.8 128.6 68.9
BookieDecommissionTest 221.0 151.2 221.4 150.8
BookKeeperAdminTest 59.3 29.3 60.5 28.9
TestAutoRecoveryAlongWithBookieServers 42.4 13.4 13.7 13.5
all 23 classes 1,777 1,169 1,522 919

Auditor.shutdown() shut its executor down and waited up to 30 seconds
for it to terminate before interrupting the running task ("Executor not
shutting down, interrupting"). It waited the whole 30 seconds in two
common cases:

- An audit waiting for the ledger replication to be enabled (the bookie
  check, a lost-bookie audit, a lostBookieRecoveryDelay change) only
  ends when an operator enables it again, e.g. after a rolling restart
  done with the auto recovery disabled.
- The audit delayed for a lost bookie by lostBookieRecoveryDelay: a
  ScheduledThreadPoolExecutor still runs the delayed tasks after
  shutdown(), so the auditor waited for the delay, and when it was
  shorter than 30 seconds, ran the audit after it was shut down.

shutdown() now interrupts the running task and drops the pending ones
right away (shutdownNow()), then waits for the executor to terminate as
before. The next auditor runs the audits again; before BOOKKEEPER-496
the auditor shutdown interrupted its thread right away too.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

🟡 Changes recommended

The test lacks synchronization to confirm the audit is waiting, so shutdown can discard the queued check and let the test pass without exercising interruption of a running audit.

1 open issue
What changed in this PR

This PR makes auditor shutdown interrupt running tasks and discard queued or delayed audits immediately, avoiding the initial 30-second wait.

Changes:

  • Replace shutdown() with shutdownNow() on the auditor executor.
  • Add regression tests for shutdown with a delayed lost-bookie audit and with ledger replication disabled.
File Description
bookkeeper-server/​src/​test/​java/​org/​apache/​bookkeeper/​replication/​AuditorPeriodicCheckTest.java Add prompt-shutdown tests for delayed and replication-blocked audits.
bookkeeper-server/​src/​main/​java/​org/​apache/​bookkeeper/​replication/​Auditor.java Interrupt executor tasks immediately while retaining termination waiting.

Review effort: Balanced

testShutdownWithAuditWaitingForReplication shut the auditor down right
after start(), while the bookie check could still be queued: then
shutdownNow() just dropped it, and the test passed without interrupting
a running audit. The test now waits until the check has registered to
be notified when the replication gets enabled, right before it waits.

@codelipenghui codelipenghui left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed commit 19799361ed9d9ca373f98e25c3e636dc2a26f406.

The immediate-cancellation approach addresses the intended shutdown delays, but the full-ledger audit's private-client cleanup needs to be interruption-safe before removing the grace period. Please address the inline finding and add a shutdown-during-scan test that verifies resource termination, not just prompt return.

Validation: the finding is based on the source cancellation/cleanup path, not a runtime reproduction. The local Maven attempt stopped in the upstream Build Tools module because no tests matched the selected auditor-test names, so neither focused regression test executed.

Auditor.shutdown() now interrupts a running full-ledger check right
away. The check then closed the BookKeeper client it creates for itself
on the interrupted thread, and BookKeeper.close() throws
InterruptedException at its first wait (scheduler.awaitTermination()),
skipping the rest: the client's worker pools, timer, event loop group
and ZooKeeper session stayed open. The check now closes its client with
the interrupt status cleared, then restores it.

testShutdownDuringCheckAllLedgersClosesItsClient shuts an auditor down
while its check waits for the ledgers to be processed, and asserts that
the check's client stopped its worker threads and closed its ZooKeeper
session.

@codelipenghui codelipenghui left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Follow-up review of 03994c43f2298ca88b63b71b30d3a33d48ef0985.

The update addresses interruption before cleanup and adds a useful test checking worker termination and ZooKeeper closure. One timing window remains: shutdown can deliver its first interrupt after the flag is cleared, while the private client's close operation is running. Please address the inline finding and cover shutdown initiated during cleanup.

Validation: this is a source-traced finding, not a runtime reproduction. Local execution of the three focused shutdown tests was blocked by unavailable BookKeeper 4.18.0-SNAPSHOT reactor dependencies; no selected tests executed.

The previous commit closed the check's client with the interrupt status
cleared, but Auditor.shutdown() can also interrupt the check while it
closes the client: BookKeeper.close() then throws at the wait it is in
and skips the rest of the close, and closing the client again returns
at once. The check now closes its client on another thread, which the
shutdown doesn't interrupt, and waits for it without giving up when
interrupted, then restores the interrupt status. A failure to close the
client is now logged rather than counted as a failed check.

testShutdownWhileCheckAllLedgersClosesItsClient shuts an auditor down
while its check closes its client, the close waiting for a task still
running on the client's scheduler, and asserts that the client stopped
its worker threads and closed its ZooKeeper session.

@codelipenghui codelipenghui left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Code Review approval for commit b1c6f4a.

Summary:

Both previously reported cleanup-interruption cases are resolved: the private client now closes on a separate thread, and the auditor waits without forwarding its interrupts. No actionable findings identified within the reviewed scope. Recommend approval of the code change; local runtime validation remains unavailable, and failing integration CI still needs investigation before merge.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants