perf(tracking): make MixpanelProvider dispatch non-blocking — bounded queue + daemon worker + real flush() (BE-5868) - #664
Conversation
…queue + daemon worker + real flush) (BE-5868) MixpanelProvider.track() posted inline on the calling thread, so every consented invocation paid a synchronous HTTP round-trip — worst case ~10s against a blackholed endpoint — before the wrapped command body ran (@track_command fires its event first; `run` fires execution_start before submitting the workflow). Dispatch is now queue-and-drain: a bounded (256) queue drained by a single daemon worker. track() is put_nowait + drop-on-overflow with a debug line; flush() is a real queue.join() bounded by _flush_all_providers' existing shared 5s daemon deadline, exactly as PostHog's client.flush() already is. No atexit hook of our own, and the lazy mixpanel import is unchanged.
|
Warning Review limit reachedYou’ve reached a temporary PR review limit under our Fair Usage Limits Policy. Next review available in: 50 minutes Enable usage-based reviews in Billing to review now. Otherwise, wait until the next included review is available. How can I continue?After more reviews become available, a review can be triggered using the To avoid repeated limits, reduce automatic review volume by pausing incremental auto-reviews earlier, using label-based review opt-in, excluding WIP or generated PR titles, or requesting reviews manually when the PR is ready. If your team needs uninterrupted high-volume reviews, an organization admin can enable usage-based reviews. How do review limits work?CodeRabbit enforces per-developer PR review limits for each organization. Most developers receive the normal plan review availability. For paid Pro and Pro+ PR reviews, CodeRabbit uses adaptive limits for sustained high-volume activity. When a developer's recent PR review activity reaches the 95th percentile or higher among CodeRabbit users, additional reviews become available more gradually as earlier reviews age out of the rolling window. Please refer docs for additional details. Review details⚙️ Run configurationConfiguration used: Organization UI Review profile: ASSERTIVE Plan: Pro Plus Run ID: 📒 Files selected for processing (3)
Comment |
There was a problem hiding this comment.
🔍 Cursor Review — Consolidated panel
Triggered by @mattmillerai.
Found 10 finding(s).
| Severity | Count |
|---|---|
| 🔴 Critical | 1 |
| 🟠 High | 2 |
| 🟡 Medium | 3 |
| 🟢 Low | 3 |
| ⚪ Nit | 1 |
Panel: 8/8 reviewers contributed findings.
…os._exit (BE-5868)
Cursor review follow-ups on the non-blocking dispatch change.
- launch's os._exit paths now drain. @track_command fires its event *before*
the command body runs, so inline sends were already delivered by the time
`comfy launch --background` called os._exit; with queue-and-drain dispatch the
event was still queued and dropped on every backgrounded launch. Adds
tracking.flush_for_hard_exit() and routes launch.py's exits through
_hard_exit(), which drains (bounded, best-effort) then os._exit()s.
__main__.py's broken-pipe exit keeps skipping the drain, as documented there.
- The worker loop is guarded as a whole, on BaseException. Nothing detects or
restarts this thread, so any escape — an unpack failure, a MemoryError out of
the SDK, a raise from inside the except handler — wedged telemetry for the
rest of the process.
- flush() is bounded and gives up on a dead worker. queue.join() is
unconditional and unbounded, so a worker that never came back blocked every
later flush() forever; flush() is public, and direct callers have no deadline
of their own. Replaces join()/task_done() with a counter + condition.
- track() deepcopies the payload. Serialization moved to the worker, so the
shallow dict() copy left nested values aliased to objects the command body
could still mutate — shipping post-mutation contents, or racing mixpanel's
json.dumps into "dictionary changed size during iteration".
- A Thread.start() RuntimeError ("can't start new thread") degrades to an inert
provider instead of escaping into _get_providers' logging.warning, which would
put a telemetry-side resource problem on the user's stderr.
- The atexit flush-timeout log drops to debug. It was unreachable for Mixpanel
while flush() was a no-op; now that it drains a queue, a slow endpoint would
print to stderr after the terminal envelope.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
bigcat88
left a comment
There was a problem hiding this comment.
Approving. I didn't take the latency claim on trust — I stood up a local CONNECT proxy that terminates TLS for api.mixpanel.com and t.comfy.org with a scratch CA, so every event this CLI emits was captured on the wire and the endpoint's latency was mine to set.
1. The central claim, measured
comfy stop against a blackholed endpoint (accepts TCP, never responds):
| time to first output byte | total | |
|---|---|---|
main |
20.3s | 25.3s |
| this branch | 0.26s | 5.3s |
Two notes. The 20s is two attempts, not one — retry_limit=1 is one retry, so a blackholed send is ~2 × 10s. The comment still says "a single ~10s attempt"; that wording predates this PR, but since you rewrote the block around it, worth correcting. And the branch's 5.3s is the atexit deadline doing exactly what it is supposed to.
2. Nothing is lost on the normal path
With a reachable endpoint, comfy stop delivers the stop Mixpanel event and the cli:stop PostHog batch on both, and wall time is indistinguishable (0.26s/0.80s branch vs 0.27s/0.81s main).
3. _hard_exit is load-bearing — and fixes more than the description claims
comfy launch --background, endpoint lagging 2s inside the tunnel:
| variant | Mixpanel | PostHog |
|---|---|---|
main |
2 delivered | 0 — dropped |
this branch + main's launch.py (fix removed) |
0 — dropped | 0 — dropped |
| this branch as-is | 2 delivered | 2 delivered |
The row worth calling out is PostHog on main: os._exit was already dropping every PostHog event on this path before this PR. Your drain rescues them, which is a strict improvement the description doesn't claim.
The description is a little strong in the other direction, though: with a fast endpoint the fix-removed variant still delivered both Mixpanel events — the worker won the race. So it's "drops whenever the send hasn't landed yet", not "drops on every backgrounded launch". Doesn't change the verdict; the drain is correct either way, and on the success path (where ComfyUI takes seconds to boot) Mixpanel would usually have gone out already, which makes PostHog the real beneficiary.
Bounded, too: launch --background under a full blackhole is 10.6s here (5s × parent + child) against 40.7s on main.
4. Direct probes of the machinery (20 assertions, all pass)
50 track() calls return in 0.1ms with a send provably in flight; FIFO order holds across 1600 events from 8 concurrent producers with _pending settling to 0; overflow at maxsize=2 drops 498 of 500 without blocking or raising; flush() bounds at exactly 5.00s against a wedged worker, and worst-case track() latency while another thread sits inside that blocked flush is 0.0 ms (the Condition.wait releases as intended); a raising send leaves the worker alive and still serving later events; the deepcopy snapshot holds for both a nested dict and a nested list; an un-deepcopyable value falls back; a token-less provider is inert; cap is 256, daemon, named mixpanel-telemetry.
Lazy-import guarantee intact: comfy --help produces zero telemetry requests, and importing comfy_cli.tracking leaves mixpanel unimported, PROVIDERS None, and MainThread the only thread.
5. Tests are non-vacuous
With tracking.py and launch.py reverted to main and your test file kept, 10 of 16 fail. The 6 that pass are invariant guards (submission order, bounded exit, inert-when-disabled, flush-gives-up) whose property holds trivially under inline sends — right to keep as guards.
6. Suite
Full pytest . on your branch merged with current main: 3763 passed, 31 skipped (this box has a GPU, so 6 tests run that skip in your env — the totals reconcile exactly). ruff check and ruff format --diff clean under the CI-pinned 0.15.15.
Findings you resolved that I re-checked independently
- The 🔴 NameError is indeed a false positive:
tracking.py:17bindsloggingtocomfy_cli.logging, whosedebug(message)is single-argument — so the f-string isn't a style choice, the%-arg form would genuinelyTypeError. - Your correction on the LOG_LEVEL thread is the right one:
cmdline.py:60callssetup_logging()at import, so a warning there really would have been filtered on the default path. Good catch on yourself. - All six
os._exitcall sites inlaunch.pyare converted; the only remaining one in that module is inside_hard_exititself. (The description says seven.) MixpanelProvideris constructed exactly once in production, memoized behind_get_providers, andprovider.flush()has exactly one production caller — so both "thread leak" and "public method has no deadline" are correctly judged as theoretical.
Nits, none blocking
retry_limit=1comment: measured 2 attempts / ~20s, not one ~10s attempt.- Two test docstrings still describe the abandoned design —
test_flush_returns_even_when_the_send_raisescreditsfinally: task_done()for savingqueue.join(), andtest_flush_gives_up_promptly_when_the_worker_is_goneopens on "queue.join()would block forever here". Both are gone from the implementation. launch --backgroundcosts +0.4s on the happy path (two processes each doing a real PostHog upload now). Fair trade for events that were being dropped, and invisible next to server startup — just noting it's a measured delta, not zero.- Ctrl-C during a foreground
comfy launchcan now wait up to 5s for the drain. Consistent with every other command's atexit path, so I'd leave it.
Merge sequencing
#647 also touches comfy_cli/tracking.py; expect it to want a rebase once this lands.
ELI-5
Every time you ran a
comfycommand with analytics on, the CLI stopped and waited for an analytics event to be delivered over the network before it started doing the thing you asked for. If the analytics endpoint was slow or blackholed, you waited up to ~10 seconds staring at nothing. Now the event goes into an in-memory outbox and a background thread mails it while your command runs. If the outbox somehow fills up, extra events are quietly dropped — analytics is best-effort, your command is not.What changed
MixpanelProvideris rewritten from send-inline to queue-and-drain, all insidecomfy_cli/tracking.py:track()does aput_nowaitonto a boundedqueue.Queue(maxsize=256)and returns immediately. Onqueue.Fullit logs at debug and drops (never WARNING — a telemetry failure must not surface on the user's stderr, same policy as the urllib3/posthog logger silencing at the top of the module).daemon=Trueworker thread (mixpanel-telemetry) drains the queue and does the actualclient.track(...), withtry/except Exception → logging.debugandself._queue.task_done()in afinally:so a raising send can never wedgeflush().flush()is no longer a no-op: it is a realself._queue.join(). It is deliberately unbounded here — boundedness comes from the caller,_flush_all_providers, which already runs each provider's flush in a daemon thread joined against the shared 5s_FLUSH_DEADLINE_SECONDSdeadline and abandons it on timeout. That is exactly how PostHog's internally-unboundedclient.flush()is already handled._flush_all_providersstays the single shutdown drain path).queueis stdlib and joinsthreadingat module scope; themixpanelimport stays inside__init__.comfy --helpand shell completion remain thread-free and SDK-free, because providers are still built lazily on the first dispatched event.The
request_timeout=10/retry_limit=1consumer bound stays (themixpanel<5pin is untouched — 4.x has no async consumer, hence the hand-rolled worker). Its comment was rewritten: the bound no longer guards the hot path, it now caps how long one worker send can occupy the queue and how much of the exit drain's 5s budget a single in-flight event can eat.Accepted semantic shift
mixpanel-python stamps an event's
timewhenclient.track()runs, which moves from call time to dequeue time — sub-second skew in practice, no dashboard impact. Ordering is preserved: one FIFO, one worker, so per-process event order is unchanged.Tests
New
TestMixpanelNonBlockingDispatchintests/comfy_cli/test_tracking_providers.py(7 cases): the hot path returns in well under 1s while a send is provably still in flight;flush()drains 20 events in submission order; overflow (with_QUEUE_MAXmonkeypatched to 2) drops without blocking or raising and leaves a DEBUG-level breadcrumb; a raising send still letsflush()return;_flush_all_providers()returns inside the 5s deadline against a send that hangs forever; the worker is a daemon and the provider registers no atexit hook; a token-less provider'strack()/flush()stay inert.Existing assertions on the mocked Mixpanel client were swept — they now drain first, via a shared
_mixpanel_track_kwargs()helper or an explicitmp_provider.flush(). The negative assertion (assert_not_calledon opt-out) also flushes, so it proves nothing was enqueued rather than racing the worker.Verification (all green):
ruff check+ruff format --checkat the CI-pinned 0.15.15, the four tracking suites (174 passed), and the fullpytestrun (3748 passed, 37 skipped). The new async tests were run 3× to check for flakiness — stable.Judgment calls
logging.debug("mixpanel queue full; dropping event %s", event_name), butcomfy_cli.logging.debug(message)is a single-argument wrapper — the %-arg form would raiseTypeError. Used an f-string, matching the rest of the module.dict(properties)at enqueue time._dispatchalready hands each provider a fresh dict, so this copy is redundant today; kept it anyway so a caller mutating its dict between enqueue and send can't corrupt an in-flight event.test_worker_is_a_daemon_and_the_provider_registers_no_atexit_hook) to fence the two settled design constraints that are otherwise only enforced by a comment — mirroring the existingtest_posthog_unregisters_its_own_atexit_joinguard._flush_all_providerslogtelemetry flush timed out for MixpanelProvider. That is not new user-visible noise: it is alogging.warning, and the CLI's defaultLOG_LEVELisERROR, so it is filtered unless the user is explicitly debugging — and PostHog already reaches the same line under the same conditions.Out of scope
No change to
PostHogProvider,_dispatch,_flush_all_providers, or any of the ~60 call sites. Themixpanel<5pin is untouched.Update — review round 1 (
7b31a37)Six of the ten Cursor panel findings landed as code. Three claims in the section above are now stale and are superseded here.
Superseded:
"—flush()is a realself._queue.join(), deliberately unbounded here"join()/task_done()are gone.flush()waits on a_pendingcounter guarded by athreading.Condition, bounded by_FLUSH_DEADLINE_SECONDSand re-checkingself._worker.is_alive()on each short wait.join()is unconditional, so a worker that never came back blocked every laterflush()forever — andflush()is public, so a direct caller had no deadline of its own to fall back on."— it was not redundant, it was insufficient.dict(properties)… is redundant today"_dispatch's fresh dict is shallow, so nested values (Typer multi-value options, feedback score dicts) stayed aliased to the caller's objects. Since@track_commandfires before the wrapped body runs and serialization moved to the worker, the body could mutate a value out from under an in-flight send. Nowcopy.deepcopy, with a guarded fallback to the shallow copy."a— accurate as far as it goes (logging.warning… is filtered unless the user is explicitly debugging"cmdline.pycallssetup_logging()at import, defaultLOG_LEVEL=ERROR), but the line still surfaces atLOG_LEVEL=WARNING, after the terminal envelope, for what is a slow endpoint rather than a defect. Dropped tologging.debug.Also fixed:
os._exitbypassed the drain — the one real regression in the original diff.@track_commandfires its event before the command body runs, so inline sends were already delivered by the timecomfy launch --backgroundreachedos._exit; with queue-and-drain the event was still queued and dropped on every backgrounded launch. Addstracking.flush_for_hard_exit(), and routeslaunch.py's seven exits through_hard_exit(), which drains (bounded, best-effort) and then exits with the same code.__main__.py's broken-pipe exit still skips the drain, as its comment already declares._runloop body is guarded, onBaseException—get(), the unpack, and the send. Nothing detects or restarts this thread, so any escape wedged telemetry for the rest of the process. The failure log itself goes through_log_telemetry_debug(), which swallows, so a raise from inside theexcepthandler can't escape either.task_done()became_mark_done(), keyed on having actually dequeued something.Thread.start()RuntimeError("can't start new thread") degrades to an inert provider instead of escaping into_get_providers'logging.warning.Declined, with reasoning on the threads: the 🔴 Critical
logging.debugNameErroris a false positive —tracking.py:17rebindsloggingtocomfy_cli.logging, which is why the stdlib is aliased tologginglib. Two Lows (per-provider thread leak; a log racinglogging.shutdown) and the Nit (payload-size clamp) have no reachable impact today and are answered in-thread rather than deferred to tickets.New tests:
TestMixpanelWorkerSurvivability(4),TestMixpanelPropertySnapshot(2),TestHardExitDrain(3). The snapshot test is a verified regression test — reverting thedeepcopytodict()fails it with the post-mutation payload.Verification:
ruff checkclean, fullpytestgreen — 3758 passed, 37 skipped.