Skip to content

[MOD-19365] Bound the default Redis shutdown wait - #259

Merged
gabsow merged 9 commits into
masterfrom
fix/mod-19365-bounded-shutdown
Oct 8, 2026
Merged

gabsow merged 9 commits into
masterfrom
fix/mod-19365-bounded-shutdown

Conversation

@gabsow

@gabsow gabsow commented Oct 6, 2026 •

Copy link
Copy Markdown
Contributor

RLTest's default shutdown path can enter an unbounded wait when Redis refuses SIGTERM. The nightly can therefore pass its assertions but spend the entire job timeout in replica teardown.

Bound the default shutdown to a 30-second grace period (300 seconds under Valgrind or sanitizers), followed by SIGKILL and a 5-second process wait. Retry SIGTERM once per second during the grace period so Redis can shut down cleanly after a temporary refusal. Wait for process exit rather than pipe EOF, since Redis fork children can keep stdout/stderr open after the parent exits. Catch the kill timeout so remaining shards still get teardown and process references are cleared.

Forced shutdowns are recorded as test failures even without --check-exitcode, through the standalone/cluster environment and test runner. A bounded tail of the server log is printed after kill/reap, and diagnostic errors cannot interrupt teardown. Mid-test shutdown failures are attributed and consumed at the end of that test, before environment reuse can change the test name. The macOS debugger child wait is also bounded to 30 seconds before SIGKILL and a further 5 seconds: an inferior paused at a breakpoint can be killed and reported as a failure instead of waiting indefinitely for input; ordinary Redis children are left to Redis's own shutdown handling. Explicit terminateRetries behavior remains unchanged.

Tracking: MOD-19365.

Validation after review:

  • 15 shutdown regressions pass on Python 3.7/Linux and Python 3.14/macOS. They cover graceful and forced master/replica exit, inherited pipes held by a live child, repeated SIGTERM, kill timeout with remaining-shard teardown, bounded macOS debugger waits, and runner failure reporting without --check-exitcode in standalone and cluster environments.
  • The added second-review regressions verify an instrumented process can exit cleanly after 30 seconds (simulated clock), diagnostic path-format errors cannot prevent reaping, and reused cluster environments report and consume failures under the originating test. Including the two existing failed-setup teardown cases, 17 focused tests pass on both Python versions. A full module Valgrind nightly was not run; the longer grace is a bounded allowance, not a measured upper bound for every workload.
  • Full unit suite in an isolated Redis 8.8 Linux container: 176 passed, 5 skipped, with redis-py 5.0.8. The broad host run encountered shared-port failures and a newer redis-py API incompatibility; it is not reported as passing.
  • Controlled real Redis 8.8 replica/AOF reproduction with the real 30-second grace: initial SIGTERM is refused while the initial rewrite is paused. After resuming it, the next SIGTERM exits cleanly in 1.07 seconds (exit 0). Keeping the rewrite child paused through escalation returns in 30.01 seconds (exit -9), clears the replica process reference, and records shutdown failure without waiting for inherited-pipe EOF.
  • The original PR-base implementation remained blocked at a 37-second watchdog in the earlier controlled reproduction.
  • git diff --check passed. CI reruns on the follow-up commit.

The historical artifacts lack the relevant Redis server logs. Subsequent natural stress reproduced a matching failure on the pinned failing setup, as detailed below; this does not prove that every historical incident shared the same cause. The nightly stacks show replica teardown blocked in communicate(): Sep 30, Oct 1, Oct 6. Kept as a draft for review.

Natural stress reproduction

Natural stress reproduction now confirms the shutdown mechanism in both affected tests, without pausing children or changing the RedisJSON tests.

Setup: RedisJSON fbe6eaed5f2cc3d80fc54c9fc840469a6cd840f3, the exact Oct-06 failed-run image digest sha256:20c5071155911763c7b739aff8e4de01bd305dadd64d4bd990ae8383a4f2ffa2 (Redis unstable b540ca49), and RLTest 304834d. Linux amd64 Docker on Apple Silicon, limited to 2 CPUs. The original _stopProcess from the PR base was verified to match the method installed in that nightly image.

  • Current PR: 128/128 stress executions passed with four workers. There were 14 natural initial-AOF shutdown refusals (10 in test_mset_replication_in_aof --use-slaves, 4 in testEveryWriteCommandIsCovered --use-aof). Every affected replica exited with code 0 after the next SIGTERM, in 1.035–1.071 seconds. No SIGKILL. Four additional sequential pilot executions passed.
  • Original shutdown: 32 executions at four workers did not reproduce. An eight-worker pressure batch launched 117 runners; 116 reached the tests and three naturally hung, covering both tests. One separate runner failed importing paella; that worker stopped early. All three hung replicas had finished AOF rewriting, had no remaining fork child, and were still alive at 37 seconds. Python stacks were in _stopProcess -> communicate -> selector.poll, matching the historical stacks. Only after capturing this evidence did the watchdog send a recovery SIGTERM; each replica then exited cleanly. The eventual baseline runner exit codes must not be interpreted as unassisted passes.

Representative original-code timeline: the master finished synchronization and exited at 12:46:55.998. The replica refused SIGTERM at 12:46:56.020 (Writing initial AOF, can't exit.), processed rewrite-child completion at 12:46:56.021, and finished the rewrite at 12:46:56.035. At 37.009 seconds it was still alive with aof_rewrite_in_progress=0, while Python was blocked in communicate(). A recovery SIGTERM ended it immediately.

The pinned Redis source explains this: initial AOF rewrite refusal follows the error path into cancelShutdown(), clearing the pending shutdown request. Finishing the rewrite does not reinstate it. The old RLTest sends SIGTERM only once; the current retry handles this refusal and completes graceful shutdown. SIGKILL remains the fallback.

Master/replica logs, snapshots, stacks, runner output, binary hashes, and reproduction scripts are preserved in the stress evidence bundle. The different worker counts are not a controlled rate comparison. Historical Redis logs remain unavailable, so this reproduces a matching failure on the pinned failing setup rather than proving every past incident had the same cause. No further code change was needed for this reproduced case.


Note

Medium Risk
Changes core process lifecycle and test pass/fail semantics for all Redis-backed runs; behavior is intentional but affects teardown timing and when tests fail without --check-exitcode.

Overview
Bounds default Redis teardown so nightlies cannot hang indefinitely when a server ignores SIGTERM (e.g. during initial AOF rewrite). The default path retries SIGTERM once per second for 30s (300s under Valgrind/sanitizers), then SIGKILL with a 5s exit wait; teardown waits on process exit instead of pipe EOF so fork children cannot block shutdown. Forced shutdowns set a shutdownFailed flag surfaced via hasShutdownFailure() on standalone, OSS cluster, and enterprise cluster envs.

Runner behavior treats forced shutdown as a test failure even without --check-exitcode, attributes mid-test shutdown problems to the current test (including across env reuse/replacement), and defers [PASS]/[SKIP] printing until after env teardown so a late shutdown failure can flip the result. Skipped tests still run teardown and consume shutdown flags; macOS interactive debugger inferior waits are similarly bounded.

README documents the policy; tests/unit/test_shutdown.py adds regression coverage for these paths.

Reviewed by Cursor Bugbot for commit 21c01ba. Bugbot is set up for automated code reviews on this repo. Configure here.

@gabsow gabsow changed the title Bound Redis process shutdown and log SIGKILL escalation Bound the default Redis shutdown wait (MOD-19365) Oct 8, 2026
@gabsow gabsow changed the title Bound the default Redis shutdown wait (MOD-19365) [MOD-19365] Bound the default Redis shutdown wait Oct 8, 2026
@LiranAbir

Copy link
Copy Markdown
Collaborator

Fix looks right: it bounds the wait and records the -9. One concern: in RedisJSON's regular nightly lanes, the forced kill won't fail the test.

flow-linux.yml:202 runs tests.sh with RLTEST_ARGS='--no-progress' and no --check-exitcode. checkExitCode() only runs when --check-exitcode or --use-valgrind is set (__main__.py:596). Only the valgrind lane sets one of them. All three hung jobs linked in the description ran in regular build-linux-x64 lanes (bookworm, bionic, rocky10). So in exactly the lanes that hit this, a Redis that ignores SIGTERM now gets killed after 30s and the test passes. The only trace is the red sending SIGKILL line in the log. Before, the job at least failed on timeout.

Suggestion, either of:

  1. In RLTest: when the default path has to SIGKILL, mark the test as failed (e.g. redis process failure) whether or not --check-exitcode is set.
  2. In RedisJSON: add --check-exitcode to RLTEST_ARGS in flow-linux.yml / run-tests/action.yml.

I'd prefer (1): it covers every module repo that uses RLTest, not just RedisJSON.

Nice to have: on SIGKILL, also print the end of the server log file (like verbose_analyse_server_log does). Redis logs to a file, so captured stdout/stderr probably won't show why it refused to exit (e.g. Writing initial AOF, can't exit.).

@gabsow gabsow left a comment

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Review findings on 2ffaacc, to address before un-drafting.

The bound itself works: the 5 tests pass (py3.14/macOS), and master does hang in the post-30s communicate(). Two issues come from how it's bounded: communicate() waits for pipe EOF, not just process exit, and Redis fork children (AOFRW/BGSAVE) inherit stdout/stderr.

Probe with Python stand-ins for Redis (Linux code path, timeouts patched to 2s/1s):

case master this PR
A: ignores SIGTERM, fork child still alive hangs TimeoutExpired escapes stopEnv; parent reaped with -9 but slaveExitCode=None, slaveProcess not cleared
B: exits 0 on SIGTERM, fork child still alive returns in 0.10s, exit 0 waits the full grace, logs "did not exit on SIGTERM; sending SIGKILL", then TimeoutExpired

Case A is the slow initial-AOFRW case (rewrite > 30s): SIGKILL doesn't kill the rewrite child. The repro in the description resumed the rewrite before the kill, so it never exercised this.

Suggested shape:

  • process.wait(timeout) instead of communicate() (bounded on the process, not the pipes).
  • Re-send SIGTERM ~1/s during the grace. A refused shutdown is reset, so a later SIGTERM should succeed once the rewrite finishes -> clean exit 0 instead of -9 (worth confirming against 8.8 prepareForShutdown). This also helps with @LiranAbir's point: fewer forced kills, and the remaining ones are real.
  • Then kill() + wait(_KILL_TIMEOUT), with TimeoutExpired caught and logged so stopEnv still clears state and cluster teardown continues.

Also still unbounded and untouched: the Darwin child loop's p.wait() (L476). My first macOS probe hung there.

Comment thread RLTest/redis_std.py Outdated
except subprocess.TimeoutExpired:
print(Colors.Bred('[TERMINATING] {0} server id {1} did not exit on SIGTERM; sending SIGKILL'.format(role, serverId)))
process.kill()
process_out, process_err = process.communicate(timeout=_KILL_TIMEOUT)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

This runs after SIGKILL but still waits for pipe EOF. If Redis had a fork child alive (AOFRW > 30s), the child keeps stdout/stderr open and this raises TimeoutExpired. Only OSError is caught (L509), so it escapes stopEnv: slaveProcess isn't cleared, and in redis_cluster.stopEnv the shard loop aborts, leaving the remaining shards running. Reproduced with a stand-in (case A in the review). process.wait(timeout=_KILL_TIMEOUT) plus catch-and-log would bound it on the process only.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Addressed in 1f7b82a. The post-SIGKILL path now uses process.wait(timeout=5) and catches/logs TimeoutExpired, so inherited pipe handles cannot delay parent reaping or abort remaining shard teardown. The regression verifies that the process reference is cleared and the next shard is stopped even when the kill wait times out. A real Redis 8.8 replica with its initial AOF rewrite child kept paused through escalation returned in 30.01 seconds, recorded exit -9, cleared slaveProcess, and marked shutdown failure.

Comment thread RLTest/redis_std.py Outdated
process_out, process_err = process.communicate()
print(Colors.Bred(f'\t[TERMINATING] out ({process_out}), error ({process_err})'))
try:
process.communicate(timeout=_TERMINATE_TIMEOUT)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

communicate() completes on pipe EOF + exit, not on exit alone. A process that exits cleanly while a child still holds the pipes now costs the full 30s + 5s and raises (case B; master returned in 0.1s), with a misleading "did not exit on SIGTERM" line. process.wait(timeout=...) keeps the old poll() semantics; draining shouldn't be needed since Redis logs to --logfile.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Addressed in 1f7b82a. The grace period now waits on the process rather than communicate()/pipe EOF. Added real fork-child regressions for both a clean parent exit and an ignored SIGTERM while the child keeps stdout/stderr open. Both return within the bounded test deadline; the clean case records exit 0 without a forced-shutdown failure. The 11 focused shutdown cases pass on Python 3.7/Linux and 3.14/macOS.

Comment thread tests/unit/test_shutdown.py Outdated
process.kill.assert_called_once_with()
assert [call[1] for call in process.communicate.call_args_list] == [
{'timeout': 30}, {'timeout': 5}]
assert env.masterProcess is process

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

This pins TimeoutExpired propagating out of _stopProcess as intended behaviour. I'd rather assert the opposite: stopEnv returns, logs, and clears masterProcess. Also worth a case with a fork child holding the pipes (A/B in the review): all current cases use a childless process, where pipe EOF == exit, so they can't see the difference.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Replaced that expectation in 1f7b82a. The timeout regression now asserts that teardown returns, clears the process reference, records shutdown failure, and continues to the next shard. Added both inherited-pipe cases from the review, plus SIGTERM retry and runner-level checks proving a forced shutdown fails standalone and cluster tests without --check-exitcode. All 11 shutdown regressions pass on Python 3.7 and 3.14; the isolated full unit suite passed 172 tests (5 skipped).

@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir Addressed your comment in 1f7b82a using option 1. A forced shutdown in the default path now sets a persistent shutdown-failure flag, propagated through the standalone/cluster environment to the runner. takeEnvDown() records redis process failure even when --check-exitcode is off. Regressions exercise that runner behavior in both standalone and cluster environments.

Also added a bounded tail of the server log (last 8 KiB) on SIGKILL, with read errors logged without interrupting teardown. SIGTERM is retried during the grace period to avoid a forced kill when the initial refusal is temporary: the real Redis 8.8 replica/AOF check exited cleanly in 1.07 seconds after its rewrite resumed; keeping the rewrite paused required SIGKILL and returned in 30.01 seconds with failure recorded.

Validation: 11 shutdown regressions passed on Python 3.7 and 3.14; isolated full unit suite: 172 passed, 5 skipped. Updated CI is still running. This proves the teardown behavior, not the missing historical nightly trigger.

@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

Follow-up to the review summary: addressed in 1f7b82a, with individual replies on all three inline threads.

The default path now uses process waits, retries SIGTERM about once per second within the 30-second grace period, and catches the 5-second post-SIGKILL timeout so teardown continues. The macOS child handling is restricted to interactive debuggers and uses bounded group waits (30 seconds, then 5 seconds after escalation); a regression covers the previous unbounded wait.

Verified the SIGTERM retry behavior against real Redis 8.8: resuming the initial AOF rewrite yielded a clean exit in 1.07 seconds. Keeping the child paused through the entire grace period yielded exit -9 in 30.01 seconds, without waiting on inherited pipe EOF. Both stand-in inherited-pipe cases are also covered. All 11 focused regressions pass on Python 3.7/Linux and 3.14/macOS, and the isolated full unit suite passed 172 tests (5 skipped). The PR remains a draft while updated CI and review are pending.

@LiranAbir

Copy link
Copy Markdown
Collaborator

Thanks, 1f7b82a addresses my comment: a forced SIGKILL now records redis process failure without --check-exitcode, and the server-log tail on kill is a nice addition. CI is green on 1f7b82a. LGTM.

The cause of the original nightly hangs is still open in MOD-19365. With this change, a recurrence will show up as a failed test with the server log, instead of a job timeout.

@gabsow gabsow left a comment

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Re-review of 1f7b82a: the earlier findings are fixed.

Verified locally (py3.14/macOS):

  • 11/11 shutdown tests pass.
  • Inherited-pipe probes, Linux code path: (A) ignores SIGTERM + live fork child: returns in 3.0s, exit -9, process cleared, hasShutdownFailure() True (previously raised). (B) clean exit + live fork child: returns in 0.00s, exit 0 (previously full grace + raise).
  • Full unit suite: no PR-only failures. The ~12 failing tests here also fail on master (local environment).

Remaining, inline:

  1. Medium: 30s is now a hard kill + test failure, where master only started draining at 30s and then waited unbounded.
  2. Low: _print_shutdown_log runs before kill() and only catches OSError.
  3. Low: shutdownFailed is never reset (misattribution under --env-reuse).
  4. Note: the macOS lldb behaviour change.

(1) is the one to decide before un-drafting.

Comment thread RLTest/redis_std.py Outdated
print(Colors.Bred(f'\t[TERMINATING] out ({process_out}), error ({process_err})'))
# Wait on the process, not pipe EOF: Redis fork children can
# inherit stdout/stderr and outlive their parent.
deadline = time.monotonic() + _TERMINATE_TIMEOUT

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

On master, 30s was only where the old loop started communicate(), which then waited unbounded, so a slow but successful shutdown still passed. Now it's SIGKILL + redis process failure in every lane.

RLTest doesn't pass --save, so Redis's default save points apply and SIGTERM saves an RDB when the dataset is dirty. Under valgrind, that save plus --leak-check=full at exit could exceed 30s. That's reasoning, not measured.

Suggest scaling the grace under --use-valgrind/--sanitizer or making it configurable. Alternatively, run one module valgrind nightly (RTS/JSON) on this branch and grep for sending SIGKILL before merging.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Addressed in 304834d by scaling the default grace to 300 seconds for Valgrind and sanitizer runs; normal runs retain 30 seconds, and the post-SIGKILL wait remains 5 seconds. Explicit terminateRetries/terminateRetrySecs settings retain their existing behavior. Added regressions for both instrumentation modes showing a process still exits cleanly after the old 30-second boundary (using a simulated clock), and documented the policy in README. The 17 focused shutdown/teardown tests pass on Python 3.7 and 3.14; the isolated full unit suite passes 176 tests (5 skipped).

I have not run a full module Valgrind nightly on this branch. The 300-second allowance addresses the overly tight instrumented default while keeping teardown bounded; it is not a measured worst-case limit for all workloads. Updated CI is pending.

Comment thread RLTest/redis_std.py Outdated
if process.poll() is None:
self.shutdownFailed = True
print(Colors.Bred('[TERMINATING] {0} server id {1} did not exit on SIGTERM; sending SIGKILL'.format(role, serverId)))
self._print_shutdown_log(role)

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

This runs before process.kill(), and _print_shutdown_log only catches OSError. _getFileName raises TypeError when outputFilesFormat is None (a StandardEnv built directly rather than via Env), and that escapes before the kill, leaving Redis running. Move it after kill()/wait(), or catch Exception there.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Addressed in 304834d. Log-tail printing now happens after kill/wait, and both path construction and file reading are inside an Exception guard. The regression injects a TypeError from _getFileName and verifies that the Redis stand-in is reaped with -9, its process reference is cleared, the shutdown failure remains recorded, and the diagnostic error is logged. This protects against path-format failures without relying on the direct-constructor example.

Comment thread RLTest/redis_std.py
self.masterProcess = None
self.masterStdout = None
self.masterStderr = None
self.shutdownFailed = False

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Never reset. With --env-reuse, a forced kill during test X (e.g. a mid-test env.stop()/restart) is reported at the final takeEnvDown under whichever test is current then. Minor; resetting it in startEnv would keep the attribution tight.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Addressed attribution in 304834d, but did not reset the flag in startEnv: doing that could erase a forced-shutdown failure when the test immediately restarts Redis. Instead, _runTest records and consumes the failure under the originating test name at the end of that test, before reuse changes the name. Final teardown also consumes the flag when reporting it. Cluster aggregation visits every shard so resetting cannot short-circuit after the first failure.

A regression uses two failed shards and a following test in the reused environment: only the original test is marked failed, all flags are consumed, and final teardown does not blame the following test.

Comment thread RLTest/redis_std.py
p0 = psutil.Process(pid=process.pid)
pchi = p0.children(recursive=True)
for p in pchi:
if platform.system() == 'Darwin' and self.has_interactive_debugger:

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Note: narrowing this to interactive debuggers is fine for plain macOS runs. But in an lldb session still at a breakpoint during teardown (e.g. debugging module shutdown), the inferior now gets SIGKILLed after 30s and the test is marked failed. Previously it waited for the user. Worth a line in the PR description.

Copy link
Copy Markdown
Contributor Author

Choose a reason for hiding this comment

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

Documented in README and the PR description in 304834d. On macOS, debugger-child teardown allows 30 seconds after SIGTERM and then 5 seconds after SIGKILL. An inferior left paused at a breakpoint can now be killed and reported as a failure; teardown no longer waits indefinitely for debugger input. The existing bounded-debugger-wait regression remains passing.

LiranAbir
LiranAbir previously approved these changes Oct 8, 2026
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

Addressed all four points from the second review in new commit 304834d, with individual inline replies:

  • 300-second default grace for Valgrind/sanitizers; 30 seconds for normal runs.
  • Diagnostic log-tail printing follows kill/reap, with path and read errors guarded.
  • Shutdown failures are reported and consumed under the originating test before environment reuse changes attribution; restarting does not erase an unreported failure.
  • Documented the bounded macOS debugger teardown behavior.

Validation: 17 focused shutdown/teardown cases pass on Python 3.7 and 3.14; the isolated Redis 8.8/Linux full unit suite passed 176 tests, 5 skipped. A full module Valgrind nightly was not run. Updated CI is pending and the PR remains a draft.

@LiranAbir, your failure-reporting and server-log-tail requirements are preserved in this follow-up. Your approval was on the previous commit; this update still needs review.

@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

Natural stress reproduction now confirms the shutdown mechanism in both affected tests, without pausing children or changing the RedisJSON tests.

Setup: RedisJSON fbe6eaed5f2cc3d80fc54c9fc840469a6cd840f3, the exact Oct-06 failed-run image digest sha256:20c5071155911763c7b739aff8e4de01bd305dadd64d4bd990ae8383a4f2ffa2 (Redis unstable b540ca49), and RLTest 304834d. Linux amd64 Docker on Apple Silicon, limited to 2 CPUs. The original _stopProcess from the PR base was verified to match the method installed in that nightly image.

  • Current PR: 128/128 stress executions passed with four workers. There were 14 natural initial-AOF shutdown refusals (10 in test_mset_replication_in_aof --use-slaves, 4 in testEveryWriteCommandIsCovered --use-aof). Every affected replica exited with code 0 after the next SIGTERM, in 1.035–1.071 seconds. No SIGKILL. Four additional sequential pilot executions passed.
  • Original shutdown: 32 executions at four workers did not reproduce. An eight-worker pressure batch launched 117 runners; 116 reached the tests and three naturally hung, covering both tests. One separate runner failed importing paella; that worker stopped early. All three hung replicas had finished AOF rewriting, had no remaining fork child, and were still alive at 37 seconds. Python stacks were in _stopProcess -> communicate -> selector.poll, matching the historical stacks. Only after capturing this evidence did the watchdog send a recovery SIGTERM; each replica then exited cleanly. The eventual baseline runner exit codes must not be interpreted as unassisted passes.

Representative original-code timeline: the master finished synchronization and exited at 12:46:55.998. The replica refused SIGTERM at 12:46:56.020 (Writing initial AOF, can't exit.), processed rewrite-child completion at 12:46:56.021, and finished the rewrite at 12:46:56.035. At 37.009 seconds it was still alive with aof_rewrite_in_progress=0, while Python was blocked in communicate(). A recovery SIGTERM ended it immediately.

The pinned Redis source explains this: initial AOF rewrite refusal follows the error path into cancelShutdown(), clearing the pending shutdown request. Finishing the rewrite does not reinstate it. The old RLTest sends SIGTERM only once; the current retry handles this refusal and completes graceful shutdown. SIGKILL remains the fallback.

Master/replica logs, snapshots, stacks, runner output, binary hashes, and reproduction scripts are preserved in the stress evidence bundle. The different worker counts are not a controlled rate comparison. Historical Redis logs remain unavailable, so this reproduces a matching failure on the pinned failing setup rather than proving every past incident had the same cause. No further code change was needed for this reproduced case.

@gabsow
gabsow marked this pull request as ready for review October 8, 2026 12:58
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir We reproduced the hang naturally under stress and confirmed that the latest version fixes the root cause of the reproduced hang, beyond just bounding the wait or killing Redis.

Redis refuses SIGTERM while writing its initial AOF to protect the dataset. The old RLTest sends SIGTERM only once and then waits indefinitely, even after the AOF rewrite finishes. The updated shutdown code retries SIGTERM, allowing Redis to exit cleanly after the rewrite completes.

Evidence:

  • The original shutdown code reproduced three hangs; in each case, the AOF rewrite had finished but Redis remained alive until we sent a recovery SIGTERM after capturing 37 seconds of evidence.
  • With this PR, all 128 stress tests passed. Fourteen naturally occurring initial-AOF shutdown refusals recovered with exit code 0 in about 1.04–1.07 seconds, without SIGKILL.
  • CI is green on the current head, 304834d.

The logs establish this cause for the reproduced hangs; missing historical Redis logs mean we cannot claim every previous nightly timeout had the same cause. The detailed evidence is in #259 (comment).

Your earlier approval was dismissed after the follow-up review fixes. Could you please re-review and approve the current head so we can merge? The PR is now ready for review.

@gabsow
gabsow requested a review from LiranAbir October 8, 2026 13:01
GuyAv46
GuyAv46 previously approved these changes Oct 8, 2026

@GuyAv46 GuyAv46 left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

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

LGTM

@cursor cursor Bot 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.

Stale Bugbot comment from a previous run.

Comment thread RLTest/__main__.py
Comment thread RLTest/env.py
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir Both Bugbot findings are fixed in new commit 3938c1c, with replies on both threads. The three new regression cases reproduce the failures on the previous head and pass with the fixes; all 20 focused shutdown/teardown tests pass. The full Linux comparison shows the same 11 existing failures before and after, with three additional passing regressions. Fresh CI is starting; please re-review this head for approval.

LiranAbir
LiranAbir previously approved these changes Oct 8, 2026
@gabsow
gabsow requested a review from GuyAv46 October 8, 2026 13:43
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

Pre-release verification of approved head 3938c1c: all CI test jobs passed. An additional 32 RedisJSON stress tests passed against the pinned failing-nightly image and module source; three natural initial-AOF shutdown refusals occurred, with no SIGKILL. The disposable test container has been removed. Waiting for the current Bugbot run before merge/release.

@cursor cursor Bot 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.

Stale Bugbot comment from a previous run.

Comment thread RLTest/__main__.py
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir The final Bugbot run found one additional low-severity skip-test attribution issue. Fixed in follow-up commit ef02f7d, with four regression cases; all 24 focused tests pass. Please re-approve this small follow-up once CI is green. After merge I will publish 0.7.31 and open the module dependency-update PRs.

@gabsow
gabsow requested a review from LiranAbir October 8, 2026 13:54
LiranAbir
LiranAbir previously approved these changes Oct 8, 2026

@cursor cursor Bot 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.

Stale Bugbot comment from a previous run.

Comment thread RLTest/__main__.py
Comment thread RLTest/__main__.py
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir The final Bugbot pass found constructor-skip failure leakage and premature PASS output before teardown. Both are fixed in 14345f0; replies and regression evidence are on the threads. All 28 focused tests pass, with the new cases verified against the previous head. Please re-review this follow-up once CI completes; merge and 0.7.31 publication remain on hold until approval and checks pass.

@gabsow
gabsow requested a review from LiranAbir October 8, 2026 14:17

@cursor cursor Bot 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.

Stale Bugbot comment from a previous run.

Comment thread RLTest/__main__.py
@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir The remaining low-severity Bugbot finding is fixed in 21c01ba: SKIP now waits for teardown just like PASS. Expanded coverage includes body and constructor skips with clean/forced shutdown; all 32 focused tests pass. Please review the latest follow-up when CI completes. Release and module update PRs are still waiting for this approval/check cycle.

@gabsow

gabsow commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

@LiranAbir Please give final approval on the current head, 21c01ba. Per Tom, we are stopping further changes for non-blocking Bugbot suggestions; those can be follow-ups. The shutdown fix and regression coverage are in place (32 focused tests pass). Once the current head is approved and required CI is green, I will merge and release, unless a genuine blocking issue is identified.

@cursor cursor Bot 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.

Cursor Bugbot has reviewed your changes using high effort and found 1 potential issue.

Fix All in Cursor

❌ Bugbot Autofix is OFF. To automatically fix reported issues with cloud agents, have a team admin enable autofix in the Cursor dashboard.

Reviewed by Cursor Bugbot for commit 21c01ba. Configure here.

Comment thread RLTest/__main__.py
self.runner._pendingResults = None
if type is None and not self.runner._teardownFailed:
for printer, name in pending:
printer(name)

Copy link
Copy Markdown

Choose a reason for hiding this comment

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

Class results print late or vanish

Medium Severity

EnvScopeGuard now holds every [PASS] and [SKIP] until the guard exits, but one guard wraps an entire test class. Failures still print immediately, so later method [FAIL] lines appear before earlier passes, and a forced class teardown sets _teardownFailed and drops queued passes for methods that already succeeded. Function tests are unaffected because each has its own guard.

Additional Locations (2)
Fix in Cursor Fix in Web

Reviewed by Cursor Bugbot for commit 21c01ba. Configure here.

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