Skip to content

UN-4457 [FIX] Back off when the log stream consumer cannot reach Redis - #2347

Open
ritwik-g wants to merge 6 commits into
mainfrom
fix/log-stream-consumer-backoff
Open

ritwik-g wants to merge 6 commits into
mainfrom
fix/log-stream-consumer-backoff

Conversation

@ritwik-g

@ritwik-g ritwik-g commented Oct 15, 2026 •

Copy link
Copy Markdown
Contributor

What

  • The log stream consumer (workers/log_consumer/redis_stream_consumer.py) now waits before retrying whenever reading from Redis fails. That covers both BLMOVE and the startup recovery of the processing list.
  • The wait starts at 1 s, doubles up to 30 s, and resets on the next successful read.
  • Before each wait it drops the client's connections, so the next attempt opens a fresh one.
  • A shutdown signal still stops the pod promptly while it is waiting.

Why

  • The spin: while Redis was unreachable, the loop retried immediately. The code comment said BLMOVE would block and the client would retry, but neither is true when the connection is refused: create_redis_client gives the client no retry, and a refused connect returns at once.
  • Volume: each consumer pod spun at roughly 500–1,100 retries a second, each logging a ~32-line traceback. That is 17k–36k log lines/s, or 0.7–1.7 GiB of Cloud Logging per minute of Redis downtime, per pod (staging, Oct 1–14).
  • Cost: on staging about $290 in September. One 7h50m outage on Oct 6 produced 348 GiB (~$174) on its own. Triggers include CAST AI drains, spot preemption and Sentinel master loss.
  • Error replies spin the same way, and faster: OOM at maxmemory, READONLY on a standalone client left on a demoted primary, and MISCONF after a failed RDB save. Review measured 7k–20k failures/s locally, so the backoff covers every read failure, not only connection errors.
  • Production and on-prem: the worker is on by default in both, so a Redis failover there would do the same.

How

  • The except Exception around BLMOVE now logs, waits and doubles the wait. The log line names the step that failed (read or recovery). The PG-queue consumer's poll loop already backs off on any exception in the same way (workers/queue_backend/pg_queue/consumer.py).
  • _recover_in_flight runs inside the same try, so a container started while Redis is down waits instead of crashing at startup.
  • Pool disconnect: before each wait, redis_client.connection_pool.disconnect() runs. redis-py keeps the socket after an error reply, so without it a standalone client left on a demoted primary would get READONLY forever. Now the next attempt opens a new connection and re-resolves the host.
  • Shutdown during a wait: _wait_before_reconnect() sleeps in 0.5 s slices and checks the shutdown flag between them. A plain time.sleep(30) would not do, because since PEP 475 a sleep resumes after the signal handler returns. It polls the flag rather than using threading.Event, because Event.set() from the signal handler can deadlock against Event.wait() on the same thread.
  • The loop never gives up. A failure only a restart can fix keeps logging one ERROR every 30 s until the pod is restarted; a rotated Redis password is one, since credentials are read once at start. Earlier revisions of this PR tried exiting after repeated failures. Review showed that turned long outages into crash loops, and that with Sentinel a rotated password surfaces as "no master found", so it was removed.
  • The misleading comment is replaced. No new env vars, and no chart or compose changes.

Can this PR break any existing features. If yes, please list possible items. If no, please explain why. (PS: Admins do not merge the PR without this section filled)

  • Log delivery after Redis recovers is delayed by whatever is left of the current wait, at most about 30 s plus 1 s. A short blip costs 1–2 s.
  • Logs can be dropped during long outages. They queue in Redis meanwhile, but the producer drops new lines once log_stream_queue holds 10,000 (unstract/core/src/unstract/core/pubsub_helper.py). That was already true during an outage.
  • The first failure of any kind now waits 1 s before retrying, where it used to retry at once.
  • Shutdown during a wait takes under about 0.7 s, well inside the chart's 60 s terminationGracePeriodSeconds. Nothing depends on the loop running often: the deployment has no probes and no heartbeat file.
  • Unchanged: a Redis failure between BLMOVE and LREM still exits run(), and the container restarts, as before. In Sentinel mode, create_redis_client still connects eagerly with its own retry before the loop starts.
  • Nobody keys on the old message. "Log stream read failed; retrying" has no log-based metric, alert or runbook (checked across the org). It is now "Log stream read failed; backing off Ns before retrying".

Database Migrations

  • None

Env Config

  • None

Relevant Docs

  • None

Related Issues or PRs

Dependencies Versions

  • None (redis-py 5.2.1, unchanged)

Notes on Testing

Unit tests: new file workers/tests/test_log_stream_consumer_backoff.py, 33 tests. They use the real redis-py exception classes; only the client and the clock are faked. They cover:

  • the wait doubles from 1 s to a 30 s cap for every failure class: connection, timeout, auth, LOADING, Sentinel no-master, OOM, READONLY, MISCONF and a non-Redis ValueError;
  • no failure class ever makes run() give up, even 40 failures in;
  • connection errors and error replies in one outage share a single doubling streak;
  • an idle None reply resets the backoff;
  • every failure drops the connection pool before waiting, and neither a delivered envelope nor an idle read does;
  • startup recovery backs off instead of crashing, and logs as recovery;
  • a log envelope that arrives after an outage is processed and removed from the processing list;
  • a real SIGTERM during a 30 s wait makes run() return in under 2 s;
  • with a fake clock, each wait lasts its full length in slices of at most 1 s.

Mutation testing: each of these mutations fails at least one test:

  • removing the wait;
  • a fixed or non-interruptible wait;
  • never resetting the backoff;
  • dropping the pool after a delivered envelope, or only for some failure kinds;
  • moving startup recovery out of the backoff;
  • reintroducing a give-up exit;
  • mislabelling the step.

Targeted run: 43 passed, also under pytest-xdist -n 4; ruff 0.3.4 clean.

Against a real Redis (redis 7, the real run() and create_redis_client):

Scenario main This PR
Redis stopped (30 s) 1,394 failures/s, 51,581 lines/s, 75% CPU 0.13 failures/s, 4.9 lines/s, 0.03% CPU
Connection refused (30 s) ~2,700 failures/s, ~100k lines/s, 85% CPU 0.17 failures/s, ~6.5 lines/s, 0.1% CPU
Host unresolvable (15 s) 525 failures/s, 22k lines/s 0.27 failures/s, 11 lines/s
Redis paused (read timeout) not a spin not a spin; waits 1, 2, 4 s after each 10 s timeout
OOM (maxmemory 1, 8 s) 6.9k–17.5k failures/s 3 failures; waits 1, 2, 4 s
READONLY (REPLICAOF, 8 s) 9.1k–20.8k failures/s 4 failures; waits 1, 2, 4, 8 s
READONLY, connection reuse same connection every retry (client id 3, 3) new connection each retry (client ids 6, 7)
Startup with Redis down (Redis started 3 s later) crash at startup recovery backed off 1, 2, 4 s, then continued
SIGTERM at the 30 s cap n/a exits in 0.72 s, code 0
  • Waits observed: 1, 2, 4, 8, 16, 30, 30 s. Once at the cap, a pod logs one traceback every 30 s.
  • Envelopes pushed during an outage were processed exactly once after recovery and removed from the processing list.
  • At this rate the Oct 6 outage would have logged about 24 MiB instead of 348 GiB.

For QA:

  1. Stop Redis (docker stop, or scale the Redis StatefulSet to 0) and watch the worker-log-stream-consumer logs. Expect "backing off 1s … 2s … 4s … 30s", then one line every 30 s, with the pod staying up.
  2. Start Redis again and run a workflow. Its execution logs should still arrive, within about 30 s.

Screenshots

  • None

Checklist

I have read and understood the Contribution Guidelines.

🤖 Generated with Claude Code

When BLMOVE failed, run() logged the traceback and retried at once. The
comment assumed BLMOVE blocks and the client retries, but create_redis_client
gives the client no retry and a refused connect returns immediately, so the
loop spun at ~1k iterations/s while Redis was down, each one logging a
~30-line traceback (~0.8 GiB of Cloud Logging per minute, per pod).

Redis connection errors and timeouts now wait 1s, doubling to a 30s cap,
reset by the next reply. The wait polls the shutdown flag every 0.5s so
SIGTERM still exits promptly. Other errors keep the immediate retry.

UN-4457

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@ritwik-g ritwik-g 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.

Standardized review — round 1 (self-review), INITIAL

Reviewed tip: d376b0f77 · merge base 6da459096 · base fetched (base_fetch: ok); branch level with origin/main · 2 files / 300 lines (matches GitHub).
Review: unstract:review-deep (plugin unstract v2.1.72). review-shallow refused this PR: concurrency primitive (signal-interruptible wait in run()); its auth_authz_secrets trigger also fired, on the AuthenticationError class name.

Verdict — REQUEST CHANGES

Summary — Critical: 0 · High: 1 · Medium: 0 · Low: 6 · Lenses run: 19/19 (5 N/A: 5, 7, 12, 14, 18).

Signals: lenses 3, 6, 8, 10, 13, 16, 17, 19 raised (except/backoff/signal-handler path in workers/log_consumer/redis_stream_consumer.py, the new test file, new comments, a changed log line).
Dispatched (no name:): code-reviewer (lenses 1, 2, 3, 9, 10, 15), silent-failure-hunter (3), pr-test-analyzer (13), comment-analyzer (16), whole-diff cold read, and code-reviewer on infra lenses 6, 8, 11, 19 (the code is this session's own). Every agent returned a report.
boundary-sweep: 2 sinks traced, clean. The new branch logs the backoff seconds plus the same redis exception traceback the old line logged. redis-py's connection, auth and Sentinel error messages carry host, port and master name, never credentials.
Security deep-dive: done — no findings at confidence >= 8. The find sub-task returned no candidates, so no filter sub-tasks ran. This is a precision-biased scan, not a clean bill of health.
Lens 15 pinned gate (orchestrator): ruff@0.3.4 check exit 0; ruff@0.3.4 format --check exit 0, on both changed files.
Lens 17: lens17-merge-sweep.sh exit 1. Every hit is in this diff's own two files and agrees with the changed rule. No doc, compose or README restates the retry behaviour.

Findings are posted inline (7).

Unanchored findings

  • The PR body says errors from a server that answered, such as ReadOnlyError, "still retry immediately". That is false in Sentinel mode, where READONLY arrives as ConnectionError and backs off.
  • The PR body's recovery bound ("at most about 30 s plus 1 s") covers BLMOVE failures only. If Redis is lost between BLMOVE and lrem (L204) or during startup _recover_in_flight (L116), the error still exits run() and the container restarts under CrashLoopBackOff (up to 5 minutes). This is pre-existing and deserves its own follow-up, but the body should be scoped accordingly.
  • "Logs queue in Redis meanwhile and are not lost" is conditional: the producer drops once log_stream_queue reaches 10,000 (unstract/core/src/unstract/core/pubsub_helper.py:245).

Lens checklist

  1. Spec & intent — See findings #1
  2. Architectural fit & precedent — See findings #1
  3. Correctness & edge cases — See findings #1
  4. Security — Clean
  5. Data integrity & migrations — N/A — no persisted data, schema or migration; the BLMOVE/LREM envelope path is untouched
  6. Concurrency — Clean
  7. API & contract compatibility — N/A — no wire format, status code or payload change; the changed log text has no consumers (grepped across the org)
  8. Reliability & resilience — See findings #1
  9. Performance & cost — See findings #1
  10. Observability — See findings #2
  11. Operational safety — Clean
  12. LLM/agent-specific — N/A — no model, prompt or agent path
  13. Testing — See findings #1, #4, #7
  14. Dependencies & build — N/A — no dependency or lockfile change
  15. Code quality — Clean
  16. Doc & comment accuracy — See findings #2, #3, #4, #5, #6
  17. Cross-document rule consistency — Clean
  18. On-prem deployment experience — N/A — no chart, sample values, schema, on-prem settings or build path touched
  19. Scaling & workload lifecycle — Clean

Assessed by the orchestrator rather than received from an agent: 4, 5, 7, 12, 14, 15 (pinned gate), 17, 18.

Open questions for the author

  • After Redis recovers, the consumer can stay asleep for up to 30 s while the producer drops lines at 10,000 queued. Is peak log volume safely below ~333 lines/s?
  • Does any deployment (cloud or on-prem) run standalone or URL mode against a managed Redis with maxmemory set? That raises the likelihood of #1.

Assumptions made

  • Production runs redis-py 5.2.1 (workers/uv.lock, <6.0.0). The "no client retry" premise depends on staying below 6.0, where the default retry changes.

cost: agents=6 wall=17:07 lenses-examined=14 files=2 lines=300

Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py
…rrors

Review round 1 measured the same spin on error replies that recur until
Redis changes state: OOM at maxmemory, READONLY on a standalone client left
on a demoted primary, MISCONF after a failed RDB save, plus local errors
such as a TLS misconfiguration. Each returned at once and was retried
immediately, at 7k-20k failures/s locally, faster than the refused-connect
case this branch fixes.

Every BLMOVE failure now takes the same capped backoff, reset by the next
successful BLMOVE. Comments and test docs now state that rule, and the
inconsistent spin figures are replaced by the per-minute log volume.

UN-4457

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@ritwik-g ritwik-g 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.

Standardized review — round 2 (self-review), FOLLOWUP

Reviewed tip: 5f968ccdc · round delta d376b0f77..5f968ccdc · merge base 6da459096 · base fetched (base_fetch: ok); branch level with origin/main · 2 files / 300 lines (matches GitHub).
Review: unstract:review-deep (plugin unstract v2.1.72); review-shallow is ineligible across the whole PR (concurrency primitive).

Verdict — REQUEST CHANGES

Summary — Critical: 0 · High: 0 · Medium: 1 · Low: 5 · Lenses run: 19/19 (5 N/A: 5, 7, 12, 14, 18).

Prior context fetched — followup-fetch.sh exited 0 (6 of 6 files). Previous-review SHA: d376b0f77 (review 5543035654).

Scope change — NO

Signals: lenses 3, 6, 8, 13, 16 raised (the backoff branch widened to except Exception, edited tests, rewritten comments).
Dispatched (no name:): code-reviewer (1, 2, 3, 9, 10, 15), silent-failure-hunter (3), pr-test-analyzer (13), comment-analyzer (16), whole-diff cold read, and code-reviewer on infra lenses 6, 8, 11, 19 (the code is this session's own). All returned reports.
boundary-sweep: 1 sink traced, clean. The single remaining log call carries the backoff seconds and the same exception traceback as before; no credentials reach it.
Security deep-dive: done — no findings at confidence >= 8 (the find sub-task returned no candidates). This is a precision-biased scan, not a clean bill of health.
Lens 15 pinned gate (orchestrator): ruff@0.3.4 check exit 0; format --check exit 0.
Lens 17: lens17-merge-sweep.sh exit 1. Every hit is in this diff's two files, except workers/queue_backend/pg_queue/consumer.py:1077, whose log line describes the same backoff-on-any-failure rule and agrees with it.

Prior findings status

  • #1 [High] Non-connection BLMOVE failures spin, and the test pins the spin → RESOLVED at 5f968ccdc. The single except Exception backs off on every failure (workers/log_consumer/redis_stream_consumer.py:L164-L178). The parametrized test now covers OOM, READONLY, MISCONF and a local ValueError (workers/tests/test_log_stream_consumer_backoff.py:L95-L106), and TestMixedFailures asserts [1, 2, 4]. A mutation restoring the immediate retry fails 5 tests. Measured against a real Redis 7: OOM gave 3 failures in 8 s and READONLY 4 in 8 s, against 7k–20k/s before.
  • #2 [Low] "Server that answered" is not the rule, and "unavailable" is logged for auth errors → RESOLVED at 5f968ccdc. The split is gone, and the log text is now "backing off Ns before retrying".
  • #3 [Low] "Reset by the next reply" overstates the reset → RESOLVED at 5f968ccdc. It now reads "next successful BLMOVE (an envelope or an idle None)" (redis_stream_consumer.py:L66-L67, :L180).
  • #4 [Low] SIGTERM test comment overclaims → PARTIALLY RESOLVED. The new comment says the slice length is "pinned" by TestTheWaitItself, which only bounds it at ≤1 s. Superseded by new finding #9.
  • #5 [Low] Spin figures disagree → RESOLVED at 5f968ccdc. One figure remains (redis_stream_consumer.py:L69). Its sourcing is new finding #11.
  • #6 [Low] LOADING attributed to a replica → RESOLVED at 5f968ccdc ("a restarted Redis still loading its dataset", test L93).
  • #7 [Low] Real-SIGTERM test not run under xdist → RESOLVED. The round-2 test reviewer ran the two files under pytest-xdist -n 4: 31 passed. No code change was needed.

New findings are posted inline (5).

Unanchored findings

  • The PR body's "Notes on Testing" says 17 tests in the new file; pytest collects 21.

Lens checklist

  1. Spec & intent — Clean
  2. Architectural fit & precedent — Clean
  3. Correctness & edge cases — See findings #8
  4. Security — Clean
  5. Data integrity & migrations — N/A — no persisted data, schema or migration; the BLMOVE/LREM envelope path is untouched
  6. Concurrency — Clean
  7. API & contract compatibility — N/A — no wire format, status code or payload change
  8. Reliability & resilience — See findings #8
  9. Performance & cost — Clean
  10. Observability — Clean
  11. Operational safety — Clean
  12. LLM/agent-specific — N/A — no model, prompt or agent path
  13. Testing — See findings #9
  14. Dependencies & build — N/A — no dependency or lockfile change
  15. Code quality — Clean
  16. Doc & comment accuracy — See findings #8, #9, #10, #11, #12
  17. Cross-document rule consistency — Clean
  18. On-prem deployment experience — N/A — no chart, sample values, schema, on-prem settings or build path touched
  19. Scaling & workload lifecycle — Clean

Assessed by the orchestrator rather than received from an agent: 4, 5, 7, 12, 14, 15 (pinned gate), 17, 18.

Open questions / assumptions

  • Does any cloud or on-prem deployment run standalone mode against an endpoint that can demote its primary? That decides how often N1 happens.
  • Assumes redis-py 5.2.1 (<6.0.0), as in round 1.

cost: agents=7 wall=07:47 lenses-examined=14 files=2 lines=300

Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py
Review round 2: redis-py drops the socket only on a connection error or
timeout. After an error reply it keeps the connection, so a standalone
client left on a demoted primary retried the same replica every 30s
forever. Drop the pool before each backoff wait so the next attempt opens
a fresh connection and re-resolves the host. Verified against a real
two-node Redis: client id 3 was reused without the drop; ids 6 and 7
were new with it.

Also tighten comments the review found overstated: most failures recur
at once (not all), the TLS ValueError comes after the TCP connect, the
wait test bounds the slice rather than pinning it, and the log-volume
figure now names where it was measured.

UN-4457

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@ritwik-g ritwik-g 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.

Standardized review — round 3 (self-review), FOLLOWUP

Reviewed tip: 51e97bb71 · round delta 5f968ccdc..51e97bb71 · merge base 6da459096 · base fetched (base_fetch: ok); branch level with origin/main · 2 files / 334 lines (matches GitHub).
Review: unstract:review-deep (plugin unstract v2.1.72); review-shallow is ineligible across the whole PR (concurrency primitive).

Verdict — REQUEST CHANGES

Summary — Critical: 0 · High: 0 · Medium: 2 · Low: 4 · Lenses run: 19/19 (5 N/A: 5, 7, 12, 14, 18).

Prior context fetched — followup-fetch.sh exited 0. Previous-review SHA: 5f968ccdc (review 5543105608).

Scope change — NO

Signals: lenses 3, 6, 8, 13, 16 raised (the pool disconnect in the error path, new tests, rewritten comments).
Dispatched (no name:): code-reviewer (1, 2, 3, 9, 10, 15), silent-failure-hunter (3), pr-test-analyzer (13), comment-analyzer (16), whole-diff cold read, and code-reviewer on infra lenses 6, 8, 11, 19 (the code is this session's own). All returned reports.
boundary-sweep: 1 sink traced, clean. It is unchanged since round 2.
Security deep-dive: done — no findings at confidence >= 8 (the find sub-task returned no candidates). This is a precision-biased scan, not a clean bill of health.
Lens 15 pinned gate (orchestrator): ruff@0.3.4 check exit 0; format --check exit 0.
Lens 17: lens17-merge-sweep.sh exit 1. All hits are in this diff's two files, plus workers/queue_backend/pg_queue/consumer.py:1077, which states the same rule and agrees with it.

Prior findings status

  • #4 [Low] SIGTERM test comment overclaims → RESOLVED at 51e97bb71 ("TestTheWaitItself bounds each slice at 1s").
  • #8 [Medium] Standalone READONLY never reconnects → RESOLVED at 51e97bb71. redis_client.connection_pool.disconnect() runs before every backoff wait (workers/log_consumer/redis_stream_consumer.py:L176-L180); TestReconnectAfterFailure pins drop-then-wait; removing it fails 1 test.
    • Real Redis 7, node demoted with REPLICAOF: without the drop the client reused id 3 on every retry; with it, ids 6 and 7.
    • Round-3 reviewers confirmed the call cannot raise out of the loop (redis-py swallows socket errors on close) and that Sentinel pools re-discover the master on reconnect.
  • #9 [Low] "Pinned" overstates the slice guard → RESOLVED at 51e97bb71.
  • #10 [Low] "Raised locally before any round trip" → PARTIALLY RESOLVED. The comment now says "while wrapping the socket"; the error is actually raised while redis-py configures the SSL context (redis/connection.py:1036-1038), before any wrap.
  • #11 [Low] "Recur at once" too broad; 1.7 GiB unsourced → RESOLVED at 51e97bb71 ("most such failures"; "(staging, Oct 2026)").
  • #12 [Low] Reconnect names fit only connection errors → RESOLVED at 51e97bb71. Every failure now reconnects, so _wait_before_reconnect / _RECONNECT_BACKOFF_* describe what happens.

New findings are posted inline (5).

Unanchored findings

  • No backoff jitter: several replicas would reconnect in lockstep. Moot at the chart default replicas: 1.

Lens checklist

  1. Spec & intent — Clean
  2. Architectural fit & precedent — Clean
  3. Correctness & edge cases — See findings #13
  4. Security — Clean
  5. Data integrity & migrations — N/A — no persisted data, schema or migration; the BLMOVE/LREM envelope path is untouched (the disconnect runs only on the failure path)
  6. Concurrency — Clean
  7. API & contract compatibility — N/A — no wire format, status code or payload change
  8. Reliability & resilience — See findings #13
  9. Performance & cost — Clean
  10. Observability — Clean
  11. Operational safety — Clean
  12. LLM/agent-specific — N/A — no model, prompt or agent path
  13. Testing — See findings #14, #15
  14. Dependencies & build — N/A — no dependency or lockfile change
  15. Code quality — Clean
  16. Doc & comment accuracy — See findings #16, #17
  17. Cross-document rule consistency — Clean
  18. On-prem deployment experience — N/A — no chart, sample values, schema, on-prem settings or build path touched
  19. Scaling & workload lifecycle — Clean

Assessed by the orchestrator rather than received from an agent: 4, 5, 7, 12, 14, 15 (pinned gate), 17, 18.

Open questions / assumptions

  • Assumes redis-py 5.2.1 (<6.0.0).

cost: agents=7 wall=14:17 lenses-examined=14 files=2 lines=334

Comment thread workers/log_consumer/redis_stream_consumer.py
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Review round 3: with backoff on every failure, an error that never clears
in-process (a rotated password read once at start, an ACL or TLS
misconfiguration) left the pod Running, logging one line every 30s and
draining nothing. After 10 consecutive waits at the 30s cap, run() now
exits 1 so the container restarts, re-reads its Secrets, and shows up as
CrashLoopBackOff. Any successful read resets the count.

Tests now also cover a delivered envelope not dropping the pool, and
assert the pool drop for every failure class. Comments: redis-py keeps
the socket after an error reply (not "drops it only on connection
errors"), the TLS ValueError is raised while configuring the SSL
context, and BLMOVE's timeout is no longer the only shutdown checkpoint.

UN-4457

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@ritwik-g ritwik-g 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.

Standardized review — round 4 (self-review), FOLLOWUP

Reviewed tip: 0849d201b · round delta 51e97bb71..0849d201b · merge base 6da459096 · base fetched (base_fetch: ok); branch level with origin/main · 2 files / 396 lines (matches GitHub).
Review: unstract:review-deep (plugin unstract v2.1.72); review-shallow is ineligible across the whole PR (concurrency primitive).

Verdict — REQUEST CHANGES

Summary — Critical: 0 · High: 1 · Medium: 1 · Low: 4 · Lenses run: 19/19 (5 N/A: 5, 7, 12, 14, 18).

Prior context fetched — followup-fetch.sh exited 0. Previous-review SHA: 51e97bb71 (review 5543199920).

Scope change — NO

Signals: lenses 3, 8, 11, 13, 16, 19 raised (the new process-exit path, new tests, rewritten comments).
Dispatched (no name:): code-reviewer (1, 2, 3, 9, 10, 15), silent-failure-hunter (3), pr-test-analyzer (13), comment-analyzer (16), whole-diff cold read, and code-reviewer on infra lenses 6, 8, 11, 19 (the code is this session's own). All returned reports.
boundary-sweep: 2 sinks traced, clean. The new give-up log line carries the wait count, the cap and the same exception traceback.
Security deep-dive: done — no findings at confidence >= 8 (the find sub-task returned no candidates). This is a precision-biased scan, not a clean bill of health.
Lens 15 pinned gate (orchestrator): ruff@0.3.4 check exit 0; format --check exit 0.
Lens 17: lens17-merge-sweep.sh hits are confined to this diff's two files.

Prior findings status

  • #10 [Low] TLS ValueError comment → RESOLVED at 0849d201b ("while redis-py configures the SSL context").
  • #13 [Medium] Permanent errors retried forever → RESOLVED at 0849d201b: after 10 waits at the cap, run() returns 1. Its side effect on long outages is new finding #18.
  • #14 [Medium] No-drop test covered only idle reads → RESOLVED at 0849d201b. It now scripts a delivered envelope; a mutation that drops the pool after lrem fails it.
  • #15 [Low] Pool drop asserted for 2 of 9 classes → RESOLVED at 0849d201b (assert_called_once() in the parametrized test; a partial-drop mutation fails 7 tests).
  • #16 [Low] "Drops the socket only…" overstated → RESOLVED at 0849d201b ("keeps the socket after an error reply").
  • #17 [Low] "Only chance to notice a shutdown" → RESOLVED at 0849d201b (clause removed).

New findings are posted inline (6).

Lens checklist

  1. Spec & intent — See findings #18
  2. Architectural fit & precedent — Clean
  3. Correctness & edge cases — See findings #18
  4. Security — Clean
  5. Data integrity & migrations — N/A — no persisted data, schema or migration; an envelope on the processing list is recovered on restart (same HOSTNAME)
  6. Concurrency — Clean
  7. API & contract compatibility — N/A — no wire format, status code or payload change
  8. Reliability & resilience — See findings #18
  9. Performance & cost — Clean
  10. Observability — Clean
  11. Operational safety — See findings #18, #21
  12. LLM/agent-specific — N/A — no model, prompt or agent path
  13. Testing — See findings #22, #23
  14. Dependencies & build — N/A — no dependency or lockfile change
  15. Code quality — Clean
  16. Doc & comment accuracy — See findings #19, #20
  17. Cross-document rule consistency — Clean
  18. On-prem deployment experience — N/A — no chart, sample values, schema, on-prem settings or build path touched
  19. Scaling & workload lifecycle — See findings #18

Assessed by the orchestrator rather than received from an agent: 4, 5, 7, 12, 14, 15 (pinned gate), 17, 18.

cost: agents=7 wall=11:49 lenses-examined=14 files=2 lines=396

Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py
Review round 4: exiting after any 10 waits at the cap turned a long Redis
outage into a crash loop. The restarted container's startup recovery hit
Redis outside the backoff and died at once, so kubelet's restart back-off
grew to 5 minutes and delivery resumed that long after Redis did, while
the producer dropped lines at its 10k cap.

Now only failures a restart can fix count toward the exit: an
AuthenticationError (a rotated password read once at start), NOPERM, and
local client config errors (ValueError, e.g. TLS). Outages keep backing
off in-process, and any other failure resets the count. Startup recovery
runs inside the same backoff, so a restart during an outage waits instead
of crashing. Verified against a real Redis started 3s after the consumer:
recovery backed off 1s, 2s, 4s and continued without exiting.

UN-4457

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>

@ritwik-g ritwik-g 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.

Standardized review — round 5 (self-review), FOLLOWUP

Reviewed tip: 9d821f4db · round delta 0849d201b..9d821f4db · merge base 6da459096 · base fetched (base_fetch: ok); branch level with origin/main · 2 files / 459 lines (matches GitHub).
Review: unstract:review-deep (plugin unstract v2.1.72); review-shallow is ineligible across the whole PR (concurrency primitive).

Verdict — REQUEST CHANGES

Summary — Critical: 0 · High: 0 · Medium: 5 · Low: 5 · Lenses run: 19/19 (5 N/A: 5, 7, 12, 14, 18).

Prior context fetched — followup-fetch.sh exited 0. Previous-review SHA: 0849d201b (review 5543290502).

Scope change — NO

Signals: lenses 3, 8, 13, 16 raised (the exception-class split for the exit, startup recovery moved into the loop, new tests).
Dispatched (no name:): code-reviewer (1, 2, 3, 9, 10, 15), silent-failure-hunter (3), pr-test-analyzer (13), comment-analyzer (16), whole-diff cold read, and code-reviewer on infra lenses 6, 8, 11, 19 (the code is this session's own). All returned reports. The error-handling reviewer exercised a live Redis, Redis Sentinel and a TLS Redis.
boundary-sweep: 2 sinks traced, clean.
Security deep-dive: done — no findings at confidence >= 8 (the find sub-task returned no candidates). This is a precision-biased scan, not a clean bill of health.
Lens 15 pinned gate (orchestrator): ruff@0.3.4 check exit 0; format --check exit 0.
Lens 17: hits are confined to this diff's two files.

Author decision (10-16), recorded here: after this round the give-up exit is removed entirely. Findings #24, #25, #28, #29 and #30 concern only that mechanism, and the next commit deletes it rather than patching it further. A persistent auth error is then documented as needing a restart, with a follow-up ticket for a liveness signal.

Prior findings status

  • #18 [High] Give-up exit crash-loops long outages → RESOLVED at 9d821f4db. Outages no longer count toward the exit (workers/log_consumer/redis_stream_consumer.py:L188-L191), and startup recovery runs inside the backoff (:L175-L179). Verified on a real Redis started 3 s after the consumer: recovery backed off 1, 2, 4 s and continued without exiting. Sentinel's eager client construction is new finding #26.
  • #19 [Medium] "Must not kill the pod" contradicted the exit → RESOLVED at 9d821f4db (clause removed).
  • #20 [Low] ACL example and "~5 min" → PARTIALLY RESOLVED. The wording changed, but NOPERM and the "at least ~5.5 min" figure are still wrong (#29, #30). Becomes OBSOLETE when the exit is removed.
  • #21 [Low] docker-compose restart keeps the old env → RESOLVED at 9d821f4db (stated in the comment).
  • #22 [Low] Give-up traceback not asserted → RESOLVED at 9d821f4db (assert last.kwargs.get("exc_info") is True; a mutation dropping it fails 3 tests).
  • #23 [Low] Two wall-clock shutdown tests → NOT RESOLVED. They are unchanged and kept deliberately: the real-signal test is the only end-to-end SIGTERM proof, and both bounds are generous (2 s against 0.3–0.5 s).

New findings are posted inline (9).

Unanchored findings

  • lrem in the finally is still outside any handler: a Redis failure between BLMOVE and LREM exits run() and replays the envelope once on restart. This is pre-existing, and the comments must not claim that every Redis failure backs off.

Lens checklist

  1. Spec & intent — See findings #24
  2. Architectural fit & precedent — Clean
  3. Correctness & edge cases — See findings #24, #25
  4. Security — Clean
  5. Data integrity & migrations — N/A — no persisted data, schema or migration
  6. Concurrency — Clean
  7. API & contract compatibility — N/A — no wire format, status code or payload change
  8. Reliability & resilience — See findings #24, #26, #29
  9. Performance & cost — Clean
  10. Observability — See findings #32
  11. Operational safety — Clean
  12. LLM/agent-specific — N/A — no model, prompt or agent path
  13. Testing — See findings #27, #28
  14. Dependencies & build — N/A — no dependency or lockfile change
  15. Code quality — See findings #31
  16. Doc & comment accuracy — See findings #25, #26, #30
  17. Cross-document rule consistency — Clean
  18. On-prem deployment experience — N/A — no chart, sample values, schema, on-prem settings or build path touched
  19. Scaling & workload lifecycle — Clean

Assessed by the orchestrator rather than received from an agent: 4, 5, 7, 12, 14, 15 (pinned gate), 17, 18.

cost: agents=7 wall=10:00 lenses-examined=14 files=2 lines=459

Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py Outdated
Comment thread workers/tests/test_log_stream_consumer_backoff.py
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py Outdated
Comment thread workers/log_consumer/redis_stream_consumer.py
Review round 5: the exit-after-repeated-failures path reliably helped only
a standalone client with a rotated password. With Sentinel the same
rotation surfaces as MasterNotFoundError (an outage), most TLS mistakes
arrive as ConnectionError, and each patch to the exit turned up new edge
cases. Remove it: every read or startup-recovery failure backs off 1s to
30s with a fresh connection, indefinitely. A failure only a restart can fix
keeps logging an ERROR every 30s, as documented at the backoff constants.

The failure log now names the step (recovery or read). A parametrized test
pins that no failure class ever makes run() give up.

UN-4457

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
@sonarqubecloud

Copy link
Copy Markdown

@ritwik-g ritwik-g 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.

Self-review round 6 — FOLLOWUP (review-deep)

Round tip: 6a4557d1933ea6c8748b776fd0e25e18a06945e5. Round delta: 9d821f4db..6a4557d19 (the give-up exit is dropped and the loop always backs off). Review: unstract:review-deep; lite is ineligible because the PR adds a concurrency primitive and retry logic.

Verdict — APPROVE WITH NITS

Summary — Critical: 0 · High: 0 · Medium: 0 · Low: 3 · Lenses run: 19/19

Prior context fetched

  • followup-fetch.sh exited 0 (6 of 6 fetches).
  • The "since" boundary is the previous review's SHA, 9d821f4db5e3671ecb4bb39c1382013678decd59 (review 5543390630).

Scope change — NO. The delta only removes code (_RESTART_FIXABLE_ERRORS, _MAX_WAITS_AT_BACKOFF_CAP, waits_at_cap, the return 1 path) and relabels the failure log.

Security deep-dive: done, 0 findings. The find sub-task ran and returned no candidates, so no filter sub-tasks were needed.

boundary-sweep: 2 sinks traced, clean. The ERROR log with exc_info and the recovery WARNING count carry host:port or Sentinel service names only, never credentials.

Prior findings status

  • #20 [Low] The give-up comment overstates what a restart fixes and how long it takes → OBSOLETE. The give-up exit and its comment are removed at 6a4557d. workers/log_consumer/redis_stream_consumer.py:66-72 now says the loop never gives up.
  • #23 [Low] Two shutdown tests use real wall-clock time with a 2 s bound → WAIVED. A real SIGTERM has to be delivered against a real time.sleep to test PEP 475 resumption. The observed exit is ~0.7 s against the 2 s bound, and TestTheWaitItself covers the slicing on a fake clock.
  • #24 [Medium] With Sentinel, a rotated password surfaces as MasterNotFoundError → OBSOLETE. No error classification remains. Every failure backs off (redis_stream_consumer.py:171-190).
  • #25 [Medium] "Local client config such as TLS" is false → OBSOLETE. The claim is removed with the restart-fixable set.
  • #26 [Medium] In Sentinel mode a restart during an outage still crashes in create_redis_client → PARTIALLY RESOLVED.
    • The code comment is now scoped to the startup LMOVE (redis_stream_consumer.py:164), and the PR body states that Sentinel still connects eagerly before the loop.
    • Residual: the test comment at workers/tests/test_log_stream_consumer_backoff.py:199, "A restart during an outage must wait in-process, not crash-loop", is true only in standalone mode. It is accepted as a Low test-comment wording item; the Sentinel constructor's own retry is unchanged by this PR.
  • #27 [Medium] "Outages never give up" is tested for refused connects only → RESOLVED in 6a4557d. TestNeverGivesUp (test_log_stream_consumer_backoff.py:176-195) is parametrized over 9 failure classes. Reintroducing a return 1 fails all 9 (mutation-verified).
  • #28 [Medium] The give-up tests inject hand-built exceptions → OBSOLETE. The give-up tests are removed.
  • #29 [Low] A restart does not fix NOPERM → OBSOLETE. No restart path remains.
  • #30 [Low] "At least ~5.5 min" is wrong → OBSOLETE. The figure is removed.
  • #31 [Low] One comment line is about 130 characters → OBSOLETE. The line is removed.
  • #32 [Low] A startup-recovery failure is logged as "Log stream read failed" → RESOLVED in 6a4557d. The label is computed in except (redis_stream_consumer.py:177-182) and pinned both ways by tests (test_log_stream_consumer_backoff.py:118-127 and :209-213).

New findings

#33, #34 and #35 are posted inline below (all Low, below the floor and accepted as notes; #35 is pre-existing and a candidate follow-up).

Lens checklist

  1. Spec & intent — Clean (code-reviewer). Title follows TICKET [TYPE] text.
  2. Architectural fit — Clean (code-reviewer). Mirrors the PG-queue consumer's backoff.
  3. Correctness & edge cases — See findings #33 (code-reviewer, silent-failure-hunter, cold read).
  4. Security — Clean (security deep-dive done, 0 findings; boundary sweep clean; assessed by orchestrator).
  5. Data integrity & migrations — N/A — no schema, migration or persisted-format change (assessed by orchestrator).
  6. Concurrency — Clean (infra agent).
  7. API & contract compatibility — N/A — no wire, payload or status change. The log message text has no consumers (checked in an earlier round; assessed by orchestrator).
  8. Reliability & resilience — See findings #35 (infra agent, cold read).
  9. Performance & cost — Clean (code-reviewer).
  10. Observability — Clean (code-reviewer).
  11. Operational safety — Clean (infra agent). The missing liveness signal is tracked as a follow-up ticket.
  12. LLM/agent — N/A — no model, prompt or agent code (assessed by orchestrator).
  13. Testing — Clean (pr-test-analyzer; mutation-verified).
  14. Dependencies & build — N/A — no dependency or build change (assessed by orchestrator).
  15. Code quality — Clean (code-reviewer). Pinned gate uvx ruff@0.3.4 check and format --check are clean on both files (run by orchestrator).
  16. Doc & comment accuracy — See findings #33, #34 (comment-analyzer).
  17. Cross-document rule consistency — Clean (lens17-merge-sweep.sh exit 1, every hit consistent with HEAD; run by orchestrator).
  18. On-prem deployment experience — N/A — no chart, values, schema or on-prem path touched (assessed by orchestrator).
  19. Scaling & workload lifecycle — Clean (infra agent). The 0.5 s shutdown poll sits well inside the 60 s grace period and the compose default of 10 s.

Open questions / assumptions

  • I assume a manual restart, plus the follow-up liveness/alert ticket, is the remedy for restart-only failures such as a rotated password. The code comment states this.

cost: agents=8 wall=06:36 lenses-examined=14 files=2 lines=389

Comment thread workers/log_consumer/redis_stream_consumer.py
Comment thread workers/log_consumer/redis_stream_consumer.py
Comment thread workers/log_consumer/redis_stream_consumer.py
@ritwik-g
ritwik-g marked this pull request as ready for review October 16, 2026 05:50
@greptile-apps

greptile-apps Bot commented Oct 16, 2026 •

Copy link
Copy Markdown
Contributor

via Greptile

RetriggerView in GreptileConfidence Score: 5/5

[High impact] The PR appears safe to merge; no actionable issues were found.

Summary

The Redis log consumer now waits after failed reads and startup recovery attempts instead of retrying immediately.

  • The log consumer waits before retrying Redis failures.

No actionable issues were found. Tests were inspected but not run.

Acknowledged limits:

  • ritwik-g explicitly accepts up to about 30 seconds of added delivery delay after Redis recovers.
  • ritwik-g explicitly keeps indefinite retries for failures that require a restart, including rotated credentials, to avoid crash loops.
  • ritwik-g identifies eager Sentinel startup retries and failures during LREM as unchanged and outside this fix.

Diagram

%%{init: {'theme': 'neutral'}}%%
flowchart TD
  A[Start] --> B[Recover this pod's pending logs]
  B --> C[Read from Redis]
  B -->|Failure| D[Log error and disconnect pool]
  C -->|Failure| D
  D --> E[Wait 1 to 30 seconds; check shutdown]
  E -->|Shutdown requested| H[Stop]
  E -->|Retry| F{Recovery finished?}
  F -->|No| B
  F -->|Yes| C
  C -->|Success| G[Reset wait to 1 second]
  G --> I[Handle and remove log, if present]
  I --> J{Shutdown requested?}
  J -->|No| C
  J -->|Yes| H
Loading

Reviews (1) · Last reviewed commit: "fix: drop the give-up exit; the log stre..." · Reviewed by Greptile

@github-actions

Copy link
Copy Markdown
Contributor

Unstract test results

Per-group results

Status Group Tier Passed Failed Errors Skipped Duration (s)
✅ e2e-api-deployment e2e 3 0 0 0 16.6
✅ e2e-coowners e2e 1 0 0 0 1.3
✅ e2e-etl e2e 1 0 0 0 12.5
✅ e2e-login e2e 2 0 0 0 1.2
✅ e2e-prompt-studio e2e 1 0 0 0 9.7
✅ e2e-smoke e2e 2 0 0 0 1.5
✅ e2e-workflow e2e 1 0 0 0 12.5
✅ frontend unit 625 0 0 0 18.7
✅ integration-backend integration 638 0 0 26 53.7
✅ integration-connectors integration 1 0 0 7 8.7
✅ integration-workers integration 164 0 0 1 35.0
❌ ui e2e 0 1 0 0 0.0
✅ unit-backend unit 1567 0 0 1 52.0
✅ unit-connectors unit 82 0 0 0 11.9
✅ unit-core unit 281 0 0 0 3.3
✅ unit-platform-service unit 18 0 0 0 2.8
✅ unit-rig unit 120 0 0 0 4.6
✅ unit-runner unit 12 0 0 0 3.1
✅ unit-sdk1 unit 843 0 0 0 41.4
✅ unit-tool-sidecar unit 8 0 0 0 1.8
✅ unit-workers unit 1465 0 0 1 135.1
TOTAL 5835 1 0 36 427.4

Critical paths

⚠️ Critical paths not yet covered

  • workflow-execution-fan-out — Multi-file workflow execution fans out to file-processing workers and rejoins. (declared coverage: no groups declared)
✅ Covered critical paths
  • auth-login — covered by e2e-login
  • adapter-register-llm — covered by integration-backend
  • workflow-author — covered by integration-backend
  • co-owner-manage — covered by integration-backend, e2e-coowners
  • workflow-create-execute — covered by e2e-workflow
  • api-deployment-provision — covered by integration-backend
  • api-deployment-auth — covered by integration-backend
  • api-deployment-run — covered by e2e-api-deployment
  • mcp-server-auth — covered by integration-backend
  • mcp-platform-auth — covered by integration-backend
  • platform-key-whoami — covered by integration-backend
  • prompt-studio-author — covered by integration-backend
  • prompt-studio-fetch-response — covered by e2e-prompt-studio
  • connector-register-test — covered by integration-backend
  • pipeline-etl-execute — covered by e2e-etl
  • usage-aggregate-read — covered by integration-backend
  • usage-token-tracking — covered by e2e-api-deployment
  • callback-result-delivery — covered by e2e-api-deployment

@muhammad-ali-e muhammad-ali-e 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.

LGTM. The change is limited to the failure path of the log stream consumer, so healthy-Redis behaviour is unchanged, and all review threads are resolved.

Optional, non-blocking: since this is the public repo, consider dropping the staging $ cost figures from the PR description.


Generated by Claude Code

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.

2 participants