Skip to content

[OPIK-8202] [BE] fix: harden ClickHouseAppender against dropped user logs - #8126

Draft
JetoPistola wants to merge 2 commits into
mainfrom
danield/OPIK-8202-fix-flaky-log-polling-tests
Draft

[OPIK-8202] [BE] fix: harden ClickHouseAppender against dropped user logs#8126
JetoPistola wants to merge 2 commits into
mainfrom
danield/OPIK-8202-fix-flaky-log-polling-tests

Conversation

@JetoPistola

Copy link
Copy Markdown
Contributor

Details

Hardens ClickHouseAppender against two ways it can silently lose user-facing log rows. Both were found while investigating the intermittent Integration Group 14 failures in AutomationRuleEvaluatorsResourceTest, but neither is confirmed to be the cause of that flake — see the caveat below.

flushLogs drains the batch out of the queue before inserting, so any failure past that point loses those events:

  • A failed insert was only logged — never retried, never re-queued.
  • A throw escaping flushLogs permanently cancelled the scheduleAtFixedRate task, silently stopping user-log persistence for the rest of the JVM's life.

This retries the insert, re-queues the batch when retries are exhausted (including on a synchronous throw), and keeps the periodic flush alive across failures. In production the second bug would end evaluator-log persistence until the next restart, so it is worth fixing on its own merits.

Caveat — this does not confirm a fix for the flake. Locally the affected tests fail on unmodified main and still fail with these changes, at rates too close to distinguish over three full-class runs each (3/3 vs 2/3). Local runs are also a poor proxy: they fail far more often than CI does, so something environmental may be involved. The root cause is still unidentified — in failing runs the log write path reports no errors, and the sampler scores the rule the test expects it to skip, so the awaited row is never produced rather than lost. Opening as a draft to get CI signal on the real environment.

The awaits in AutomationRuleEvaluatorsResourceTest now state their timeout explicitly instead of inheriting Awaitility's implicit 10s default. This is a readability change, not a fix: the flush interval is 500ms and the failing tests still fail with a 30s wait, so the rows are not merely late.

Change checklist

  • User facing
  • Documentation update

Issues

  • Resolves #
  • OPIK-8202

AI-WATERMARK

AI-WATERMARK: yes

  • Tools: Claude Code
  • Model(s): Claude Opus 5 (1M context)
  • Scope: full implementation (investigation, appender fix, unit tests)
  • Human verification: pending review — see the caveat in Details; the flake fix is explicitly not verified

Testing

Commands run, from apps/opik-backend:

  • mvn -o compile -DskipTests — passes
  • mvn -o spotless:check — passes
  • mvn -o test -Dtest='ClickHouseAppenderTest' — passes (2/2)

The two new unit tests in ClickHouseAppenderTest are the meaningful coverage here: they fail on unmodified main and pass with this change, and need no containers.

  • whenInsertFailsTransiently__thenEventsAreRetriedAndPersisted — fails a first insert attempt, asserts the events still land.
  • whenFlushThrows__thenSubsequentFlushesStillRun — throws inside a flush, asserts later flushes still run (pins the killed-scheduler bug).

Integration runs of AutomationRuleEvaluatorsResourceTest (Testcontainers: ClickHouse, MySQL, Redis + in-process Dropwizard + WireMock), three consecutive full-class runs each, locally on macOS/Apple Silicon:

  • unmodified main: 3/3 runs failed
  • this branch: 2/3 runs failed

Same failure mode either way (Awaitility ConditionTimeout, Expected size: 1 but was: 0), landing on a different test each run. That difference is not significant at n=3 — this branch is not demonstrated to fix the flake, which is why this is a draft. Local reproduction is also much more frequent than CI's, so the local failures may be partly environmental.

Not run: the full backend suite, and any verification that this changes flake rate in CI — that is what the draft is for.

Documentation

N/A — internal robustness fix with no user-facing or API surface change.

…logs

Investigating the intermittent Integration Group 14 failures in
AutomationRuleEvaluatorsResourceTest surfaced two ways the appender can lose
user-facing log rows outright. Both are fixed here.

flushLogs drains the batch out of the queue before inserting, so any failure
past that point loses those events:

- a failed insert was only logged, never retried or re-queued
- a throw escaping flushLogs cancelled the scheduleAtFixedRate task
  permanently, silently stopping log persistence for the rest of the JVM's life

Retry the insert, re-queue the batch when the retries are exhausted (including
on a synchronous throw), and keep the periodic flush alive across failures. The
two new unit tests fail without these changes and pass with them; they need no
containers.

The awaits in AutomationRuleEvaluatorsResourceTest now state their timeout
explicitly instead of inheriting Awaitility's implicit 10s default. This is a
readability change, not a fix: the flush interval is 500ms, and the failing
tests still fail with a 30s wait, so the rows are not merely late.

This does NOT confirm a fix for the OPIK-8202 flake. Locally the affected tests
fail on unmodified main and still fail with these changes, at rates too close
to distinguish over three runs each. Local runs are also a poor proxy here --
they fail far more often than CI does, so something environmental may be
involved. The root cause of the flake is still unidentified: in failing runs
the log write path reports no errors, and the sampler scores the rule the test
expects it to skip, so the awaited row is never produced rather than lost.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@github-actions github-actions Bot added java Pull requests that update Java code Backend tests Including test files, or tests related like configuration. labels Sep 3, 2026
@github-actions

github-actions Bot commented Sep 3, 2026

Copy link
Copy Markdown
Contributor

⏱️ pre-commit per-hook timing

Hook Description Result Duration
☕ spotless — java backend Format Java code 5.23s
🛡️ semgrep — java backend sql Block SQL injection-prone string formatting 1.84s
Total (2 ran) 7.07s
⏭️ 42 skipped (no matching files changed)
Hook Description Result
🐍 trim trailing whitespace — python sdk Strip trailing whitespace ⏭️
🐍 fix end of files — python sdk Ensure files end in a newline ⏭️
🐍 ruff — python sdk Lint + autofix Python (ruff) ⏭️
🐍 ruff-format — python sdk Format Python code (ruff) ⏭️
🐍 mypy — python sdk Static type check ⏭️
🤖 trim trailing whitespace — optimizer Strip trailing whitespace ⏭️
🤖 fix end of files — optimizer Ensure files end in a newline ⏭️
🤖 check yaml — optimizer Validate YAML syntax ⏭️
🤖 check json — optimizer Validate JSON syntax ⏭️
🤖 check toml — optimizer Validate TOML syntax ⏭️
🤖 check for added large files — optimizer Block large files (>1MB) ⏭️
🔐 detect private key — optimizer Block committed private keys ⏭️
🤖 check for merge conflicts — optimizer Block merge-conflict markers ⏭️
🤖 check for case conflicts — optimizer Block case-only name clashes ⏭️
🤖 pyupgrade — optimizer Modernize Python syntax ⏭️
🤖 ruff — optimizer Lint + autofix Python (ruff) ⏭️
🤖 ruff-format — optimizer Format Python code (ruff) ⏭️
🤖 mypy — optimizer Static type check ⏭️
📓 nbstripout — optimizer notebooks Strip notebook output ⏭️
📝 markdownlint — optimizer Lint Markdown ⏭️
🔤 codespell — optimizer Fix common misspellings ⏭️
📊 radon cc — optimizer Cyclomatic-complexity gate ⏭️
📊 radon raw — optimizer Raw size metrics gate ⏭️
📊 xenon — optimizer Fail on complexity thresholds ⏭️
📊 lizard — optimizer Cyclomatic-complexity gate ⏭️
🧹 vulture — optimizer Find dead code ⏭️
🛡️ trim trailing whitespace — guardrails Strip trailing whitespace ⏭️
🛡️ fix end of files — guardrails Ensure files end in a newline ⏭️
🛡️ ruff — guardrails Lint + autofix Python (ruff) ⏭️
🛡️ ruff-format — guardrails Format Python code (ruff) ⏭️
🛡️ mypy — guardrails Static type check ⏭️
⚓ helm-docs Regenerate Helm chart README ⏭️
block non-public FE plugins Block non-public FE plugins ⏭️
🧪 pre-commit wrapper smoke tests Self-test the wrapper scripts ⏭️
🧪 rebaseline script tests Self-test the changelog re-baseline script ⏭️
🌐 eslint — frontend Lint + autofix JS/TS ⏭️
🌐 typecheck — frontend Whole-project tsc type check ⏭️
📘 eslint — typescript sdk Lint + autofix JS/TS ⏭️
📘 typecheck — typescript sdk Whole-project tsc type check ⏭️
⚙️ actionlint — github workflows Lint GitHub Actions workflows ⏭️
🐳 hadolint — dockerfiles Lint Dockerfiles ⏭️
🌈 zizmor — github workflows security Security-scan GitHub Actions workflows ⏭️

@github-actions

github-actions Bot commented Sep 3, 2026

Copy link
Copy Markdown
Contributor

Python SDK E2E Tests Results (Python 3.10)

296 tests   288 ✅  5m 3s ⏱️
  1 suites    8 💤
  1 files      0 ❌

Results for commit a360c1d.

♻️ This comment has been updated with latest results.

Review feedback on the retry path. A synchronous throw from saveAll means the
batch is rejected before any I/O -- an event missing workspace_id or rule_id
throws IllegalStateException out of the DAO. Requeueing such a batch made every
later flush throw identically, so the appender would spin on a poison batch
forever. Drop it instead, and keep requeueing only for errors signalled through
the returned Mono, which are the genuinely transient ones.

Also hoist the fixed Retry.backoff policy into a constant rather than building
one per flushed batch, and assert the retry attempt count in the transient
test -- it previously passed on requeue-then-reflush alone, so it did not
actually pin Retry.backoff.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@github-actions

github-actions Bot commented Sep 3, 2026

Copy link
Copy Markdown
Contributor

Backend Tests - Integration Group 14

 43 files   43 suites   4m 11s ⏱️
360 tests 357 ✅ 2 💤 0 ❌ 1 🔥
330 runs  327 ✅ 2 💤 0 ❌ 1 🔥

For more details on these errors, see this check.

Results for commit a360c1d.


private static final long INSERT_RETRY_ATTEMPTS = 3;
private static final Duration INSERT_RETRY_MIN_BACKOFF = Duration.ofMillis(100);
private static final Retry INSERT_RETRY = Retry.backoff(INSERT_RETRY_ATTEMPTS, INSERT_RETRY_MIN_BACKOFF);

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.

Hardcoded retry policy blocks operational tuning

ClickHouseAppender hardcodes Retry.backoff(INSERT_RETRY_ATTEMPTS, INSERT_RETRY_MIN_BACKOFF), so operators cannot tune or disable ClickHouse insert retries at runtime — should we move these values into a validated typed configuration block with YAML defaults and environment overrides, then build the policy from that shared configuration?

Severity

Want Baz to fix this for you? Activate Fixer

Other fix methods

Fix in Cursor

Prompt for AI Agents
Before applying, verify this suggestion against the current code. In
`apps/opik-backend/src/main/java/com/comet/opik/infrastructure/log/ClickHouseAppender.java`
around line 33, the ClickHouse insert retry policy is hardcoded in the `INSERT_RETRY`
field, preventing operators from tuning or disabling retries at runtime. Add a validated
typed configuration block with YAML defaults and environment-variable overrides for
retry attempts and backoff, and construct the appender’s retry policy from that shared
configuration instead of hardcoded constants. Update the wiring and any relevant
configuration documentation or tests to verify the defaults, overrides, and
disabled-retry behavior.

Comment on lines +120 to +123
// A synchronous throw from saveAll means the batch itself is rejected before
// any I/O (e.g. an event missing workspace_id or rule_id). Requeueing would
// fail identically on every later flush, so drop it instead of looping.
log.error("Dropping '{}' logs rejected before insert", events.size(), e);

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.

Expected log drops pollute ERROR telemetry

Handled validation failures such as missing workspace_id or rule_id go through log.error(..., e), so expected rejected batches produce ERROR telemetry and stack traces that obscure failures needing investigation — should we log them at WARN with concise bounded context and omit the throwable unless the failure is unexpected?

Severity

Want Baz to fix this for you? Activate Fixer

Other fix methods

Fix in Cursor

Prompt for AI Agents
Before applying, verify this suggestion against the current code. In
`apps/opik-backend/src/main/java/com/comet/opik/infrastructure/log/ClickHouseAppender.java`
around lines 120-123, update the synchronous `saveAll` rejection handling in
`flushLogs()` so expected validation failures are logged at `WARN`, not `ERROR`. Use
concise bounded context such as the affected table and event count, and omit the
throwable to avoid routine stack traces; preserve throwable logging only for genuinely
unexpected failures if the surrounding exception handling can distinguish them.

Comment on lines +66 to +77
@Test
@DisplayName("when the batch is rejected before insert, then it is dropped rather than requeued")
void whenBatchRejectedBeforeInsert__thenItIsDroppedRatherThanRequeued() {
var attempts = new AtomicInteger();

// A synchronous throw means the batch is malformed (e.g. missing workspace_id), so it would
// fail identically forever. Requeueing it would spin the flush thread on a poison batch.
startAppender(events -> {
attempts.incrementAndGet();
throw new IllegalStateException("workspace_id is not set");
});

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.

Exhausted retries can silently lose logs

The new coverage never exhausts INSERT_RETRY, so a regression could still drop batches after all attempts fail while the other retry paths pass. According to the PR description, should we add a deterministic test that fails every attempt, asserts the batch is requeued, then allows a later flush to persist it and verifies the attempt count?

Severity

Want Baz to fix this for you? Activate Fixer

Other fix methods

Fix in Cursor

Prompt for AI Agents
Before applying, verify this suggestion against the current code. In
apps/opik-backend/src/test/java/com/comet/opik/infrastructure/log/ClickHouseAppenderTest.java
around lines 66-86, add a deterministic test covering exhaustion of INSERT_RETRY rather
than only the synchronous-rejection path. Make every insert attempt fail through the
configured retry limit, assert the expected retry attempt count, then allow the
subsequent flush to succeed and verify that the requeued batch is persisted with the
final expected total attempt count. Keep the existing poison-batch test and use
synchronization/await conditions so the test does not depend on timing.

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

Labels

Backend java Pull requests that update Java code 🟡 size/M tests Including test files, or tests related like configuration.

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant