Skip to content

fix: flush() delivers pending events without waiting out flush_interval - #797

Merged
marandaneto merged 6 commits into
mainfrom
posthog-code/flush-bypasses-flush-interval
Aug 5, 2026
Merged

fix: flush() delivers pending events without waiting out flush_interval#797
marandaneto merged 6 commits into
mainfrom
posthog-code/flush-bypasses-flush-interval

Conversation

@posthog

@posthog posthog Bot commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

💡 Motivation and Context

Why: this came out of a scheduled audit of posthog-python against the cross-SDK contracts in PostHog/sdk-specs, looking for places where the SDK does not yet satisfy the spec.

The flush contract says an explicit flush must not wait for the batching timer:

Consumer.next() accumulates until it has flush_at items or flush_interval elapses, and there was no channel from flush() to a consumer telling it to stop waiting — _Lane.flush() only blocks on queue.join(). So a consumer holding fewer than flush_at events kept waiting for more, and the caller waited with it. Measured on defaults (flush_at=100, flush_interval=5.0) against a local mock server:

scenario before after
capture() × 1, then flush() 4.996s 0.003s
capture() × 1000, then flush() 4.996s 0.002s
flush() on an empty queue 0.000s 0.000s
flush_interval=20, 1 event, default flush() 10.0s, 0 events delivered 0.002s, 1 delivered

The last row is the sharp edge: flush() defaults to timeout_seconds=10, so any flush_interval above that meant the default flush() gave up before the consumer ever tried to send, logged "flush ran out of budget", and delivered nothing.

Change

DrainSignal is a generation counter shared by a lane and its consumers. _Lane.flush() (and _Lane.join()) bump it before waiting. While a request is outstanding a consumer takes only what is already queued — non-blocking gets, no timer wait — and uploads as soon as the queue comes up empty, which is also when it marks the request served.

A consumer that is already holding a partial batch is parked on queue.get() and cannot see a flag flip, so it now waits in slices (DRAIN_POLL_INTERVAL, 50ms) instead of one long block. An idle consumer still parks for the whole interval: anything a caller enqueued before flush() is already in the queue and wakes its get() by itself, so there is nothing for a flush to wait on.

Batching without an explicit flush is unchanged. A slice expiring only re-arms the wait; the batch window still closes on flush_at, BATCH_SIZE_LIMIT, or a full flush_interval. Verified directly: one event every 100ms for 1s with flush_at=100, flush_interval=1.0 produces a single batch of 10 both before and after.

⚠️ Behavior change

  • flush() and shutdown() return much sooner. Any code that (perhaps accidentally) relied on flush() blocking for roughly flush_interval will see it return promptly instead.
  • Batches produced during an explicit flush can be smaller than flush_at, since the point is to stop waiting for a full batch. The spec allows this; a flush of a large backlog still sends full-size batches (verified: 1000 queued events → ten batches of 100).
  • No public signature changes. Consumer gains an optional drain_signal argument; constructed without one it behaves exactly as before.

Not fixed here (follow-up): shutdown() still spends up to one flush_interval inside join(), because a consumer parked with an empty batch only notices pause() when its get() times out. That is a thread-teardown delay, not a delivery delay — events are already flushed by then — and waking those consumers needs a separate mechanism (a queue sentinel per consumer), so it is left out to keep this change focused. It is already an improvement: shutdown() with one queued event previously cost two intervals, now one.

💚 How did you test it?

  • New unit tests in posthog/test/test_consumer.py (drain returns a partial batch without waiting; still respects flush_at; request is served once the queue empties, so no spin; consecutive requests each drain; a request that lands while the consumer is parked mid-batch wakes it; a consumer with no drain signal batches exactly as before) and posthog/test/test_client.py (flush() does not wait out flush_interval; delivers when flush_interval exceeds the flush timeout; batches stay whole).
  • Both new client-level tests were confirmed to fail with the drain signal neutralized, so they pin the regression rather than passing vacuously.
  • Full suite: pytest --timeout=120 --ignore=integration_tests --ignore=posthog/test/ai1306 passed, 0 failed. (posthog/test/ai needs live provider credentials unavailable in this environment; those tests were not run and are untouched here.)
  • ruff format --check ., ruff check ., mypy --no-site-packages --config-file mypy.ini . | mypy-baseline filter, and python .github/scripts/check_public_api.py all clean; the public API snapshot is regenerated.
  • One unrelated test needed a companion fix: test_message_only_error_logs_include_posthog_prefix asserted on the entire capture_message_only_logs() stream, which taps the process-wide posthog logger for the ~5s that Consumer.upload() takes. Because this change makes the suite ~40s faster, feature-flag warnings from background pollers left running by earlier tests started landing inside that window and failed the equality assertion (it went red in CI on the first push). Second commit narrows the assertion to the "error uploading" line — what the test is actually about, and how every other user of that helper asserts.
  • Manual: drove a real Client against a local mock HTTP server to produce the timing table above, plus repeated flushes, four concurrent flushes, and a thread=4 lane (all drain in ~50ms with no lost or duplicated events).

📝 Checklist

  • I reviewed the submitted code.
  • I added tests to verify the changes.
  • I updated the docs if needed. — no doc changes; flush()'s documented contract is what this makes true.
  • No breaking change or entry added to the changelog. — behavior change described above; changeset added.

If releasing new changes

  • Ran sampo add to generate a changeset file — hand-written at .sampo/changesets/flush-bypasses-flush-interval.md (the sampo CLI isn't available in this environment); please sanity-check the format.

🤖 Agent context

Autonomy: Fully autonomous

Opened by the SDK Spec Compliance Enforcer loop, which audits posthog-python against the contracts in PostHog/sdk-specs. This run re-checked the 22 spec capabilities whose Applicability is both (so in scope for a server SDK) using parallel read-only Claude Code sub-agents, then confirmed each candidate finding by running the SDK locally against a mock server.

This violation was chosen because the spec language is unambiguous, it is confirmed by measurement rather than by reading, and it has real consequences for the recommended serverless pattern (capture() then flush()/shutdown() before the process exits) — including outright non-delivery when flush_interval exceeds the flush timeout. The concurrency design was picked over two alternatives: a plain threading.Event (a shared flag cleared by whichever flush finishes first can strand a concurrent flush for another interval) and a queue sentinel per consumer (wakes parked consumers with no polling, but unconsumed sentinels leave unfinished_tasks non-zero, which would hang a later queue.join()).

Runners-up deliberately left alone: feature_enabled() has no default_value, which the recently updated is-feature-enabled spec makes a SHALL — but the method is deprecated in favour of evaluate_flags(), so it is a spec-vs-roadmap question for humans. alias() and group_identify() don't validate their required identities, which two @both scenarios require them to drop with a warning — correct per spec, but it turns currently-emitted (malformed) events into dropped ones, so it wants a human call. The $feature_flag_called dedupe map clears itself wholesale at capacity, which the feature-flag-called-tracker spec explicitly says SHOULD NOT happen; worth its own PR.

Agent-authored — requires human review; not self-merged.

The sdk-specs `flush` contract requires an explicit flush to bypass the
batching thresholds: "Do not wait for `flushAt` or `flushInterval`;
attempt delivery now" (openspec/specs/flush/spec.md, Requirement
"Canonical flush behavior", Behavior #2).

`Consumer.next()` accumulates until it has `flush_at` items or
`flush_interval` elapses, and nothing connected `flush()` to a consumer
parked mid-batch — `_Lane.flush()` only blocked on `queue.join()`. So a
consumer holding a partial batch kept waiting for more events and the
caller waited with it: on defaults, `capture()` + `flush()` took ~5s.
Worse, `flush()` defaults to `timeout_seconds=10`, so any `flush_interval`
above that made the default `flush()` give up and deliver nothing.

Add `DrainSignal`, a generation counter shared by a lane and its
consumers. `flush()` and `join()` bump it; while a request is outstanding
a consumer takes only what is already queued and uploads as soon as the
queue comes up empty, which is when it marks the request served. A
consumer already holding a partial batch waits in slices so it notices a
request that lands while it is parked; an idle consumer still parks for
the whole interval, since a new put wakes its get() anyway.

Timer-based batching without an explicit flush is unchanged: a slice
expiring only re-arms the wait, and the batch window still closes on
`flush_at`, the batch size limit, or a full `flush_interval`.


Generated-By: PostHog Code
Task-Id: 2bc2b5c5-03be-4da2-b7df-97c3364b33c9
@github-actions

github-actions Bot commented Jul 29, 2026

Copy link
Copy Markdown
Contributor

posthog-python Compliance Report

Date: 2026-08-05 12:47:17 UTC
Duration: 256377ms

✅ All Tests Passed!

111/111 tests passed


Capture_V1 Tests

94/94 tests passed

View Details
Test Status Duration
Endpoint And Method.Targets V1 Endpoint 517ms
Endpoint And Method.Does Not Use Legacy Endpoints 510ms
Required Headers.Has Authorization Bearer Header 511ms
Required Headers.Has Content Type Json 510ms
Required Headers.Has Posthog Sdk Info Format 510ms
Required Headers.Has Posthog Attempt Header 510ms
Required Headers.Has Posthog Request Id 510ms
Required Headers.Has Posthog Request Timestamp 510ms
Required Headers.Has User Agent 511ms
Body Format.Body Has Created At And Batch 516ms
Body Format.No Api Key In Body 511ms
Body Format.No Sent At In Body 510ms
Event Format.Event Has Required Root Fields 511ms
Event Format.Event Uuid Is Valid 509ms
Event Format.Event Timestamp Is Rfc3339 510ms
Event Format.Distinct Id Is String 510ms
Event Format.Distinct Id At Root Not Properties 510ms
Event Format.Custom Properties Preserved 510ms
Event Format.Set Properties Preserved 510ms
Event Format.Set Once Properties Preserved 510ms
Event Format.Groups Properties Preserved 511ms
Event Format.Sdk Generates Uuid If Not Provided 510ms
Event Format.Event Has Required Root Fields Batch 513ms
Event Format.Event Uuid Is Valid Batch 514ms
Event Format.Event Timestamp Is Rfc3339 Batch 513ms
Event Format.Distinct Id Is String Batch 514ms
Event Format.Distinct Id At Root Not Properties Batch 513ms
Event Format.Custom Properties Preserved Batch 514ms
Event Format.Set Properties Preserved Batch 513ms
Event Format.Set Once Properties Preserved Batch 513ms
Event Format.Groups Properties Preserved Batch 514ms
Event Format.Sdk Generates Uuid If Not Provided Batch 514ms
Batch Behavior.Multiple Events In Single Batch 518ms
Batch Behavior.Batch Envelope Smoke 515ms
Batch Behavior.Flush With No Events Sends Nothing 506ms
Batch Behavior.Flush At Triggers Batch 1011ms
Batch Behavior.Created At Reflects Batch Creation Time 511ms
Deduplication.Generates Unique Uuids 517ms
Deduplication.Different Events Same Content Different Uuids 513ms
Deduplication.Preserves Uuid On Retry 6519ms
Deduplication.Preserves Timestamp On Retry 6516ms
Deduplication.Preserves Uuid And Timestamp On Batch Retry 6519ms
Deduplication.No Duplicate Events In Batch 518ms
Header Behavior On Retry.Attempt Header Starts At One 511ms
Header Behavior On Retry.Attempt Header Increments On Retry 13527ms
Header Behavior On Retry.Request Id Preserved On Retry 6519ms
Header Behavior On Retry.Different Requests Have Different Request Ids 3020ms
Header Behavior On Retry.Request Timestamp Changes On Retry 6520ms
Response Format Validation.Success Response Has Uuid Keyed Results 510ms
Response Format Validation.Success Response Has Ok For Each Event 514ms
Response Format Validation.Success No Retry After When All Ok 513ms
Response Format Validation.Success Retry After Present When Retry Events 1515ms
Response Format Validation.Success No Retry After When Drop Only 513ms
Response Format Validation.Response Echoes Request Id 510ms
Retry Behavior.Retries On 408 6519ms
Retry Behavior.Retries On 500 6519ms
Retry Behavior.Retries On 503 8523ms
Retry Behavior.Retries On 504 6519ms
Retry Behavior.Retryable Errors Have Retry After 3517ms
Retry Behavior.Respects Retry After On Retryable Error 11523ms
Retry Behavior.Does Not Retry On 400 2514ms
Retry Behavior.Does Not Retry On 401 2513ms
Retry Behavior.Does Not Retry On 402 2514ms
Retry Behavior.Does Not Retry On 413 2514ms
Retry Behavior.Does Not Retry On 415 2513ms
Retry Behavior.Non Retryable Errors Have No Retry After 2514ms
Retry Behavior.Implements Backoff 22533ms
Retry Behavior.Max Retries Respected 22537ms
Partial Batch Handling.Handles 200 Full Success 2513ms
Partial Batch Handling.Handles 200 With All Ok 3515ms
Partial Batch Handling.Does Not Retry Dropped Events 3515ms
Partial Batch Handling.Does Not Retry Limited Events 3513ms
Partial Batch Handling.Prunes Ok Events On Partial Retry 6522ms
Partial Batch Handling.Prunes Dropped Events On Partial Retry 6518ms
Partial Batch Handling.Retries Only Retry Events From Partial 6521ms
Partial Batch Handling.Partial Retry Preserves Uuids 6520ms
Partial Batch Handling.Partial Retry Attempt Header Increments 6522ms
Partial Batch Handling.Partial Retry Request Id Preserved 6521ms
Partial Batch Handling.Respects Retry After On Partial 8517ms
Partial Batch Handling.Unknown Result Treated As Terminal 3514ms
Partial Batch Handling.Mixed Ok Drop Limited No Retry 3518ms
Compression.Sends Gzip Content Encoding 510ms
Compression.No Content Encoding When Disabled 510ms
Compression.Compressed Body Is Decompressible 511ms
Error Handling.Does Not Retry On Unknown 4Xx 2513ms
Event Options.Cookieless Mode Override 510ms
Event Options.Disable Skew Correction Override 510ms
Event Options.Process Person Profile Override 509ms
Event Options.Product Tour Id Override 510ms
Event Options.Unset Options Omitted 511ms
Event Options.Options Override In Batch 514ms
Geoip And Historical Migration.Geoip Disable Injected Into Properties 509ms
Geoip And Historical Migration.Historical Migration Set In Body 510ms
Geoip And Historical Migration.Historical Migration Absent By Default 510ms

Feature_Flags Tests

17/17 tests passed

View Details
Test Status Duration
Request Payload.Request With Person Properties Device Id 10ms
Request Payload.Flags Request Uses V2 Query Param 9ms
Request Payload.Flags Request Hits Flags Path Not Decide 9ms
Request Payload.Flags Request Omits Authorization Header 9ms
Request Payload.Token In Flags Body Matches Init 9ms
Request Payload.Groups Round Trip 9ms
Request Payload.Groups Default To Empty Object 9ms
Request Payload.Disable Geoip False Propagates As Geoip Disable False 9ms
Request Payload.Disable Geoip Omitted Defaults To False 9ms
Request Payload.Flag Keys To Evaluate Contains Only Requested Key 9ms
Request Lifecycle.No Flags Request On Init Alone 3ms
Request Lifecycle.No Flags Request On Normal Capture 509ms
Request Lifecycle.Two Flag Calls Produce Two Remote Requests 13ms
Request Lifecycle.Mock Response Value Is Returned To Caller 9ms
Retry Behavior.Retries Flags On 502 313ms
Retry Behavior.Retries Flags On 504 313ms
Side Effect Events.Get Feature Flag Captures Feature Flag Called Event 511ms

`capture_message_only_logs()` attaches a DEBUG handler to the process-wide
"posthog" logger, and `Consumer.upload()` spans a whole `flush_interval`,
so any background thread left running by an earlier test writes into the
same captured stream. Asserting on the entire capture made the test
depend on suite-wide timing: with flush() no longer waiting out
flush_interval the suite runs ~40s faster, and feature-flag warnings from
lingering pollers now reliably land inside that 5s window.

Assert on the "error uploading" line instead, which is what the test is
about. Matches how every other user of this helper asserts.


Generated-By: PostHog Code
Task-Id: 2bc2b5c5-03be-4da2-b7df-97c3364b33c9
@github-actions

github-actions Bot commented Aug 5, 2026

Copy link
Copy Markdown
Contributor

This PR hasn't seen activity in a week! Should it be merged, closed, or further worked on? If you want to keep it open, post a comment or remove the stale label – otherwise this will be closed in another week.

@github-actions github-actions Bot added the stale label Aug 5, 2026
marandaneto and others added 2 commits August 5, 2026 13:25
Scope drain requests to active flush and shutdown callers, wake idle consumers through the queue condition without periodic polling, and keep the coordination API private.
@marandaneto
marandaneto marked this pull request as ready for review August 5, 2026 12:17
@marandaneto
marandaneto requested a review from a team as a code owner August 5, 2026 12:17
Wake parked consumers when work arrives, a drain completes, or teardown pauses them, avoiding a busy loop while another consumer uploads.
Patch the consumer instances under test so unrelated background clients cannot add calls to process-wide transport mocks when suite timing changes.
@marandaneto
marandaneto merged commit ae26014 into main Aug 5, 2026
37 checks passed
@marandaneto
marandaneto deleted the posthog-code/flush-bypasses-flush-interval branch August 5, 2026 14:45
marandaneto added a commit that referenced this pull request Aug 5, 2026
Combine the merged drain signaling behavior from #797 with serialized lifecycle shutdown before merging main.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant