From a4ef39796f14dd0fde6cb252325d520329d353f5 Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Fri, 28 Aug 2026 15:18:43 -0400
Subject: [PATCH 1/9] Measure child busy and wait time as counters

---
 .../src/taskbroker_client/worker/worker.py    | 148 +++++++++++++-
 .../taskbroker_client/worker/workerchild.py   |  25 ++-
 clients/python/tests/worker/test_worker.py    | 189 ++++++++++++++++++
 3 files changed, 351 insertions(+), 11 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index f429f6a2..c5c6572c 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -132,6 +132,41 @@ def __init__(
             registry=self.registry,
         )
 
+        # Counters, not a ratio gauge. The gauge above is sampled per pod and
+        # then averaged across pods by the scaler, which is an unweighted mean of
+        # ratios and is not the pool's occupancy. These two are additive, so a
+        # scaler can sum them across pods first and divide once:
+        #
+        #   busy_rate / (busy_rate + wait_rate)
+        #
+        # They are also unclamped, which matters more than it sounds. Occupancy
+        # is clipped to 1.0 per interval, so an interval that over-counts loses
+        # the excess while one that under-counts keeps the deficit. Work landing
+        # in a neighbouring interval therefore drags the average down instead of
+        # cancelling out. Summing counters over the scaler's rate window has no
+        # such ceiling, so the same misattribution cancels.
+        #
+        # And a missed scrape shows up as a flat rate rather than as a
+        # plausible-looking low occupancy that triggers a scale down.
+        self.child_busy_seconds = prometheus_client.Counter(
+            "taskworker_worker_child_busy_seconds",
+            "Cumulative child-seconds spent executing tasks.",
+            ["processing_pool"],
+            registry=self.registry,
+        )
+
+        # The signal occupancy cannot express on its own: child slots that are
+        # available and have nothing to do. If this is near zero while a backlog
+        # exists, the pod is saturated no matter what occupancy reports, and more
+        # pods will help. If it is large, the pod is starved and more pods will
+        # only add idle children.
+        self.child_wait_seconds = prometheus_client.Counter(
+            "taskworker_worker_child_wait_seconds",
+            "Cumulative child-seconds spent blocked waiting for a task to arrive.",
+            ["processing_pool"],
+            registry=self.registry,
+        )
+
         prometheus_client.start_http_server(port, registry=self.registry)
         logger.info("taskworker.worker.prometheus_server_started", extra={"port": port})
 
@@ -214,26 +249,65 @@ class TrackedChild:
     # Time-weighted busy tracking
     busy_since: float | None = None  # monotonic timestamp of the currently-open busy segment
     busy_accumulated: float = 0.0  # the busy seconds banked since the last occupancy flush
+    # Time-weighted wait tracking, the mirror of the two fields above. A running
+    # child is always in exactly one of the two states: executing a task, or
+    # blocked in `child_tasks.get()` with nothing to execute.
+    #
+    # Wait is tracked separately rather than inferred as `elapsed - busy` because
+    # the inference is only valid for children that were running for the whole
+    # interval. Children spawn, warm up, and exit mid-interval, and those
+    # transitions are exactly when a pool is scaling, which is when the signal
+    # has to be trustworthy.
+    wait_since: float | None = None  # monotonic timestamp of the currently-open wait segment
+    wait_accumulated: float = 0.0  # the waiting seconds banked since the last flush
+
+    def mark_running(self, now: float) -> None:
+        """Start counting wait time once the child has finished warming up.
+
+        A `pending` child is importing the app, not starving for work, so it
+        accrues neither busy nor wait until it reports in.
+        """
+        if self.busy_since is None and self.wait_since is None:
+            self.wait_since = now
 
     def mark_busy(self, now: float) -> None:
-        """Open a busy segment when the child starts a task.
+        """Close the open wait segment and open a busy one.
 
-        `busy`/`idle` strictly alternate per child today, so a segment should
-        never already be open; the guard is defensive and keeps the original
-        start time if that invariant ever drifts.
+        `busy`/`idle` strictly alternate per child today, so a busy segment
+        should never already be open; the guard is defensive and keeps the
+        original start time if that invariant ever drifts.
         """
+        if self.wait_since is not None:
+            self.wait_accumulated += max(0.0, now - self.wait_since)
+            self.wait_since = None
         if self.busy_since is None:
             self.busy_since = now
 
     def mark_idle(self, now: float) -> None:
-        """Close the open busy segment and bank its elapsed seconds.
+        """Close the open busy segment and open a wait one.
 
         Guarded so an unexpected `idle` with no open segment is a no-op rather
         than a crash.
         """
         if self.busy_since is not None:
-            self.busy_accumulated += now - self.busy_since
+            self.busy_accumulated += max(0.0, now - self.busy_since)
+            self.busy_since = None
+        if self.wait_since is None:
+            self.wait_since = now
+
+    def mark_stopped(self, now: float) -> None:
+        """Close both segments when the child is released to shut down.
+
+        Without this a released child keeps an open wait segment that folds
+        forward on every drain, so a pool that is recycling children would look
+        starved for work when it is not.
+        """
+        if self.busy_since is not None:
+            self.busy_accumulated += max(0.0, now - self.busy_since)
             self.busy_since = None
+        if self.wait_since is not None:
+            self.wait_accumulated += max(0.0, now - self.wait_since)
+            self.wait_since = None
 
     def drain_busy(self, now: float) -> float:
         """Return busy seconds since the last drain and reset the counter.
@@ -243,12 +317,27 @@ def drain_busy(self, now: float) -> float:
         contributing to each one.
         """
         if self.busy_since is not None:
-            self.busy_accumulated += now - self.busy_since
+            self.busy_accumulated += max(0.0, now - self.busy_since)
             self.busy_since = now
         banked = self.busy_accumulated
         self.busy_accumulated = 0.0
         return banked
 
+    def drain_wait(self, now: float) -> float:
+        """Return waiting seconds since the last drain and reset the counter.
+
+        Mirrors `drain_busy`: an open wait segment is folded in up to `now` and
+        left open, so a child blocked across several intervals contributes to
+        each of them rather than dumping the whole wait into the interval it
+        finally gets a task in.
+        """
+        if self.wait_since is not None:
+            self.wait_accumulated += max(0.0, now - self.wait_since)
+            self.wait_since = now
+        banked = self.wait_accumulated
+        self.wait_accumulated = 0.0
+        return banked
+
 
 class PushTaskWorker:
     _mp_context: ForkContext | SpawnContext | ForkServerContext
@@ -970,15 +1059,45 @@ def _emit_periodic_metrics(self) -> None:
             }
 
             busy_time = 0.0
+            wait_time = 0.0
             for child in self._children.values():
                 state_counts[child.state] += 1
                 busy_time += child.drain_busy(now)
+                wait_time += child.drain_wait(now)
 
             exiting_children = len(self._exiting_children)
 
         elapsed = now - self._last_occupancy_flush_at
         self._last_occupancy_flush_at = now
 
+        # Emitted unconditionally, including during warmup, because they are
+        # counters: an interval with no running children contributes zero to
+        # both and is indistinguishable from not being scraped, which is the
+        # correct behaviour. The occupancy gauge below still has to skip warmup,
+        # since a zero there is a real value that drags the fleet average down.
+        self._metrics.distribution(
+            "taskworker.worker.child_busy_seconds",
+            busy_time,
+            tags=tags,
+        )
+        self._metrics.distribution(
+            "taskworker.worker.child_wait_seconds",
+            wait_time,
+            tags=tags,
+        )
+        if self._prom is not None:
+            # inc(0.0) is deliberate rather than guarded. It registers the
+            # labelled series on the first flush, so a pod that has not done any
+            # work yet still exposes both counters at zero. Without that the
+            # scaler sees the series appear only once a pod gets busy, and a
+            # brand new pod reads as missing rather than as idle.
+            self._prom.child_busy_seconds.labels(processing_pool=self._processing_pool_name).inc(
+                max(0.0, busy_time)
+            )
+            self._prom.child_wait_seconds.labels(processing_pool=self._processing_pool_name).inc(
+                max(0.0, wait_time)
+            )
+
         running_count = state_counts["running"]
         if running_count > 0 and elapsed > 0:
             occupancy = busy_time / (elapsed * running_count)
@@ -1161,19 +1280,27 @@ def spawn_children_thread() -> None:
                         # This child is now running
                         if message.event == "running":
                             child.state = "running"
+                            child.mark_running(message.timestamp)
 
                         # This child wants to exit, but we may not have enough running children to shut down right away
                         elif message.event == "exiting":
                             self._exiting_children.append(message.child_id)
 
-                        # This child started executing a task: open a busy segment.
+                        # This child started executing a task: close the wait
+                        # segment and open a busy one.
+                        #
+                        # These use the child's own timestamp, not the time
+                        # this loop happens to drain the queue. This thread
+                        # sleeps 100ms per iteration, so stamping here rounded
+                        # every boundary up to the next drain tick and credited
+                        # the work to the wrong flush interval.
                         elif message.event == "busy":
-                            child.mark_busy(time.monotonic())
+                            child.mark_busy(message.timestamp)
 
                         # This child finished a task: close the open busy segment
                         # and bank the elapsed time.
                         elif message.event == "idle":
-                            child.mark_idle(time.monotonic())
+                            child.mark_idle(message.timestamp)
 
                     while True:
                         # Compute how many children are still running
@@ -1195,6 +1322,7 @@ def spawn_children_thread() -> None:
                             continue
 
                         child.state = "exiting"
+                        child.mark_stopped(time.monotonic())
                         child.release.set()
 
                     spawned = sum(1 for c in self._children.values() if c.state != "exiting")
diff --git a/clients/python/src/taskbroker_client/worker/workerchild.py b/clients/python/src/taskbroker_client/worker/workerchild.py
index ac029f19..c13e84b7 100644
--- a/clients/python/src/taskbroker_client/worker/workerchild.py
+++ b/clients/python/src/taskbroker_client/worker/workerchild.py
@@ -8,7 +8,7 @@
 import threading
 import time
 from collections.abc import Callable, Generator, Sequence
-from dataclasses import dataclass
+from dataclasses import dataclass, field
 from functools import partial
 from multiprocessing.synchronize import Event
 from types import FrameType
@@ -170,6 +170,29 @@ def _log_task_retry_exhausted(
 class ChildMessage:
     child_id: UUID
     event: Literal["running", "exiting", "busy", "idle"]
+    # Stamped here, in the child, at the moment the event happens.
+    #
+    # The parent used to stamp these when it drained the queue, which it does
+    # from spawn_children_thread on a 100ms sleep, competing for the GIL with
+    # the gRPC servicer and the result thread. Every segment boundary therefore
+    # landed on a drain tick rather than on the event, and the work was credited
+    # to whichever flush interval the parent happened to read the message in
+    # rather than the one it happened in.
+    #
+    # That misattribution is not symmetric in its effect on occupancy, because
+    # occupancy is a per-interval ratio clamped to 1.0: an interval credited too
+    # much work is clipped, an interval credited too little is not floored. So
+    # anything that makes attribution bursty biases occupancy down, and drain
+    # lag gets burstier the more loaded the pod is.
+    #
+    # time.monotonic() is CLOCK_MONOTONIC, which is system-wide on Linux and
+    # macOS rather than per-process, so a value stamped in a forked child is
+    # directly comparable to one read in the parent.
+    #
+    # compare=False so two messages describing the same event stay equal. The
+    # timestamp is payload, not identity, and callers match on child_id and
+    # event.
+    timestamp: float = field(default_factory=time.monotonic, compare=False)
 
 
 def child_process(
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 9045ab04..0e22c73f 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -1280,6 +1280,8 @@ def _make_tracked_child(
     *,
     busy_since: float | None = None,
     busy_accumulated: float = 0.0,
+    wait_since: float | None = None,
+    wait_accumulated: float = 0.0,
 ) -> TrackedChild:
     return TrackedChild(
         process=mock.Mock(),
@@ -1287,9 +1289,15 @@ def _make_tracked_child(
         release=mock.Mock(),
         busy_since=busy_since,
         busy_accumulated=busy_accumulated,
+        wait_since=wait_since,
+        wait_accumulated=wait_accumulated,
     )
 
 
+def _distribution_calls(metrics: mock.Mock, name: str) -> list[Any]:
+    return [c for c in metrics.distribution.call_args_list if c.args[0] == name]
+
+
 def _gauge_calls(metrics: mock.Mock, name: str) -> list[Any]:
     return [c for c in metrics.gauge.call_args_list if c.args[0] == name]
 
@@ -1416,6 +1424,187 @@ def test_spawn_children_tracks_busy_and_idle_transitions() -> None:
         pool.shutdown()
 
 
+def test_tracked_child_records_real_widths_for_events_in_one_batch() -> None:
+    # The regression this change exists for.
+    #
+    # spawn_children_thread drains the child message queue on a 100ms sleep, so
+    # a child running 50ms tasks delivers several busy/idle pairs per drain. The
+    # parent used to stamp all of them with the drain time, which collapsed
+    # every segment inside the batch to zero width and left the whole interval
+    # credited to whichever segment happened to span the drain boundary. Total
+    # busy time survived that, but the per-interval split did not, and occupancy
+    # is computed per interval and clipped at 1.0.
+    #
+    # Two 50ms tasks with a 10ms gap, all delivered at once:
+    child = _make_tracked_child("running", wait_since=100.00)
+
+    child.mark_busy(100.00)
+    child.mark_idle(100.05)
+    child.mark_busy(100.06)
+    child.mark_idle(100.11)
+
+    # 0.05 + 0.05 of work, and the 0.01 gap between them counted as waiting.
+    assert child.busy_accumulated == pytest.approx(0.10)
+    assert child.wait_accumulated == pytest.approx(0.01)
+
+
+def test_tracked_child_busy_and_wait_partition_the_interval() -> None:
+    # A running child is always in exactly one of the two states, so over an
+    # interval with no state changes the two drains must sum to its width.
+    child = _make_tracked_child("running", wait_since=10.0)
+
+    child.mark_busy(10.4)
+    busy = child.drain_busy(11.0)
+    wait = child.drain_wait(11.0)
+
+    assert busy == pytest.approx(0.6)
+    assert wait == pytest.approx(0.4)
+    assert busy + wait == pytest.approx(1.0)
+
+    # Both open segments are carried forward rather than restarted at zero.
+    assert child.busy_since == pytest.approx(11.0)
+    assert child.wait_since is None
+
+
+def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
+    # Child timestamps and the parent's drain clock can cross: drain_busy folds
+    # an open segment forward to the parent's `now`, and a message stamped just
+    # before that can be processed just after. The delta is then negative and
+    # would silently subtract already-credited time.
+    child = _make_tracked_child("running", busy_since=10.0)
+
+    child.drain_busy(11.0)  # credits 1.0s, advances busy_since to 11.0
+    child.mark_idle(10.95)  # stamped before the drain, delivered after
+
+    assert child.busy_accumulated == pytest.approx(0.0)
+
+
+def test_tracked_child_stops_accruing_wait_once_released() -> None:
+    # A child released to shut down stops sending messages, so an open wait
+    # segment would fold forward on every drain forever and make a pool that is
+    # recycling children look starved for work.
+    child = _make_tracked_child("running", wait_since=10.0)
+
+    child.mark_stopped(10.5)
+    assert child.drain_wait(20.0) == pytest.approx(0.5)
+    assert child.drain_wait(30.0) == pytest.approx(0.0)
+
+
+def test_tracked_child_pending_accrues_neither_busy_nor_wait() -> None:
+    # Warmup is not starvation. A child importing the app has no slot to fill.
+    child = _make_tracked_child("pending")
+
+    assert child.drain_busy(11.0) == pytest.approx(0.0)
+    assert child.drain_wait(11.0) == pytest.approx(0.0)
+
+    child.mark_running(11.0)
+    assert child.drain_wait(12.0) == pytest.approx(1.0)
+
+
+def test_emit_periodic_metrics_emits_busy_and_wait_seconds() -> None:
+    # Interval [10.0, 11.0], two running children: one busy throughout, one that
+    # spent 0.25s of it waiting for a task that never arrived.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = _make_tracked_child(
+            "running", busy_accumulated=0.75, wait_since=10.75
+        )
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    busy = _distribution_calls(pool._metrics, "taskworker.worker.child_busy_seconds")
+    wait = _distribution_calls(pool._metrics, "taskworker.worker.child_wait_seconds")
+    assert len(busy) == 1 and len(wait) == 1
+    assert busy[0].args[1] == pytest.approx(1.75)
+    assert wait[0].args[1] == pytest.approx(0.25)
+
+    # The pair is what the scaler divides, and it recovers the same answer the
+    # occupancy gauge reports without depending on the flush interval or on the
+    # running-child count.
+    assert busy[0].args[1] / (busy[0].args[1] + wait[0].args[1]) == pytest.approx(0.875)
+    occupancy_calls = _gauge_calls(pool._metrics, "taskworker.worker.occupancy")
+    assert occupancy_calls[0].args[1] == pytest.approx(1.75 / 2)
+
+
+def test_emit_periodic_metrics_emits_counters_during_warmup() -> None:
+    # Unlike occupancy, these are emitted even with no running children. A zero
+    # contribution from a warming pod is correct for a counter and is what lets
+    # the scaler tell "idle" apart from "not reporting".
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("pending")
+
+    pool._emit_periodic_metrics()
+
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy") == []
+    assert len(_distribution_calls(pool._metrics, "taskworker.worker.child_busy_seconds")) == 1
+    assert len(_distribution_calls(pool._metrics, "taskworker.worker.child_wait_seconds")) == 1
+
+
+def test_spawn_children_uses_the_child_timestamp_not_the_drain_time() -> None:
+    fake_context = _FakeContext()
+    pool = _make_fake_context_pool(fake_context, concurrency=1)
+
+    pool.start_spawn_children_thread()
+    try:
+        _wait_for(lambda: len(fake_context.processes) == 1)
+        messages = fake_context.queues[-1]
+        child_id = fake_context.processes[0].args[0]
+
+        messages.put(ChildMessage(child_id, "running"))
+        _wait_for(lambda: pool.ready_count == 1)
+
+        stamped_at = time.monotonic() - 5.0
+        messages.put(ChildMessage(child_id, "busy", timestamp=stamped_at))
+        _wait_for(lambda: pool._children[child_id].busy_since is not None)
+
+        # The drain happens up to 100ms later and on a different thread; the
+        # segment has to start when the child said it did.
+        assert pool._children[child_id].busy_since == pytest.approx(stamped_at)
+    finally:
+        pool.shutdown()
+
+
+def test_spawn_children_tracks_wait_between_tasks() -> None:
+    fake_context = _FakeContext()
+    pool = _make_fake_context_pool(fake_context, concurrency=1)
+
+    pool.start_spawn_children_thread()
+    try:
+        _wait_for(lambda: len(fake_context.processes) == 1)
+        messages = fake_context.queues[-1]
+        child_id = fake_context.processes[0].args[0]
+
+        base = time.monotonic() - 10.0
+
+        # Reporting in opens a wait segment: the child is available and blocked
+        # in child_tasks.get().
+        messages.put(ChildMessage(child_id, "running", timestamp=base))
+        _wait_for(lambda: pool._children[child_id].wait_since == pytest.approx(base))
+
+        # 2s of waiting, then 1s of work, then waiting again.
+        messages.put(ChildMessage(child_id, "busy", timestamp=base + 2.0))
+        messages.put(ChildMessage(child_id, "idle", timestamp=base + 3.0))
+        # `wait_since` is already set by the "running" message above, so wait on
+        # the banked busy time, which only lands once "idle" is processed.
+        _wait_for(lambda: pool._children[child_id].busy_accumulated > 0)
+
+        child = pool._children[child_id]
+        assert child.wait_accumulated == pytest.approx(2.0)
+        assert child.busy_accumulated == pytest.approx(1.0)
+        assert child.busy_since is None
+        assert child.wait_since == pytest.approx(base + 3.0)
+    finally:
+        pool.shutdown()
+
+
 def test_spawn_children_counts_pending_children_toward_concurrency() -> None:
     fake_context = _FakeContext()
     pool = _make_fake_context_pool(fake_context, concurrency=2)

From ac731850ee8e1161401672868226e6d4b7eaeb3e Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Fri, 28 Aug 2026 16:37:59 -0400
Subject: [PATCH 2/9] comment

---
 .../src/taskbroker_client/worker/worker.py    | 82 ++++---------------
 .../taskbroker_client/worker/workerchild.py   | 25 +-----
 clients/python/tests/worker/test_worker.py    | 53 ++++--------
 3 files changed, 37 insertions(+), 123 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index c5c6572c..901e68dd 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -132,22 +132,8 @@ def __init__(
             registry=self.registry,
         )
 
-        # Counters, not a ratio gauge. The gauge above is sampled per pod and
-        # then averaged across pods by the scaler, which is an unweighted mean of
-        # ratios and is not the pool's occupancy. These two are additive, so a
-        # scaler can sum them across pods first and divide once:
-        #
-        #   busy_rate / (busy_rate + wait_rate)
-        #
-        # They are also unclamped, which matters more than it sounds. Occupancy
-        # is clipped to 1.0 per interval, so an interval that over-counts loses
-        # the excess while one that under-counts keeps the deficit. Work landing
-        # in a neighbouring interval therefore drags the average down instead of
-        # cancelling out. Summing counters over the scaler's rate window has no
-        # such ceiling, so the same misattribution cancels.
-        #
-        # And a missed scrape shows up as a flat rate rather than as a
-        # plausible-looking low occupancy that triggers a scale down.
+        # Additive and unclamped, unlike the gauge above: the scaler sums across
+        # pods and divides once, and no interval clips at 1.0.
         self.child_busy_seconds = prometheus_client.Counter(
             "taskworker_worker_child_busy_seconds",
             "Cumulative child-seconds spent executing tasks.",
@@ -155,11 +141,8 @@ def __init__(
             registry=self.registry,
         )
 
-        # The signal occupancy cannot express on its own: child slots that are
-        # available and have nothing to do. If this is near zero while a backlog
-        # exists, the pod is saturated no matter what occupancy reports, and more
-        # pods will help. If it is large, the pod is starved and more pods will
-        # only add idle children.
+        # What occupancy cannot express: slots that are free with nothing to do.
+        # Near zero under a backlog means saturated, so more pods help.
         self.child_wait_seconds = prometheus_client.Counter(
             "taskworker_worker_child_wait_seconds",
             "Cumulative child-seconds spent blocked waiting for a task to arrive.",
@@ -249,24 +232,13 @@ class TrackedChild:
     # Time-weighted busy tracking
     busy_since: float | None = None  # monotonic timestamp of the currently-open busy segment
     busy_accumulated: float = 0.0  # the busy seconds banked since the last occupancy flush
-    # Time-weighted wait tracking, the mirror of the two fields above. A running
-    # child is always in exactly one of the two states: executing a task, or
-    # blocked in `child_tasks.get()` with nothing to execute.
-    #
-    # Wait is tracked separately rather than inferred as `elapsed - busy` because
-    # the inference is only valid for children that were running for the whole
-    # interval. Children spawn, warm up, and exit mid-interval, and those
-    # transitions are exactly when a pool is scaling, which is when the signal
-    # has to be trustworthy.
+    # Mirror of the two fields above. Measured rather than inferred as
+    # `elapsed - busy`, which only holds for children running the whole interval.
     wait_since: float | None = None  # monotonic timestamp of the currently-open wait segment
     wait_accumulated: float = 0.0  # the waiting seconds banked since the last flush
 
     def mark_running(self, now: float) -> None:
-        """Start counting wait time once the child has finished warming up.
-
-        A `pending` child is importing the app, not starving for work, so it
-        accrues neither busy nor wait until it reports in.
-        """
+        """Start the wait clock: a `pending` child is importing, not starving."""
         if self.busy_since is None and self.wait_since is None:
             self.wait_since = now
 
@@ -296,12 +268,7 @@ def mark_idle(self, now: float) -> None:
             self.wait_since = now
 
     def mark_stopped(self, now: float) -> None:
-        """Close both segments when the child is released to shut down.
-
-        Without this a released child keeps an open wait segment that folds
-        forward on every drain, so a pool that is recycling children would look
-        starved for work when it is not.
-        """
+        """Close both segments so a released child stops folding wait forward."""
         if self.busy_since is not None:
             self.busy_accumulated += max(0.0, now - self.busy_since)
             self.busy_since = None
@@ -324,13 +291,7 @@ def drain_busy(self, now: float) -> float:
         return banked
 
     def drain_wait(self, now: float) -> float:
-        """Return waiting seconds since the last drain and reset the counter.
-
-        Mirrors `drain_busy`: an open wait segment is folded in up to `now` and
-        left open, so a child blocked across several intervals contributes to
-        each of them rather than dumping the whole wait into the interval it
-        finally gets a task in.
-        """
+        """Mirror of `drain_busy`, so a long block counts in every interval it spans."""
         if self.wait_since is not None:
             self.wait_accumulated += max(0.0, now - self.wait_since)
             self.wait_since = now
@@ -1070,11 +1031,8 @@ def _emit_periodic_metrics(self) -> None:
         elapsed = now - self._last_occupancy_flush_at
         self._last_occupancy_flush_at = now
 
-        # Emitted unconditionally, including during warmup, because they are
-        # counters: an interval with no running children contributes zero to
-        # both and is indistinguishable from not being scraped, which is the
-        # correct behaviour. The occupancy gauge below still has to skip warmup,
-        # since a zero there is a real value that drags the fleet average down.
+        # Emitted during warmup too: zero is correct for a counter, unlike for
+        # the occupancy gauge below where it drags the fleet average down.
         self._metrics.distribution(
             "taskworker.worker.child_busy_seconds",
             busy_time,
@@ -1086,11 +1044,8 @@ def _emit_periodic_metrics(self) -> None:
             tags=tags,
         )
         if self._prom is not None:
-            # inc(0.0) is deliberate rather than guarded. It registers the
-            # labelled series on the first flush, so a pod that has not done any
-            # work yet still exposes both counters at zero. Without that the
-            # scaler sees the series appear only once a pod gets busy, and a
-            # brand new pod reads as missing rather than as idle.
+            # inc(0.0) registers the series on the first flush, so a new pod
+            # reads as idle rather than as missing.
             self._prom.child_busy_seconds.labels(processing_pool=self._processing_pool_name).inc(
                 max(0.0, busy_time)
             )
@@ -1286,14 +1241,9 @@ def spawn_children_thread() -> None:
                         elif message.event == "exiting":
                             self._exiting_children.append(message.child_id)
 
-                        # This child started executing a task: close the wait
-                        # segment and open a busy one.
-                        #
-                        # These use the child's own timestamp, not the time
-                        # this loop happens to drain the queue. This thread
-                        # sleeps 100ms per iteration, so stamping here rounded
-                        # every boundary up to the next drain tick and credited
-                        # the work to the wrong flush interval.
+                        # Close the wait segment and open a busy one, at the
+                        # child's timestamp: this loop drains on a 100ms sleep,
+                        # so stamping here credits work to the wrong interval.
                         elif message.event == "busy":
                             child.mark_busy(message.timestamp)
 
diff --git a/clients/python/src/taskbroker_client/worker/workerchild.py b/clients/python/src/taskbroker_client/worker/workerchild.py
index c13e84b7..3229132e 100644
--- a/clients/python/src/taskbroker_client/worker/workerchild.py
+++ b/clients/python/src/taskbroker_client/worker/workerchild.py
@@ -170,28 +170,9 @@ def _log_task_retry_exhausted(
 class ChildMessage:
     child_id: UUID
     event: Literal["running", "exiting", "busy", "idle"]
-    # Stamped here, in the child, at the moment the event happens.
-    #
-    # The parent used to stamp these when it drained the queue, which it does
-    # from spawn_children_thread on a 100ms sleep, competing for the GIL with
-    # the gRPC servicer and the result thread. Every segment boundary therefore
-    # landed on a drain tick rather than on the event, and the work was credited
-    # to whichever flush interval the parent happened to read the message in
-    # rather than the one it happened in.
-    #
-    # That misattribution is not symmetric in its effect on occupancy, because
-    # occupancy is a per-interval ratio clamped to 1.0: an interval credited too
-    # much work is clipped, an interval credited too little is not floored. So
-    # anything that makes attribution bursty biases occupancy down, and drain
-    # lag gets burstier the more loaded the pod is.
-    #
-    # time.monotonic() is CLOCK_MONOTONIC, which is system-wide on Linux and
-    # macOS rather than per-process, so a value stamped in a forked child is
-    # directly comparable to one read in the parent.
-    #
-    # compare=False so two messages describing the same event stay equal. The
-    # timestamp is payload, not identity, and callers match on child_id and
-    # event.
+    # Stamped at the event, not when the parent drains it 100ms later.
+    # CLOCK_MONOTONIC is system-wide, so a child's stamp is valid in the parent.
+    # compare=False: the timestamp is payload, not identity.
     timestamp: float = field(default_factory=time.monotonic, compare=False)
 
 
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 0e22c73f..4e58d7a2 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -1425,17 +1425,8 @@ def test_spawn_children_tracks_busy_and_idle_transitions() -> None:
 
 
 def test_tracked_child_records_real_widths_for_events_in_one_batch() -> None:
-    # The regression this change exists for.
-    #
-    # spawn_children_thread drains the child message queue on a 100ms sleep, so
-    # a child running 50ms tasks delivers several busy/idle pairs per drain. The
-    # parent used to stamp all of them with the drain time, which collapsed
-    # every segment inside the batch to zero width and left the whole interval
-    # credited to whichever segment happened to span the drain boundary. Total
-    # busy time survived that, but the per-interval split did not, and occupancy
-    # is computed per interval and clipped at 1.0.
-    #
-    # Two 50ms tasks with a 10ms gap, all delivered at once:
+    # The regression this change exists for: stamping at drain time collapsed
+    # every segment in a batch to zero width. Two 50ms tasks, 10ms apart:
     child = _make_tracked_child("running", wait_since=100.00)
 
     child.mark_busy(100.00)
@@ -1449,8 +1440,8 @@ def test_tracked_child_records_real_widths_for_events_in_one_batch() -> None:
 
 
 def test_tracked_child_busy_and_wait_partition_the_interval() -> None:
-    # A running child is always in exactly one of the two states, so over an
-    # interval with no state changes the two drains must sum to its width.
+    # A running child is always in exactly one state, so the drains must sum
+    # to the interval width.
     child = _make_tracked_child("running", wait_since=10.0)
 
     child.mark_busy(10.4)
@@ -1467,10 +1458,8 @@ def test_tracked_child_busy_and_wait_partition_the_interval() -> None:
 
 
 def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
-    # Child timestamps and the parent's drain clock can cross: drain_busy folds
-    # an open segment forward to the parent's `now`, and a message stamped just
-    # before that can be processed just after. The delta is then negative and
-    # would silently subtract already-credited time.
+    # drain_busy folds forward to the parent's clock, so a message stamped just
+    # before that and processed just after must not subtract credited time.
     child = _make_tracked_child("running", busy_since=10.0)
 
     child.drain_busy(11.0)  # credits 1.0s, advances busy_since to 11.0
@@ -1480,9 +1469,8 @@ def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
 
 
 def test_tracked_child_stops_accruing_wait_once_released() -> None:
-    # A child released to shut down stops sending messages, so an open wait
-    # segment would fold forward on every drain forever and make a pool that is
-    # recycling children look starved for work.
+    # A released child stops sending messages, so an open wait segment would
+    # fold forward forever and make a recycling pool look starved.
     child = _make_tracked_child("running", wait_since=10.0)
 
     child.mark_stopped(10.5)
@@ -1491,7 +1479,7 @@ def test_tracked_child_stops_accruing_wait_once_released() -> None:
 
 
 def test_tracked_child_pending_accrues_neither_busy_nor_wait() -> None:
-    # Warmup is not starvation. A child importing the app has no slot to fill.
+    # Warmup is not starvation: a child importing the app has no slot to fill.
     child = _make_tracked_child("pending")
 
     assert child.drain_busy(11.0) == pytest.approx(0.0)
@@ -1502,8 +1490,7 @@ def test_tracked_child_pending_accrues_neither_busy_nor_wait() -> None:
 
 
 def test_emit_periodic_metrics_emits_busy_and_wait_seconds() -> None:
-    # Interval [10.0, 11.0], two running children: one busy throughout, one that
-    # spent 0.25s of it waiting for a task that never arrived.
+    # Interval [10.0, 11.0]: one child busy throughout, one waiting 0.25s.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
     pool._last_occupancy_flush_at = 10.0
@@ -1523,18 +1510,16 @@ def test_emit_periodic_metrics_emits_busy_and_wait_seconds() -> None:
     assert busy[0].args[1] == pytest.approx(1.75)
     assert wait[0].args[1] == pytest.approx(0.25)
 
-    # The pair is what the scaler divides, and it recovers the same answer the
-    # occupancy gauge reports without depending on the flush interval or on the
-    # running-child count.
+    # The scaler divides the pair, recovering occupancy without needing the
+    # flush interval or the running-child count.
     assert busy[0].args[1] / (busy[0].args[1] + wait[0].args[1]) == pytest.approx(0.875)
     occupancy_calls = _gauge_calls(pool._metrics, "taskworker.worker.occupancy")
     assert occupancy_calls[0].args[1] == pytest.approx(1.75 / 2)
 
 
 def test_emit_periodic_metrics_emits_counters_during_warmup() -> None:
-    # Unlike occupancy, these are emitted even with no running children. A zero
-    # contribution from a warming pod is correct for a counter and is what lets
-    # the scaler tell "idle" apart from "not reporting".
+    # Emitted with no running children, unlike occupancy: zero is correct for a
+    # counter and separates "idle" from "not reporting".
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
 
@@ -1565,8 +1550,8 @@ def test_spawn_children_uses_the_child_timestamp_not_the_drain_time() -> None:
         messages.put(ChildMessage(child_id, "busy", timestamp=stamped_at))
         _wait_for(lambda: pool._children[child_id].busy_since is not None)
 
-        # The drain happens up to 100ms later and on a different thread; the
-        # segment has to start when the child said it did.
+        # The drain lands up to 100ms later on another thread; the segment has
+        # to start when the child said it did.
         assert pool._children[child_id].busy_since == pytest.approx(stamped_at)
     finally:
         pool.shutdown()
@@ -1584,16 +1569,14 @@ def test_spawn_children_tracks_wait_between_tasks() -> None:
 
         base = time.monotonic() - 10.0
 
-        # Reporting in opens a wait segment: the child is available and blocked
-        # in child_tasks.get().
+        # Reporting in opens a wait segment: available, blocked in get().
         messages.put(ChildMessage(child_id, "running", timestamp=base))
         _wait_for(lambda: pool._children[child_id].wait_since == pytest.approx(base))
 
         # 2s of waiting, then 1s of work, then waiting again.
         messages.put(ChildMessage(child_id, "busy", timestamp=base + 2.0))
         messages.put(ChildMessage(child_id, "idle", timestamp=base + 3.0))
-        # `wait_since` is already set by the "running" message above, so wait on
-        # the banked busy time, which only lands once "idle" is processed.
+        # `wait_since` is already set by "running" above, so wait on banked busy.
         _wait_for(lambda: pool._children[child_id].busy_accumulated > 0)
 
         child = pool._children[child_id]

From a9716c20ef032a4c2cc8fad8507273482d70598e Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Mon, 31 Aug 2026 19:48:32 -0400
Subject: [PATCH 3/9] Stop double billing child busy and wait time

A sandbox concurrency sweep showed child_busy_seconds reaching 580
seconds per 1s flush across 24 children, 24x the physical ceiling of
elapsed * running_count, ramping linearly through a stage. Occupancy
read exactly 1.0 the whole time because min(occupancy, 1.0) hid it.

The parent reads child events on a 100ms loop while the metrics thread
drains on a 1s cadence, so an event routinely arrives stamped before a
drain that already accounted for that time. mark_busy then clipped the
wait closure to zero, leaving the emitted wait in place, and opened a
busy segment starting back inside it. Both counters billed the same wall
clock, and the error grew with the event backlog.

- Give TrackedChild a last_drained_at watermark and clamp every segment
  boundary forward to it, so no interval can be credited twice. This
  trades double billing for lag: busy + wait stays equal to the interval
  width, but a stale event lands in the interval it was read, not the
  one it happened in.
- Sum the counters over running children only. Occupancy divides by
  running_count, so folding pending or exiting children into the
  numerator measured one population against another.
- Emit taskworker.worker.occupancy.accounting_overflow when either
  counter exceeds elapsed * running_count, so this class of fault cannot
  hide behind the clamp again.
- Emit taskworker.worker.child_message.age so the lag the clamp
  introduces is visible. Flat and sub-second is healthy; a rising line
  means the event loop is not keeping up and the signal is going stale.
---
 .../src/taskbroker_client/worker/worker.py    | 76 ++++++++++++++-
 clients/python/tests/worker/test_worker.py    | 93 ++++++++++++++++++-
 2 files changed, 163 insertions(+), 6 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index 901e68dd..56a94964 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -236,9 +236,28 @@ class TrackedChild:
     # `elapsed - busy`, which only holds for children running the whole interval.
     wait_since: float | None = None  # monotonic timestamp of the currently-open wait segment
     wait_accumulated: float = 0.0  # the waiting seconds banked since the last flush
+    # Everything up to here has already been drained and emitted. Segment
+    # boundaries stamped earlier than this are clamped forward to it. 0.0 means
+    # "never drained"; time.monotonic() is always well above it, so a child that
+    # has not been flushed yet accepts its events verbatim.
+    last_drained_at: float = 0.0
+
+    def _clamp(self, now: float) -> float:
+        """Never let a segment boundary land inside an already-emitted interval.
+
+        The parent reads child events on a 100ms loop while the metrics thread
+        drains on a 1s cadence, so an event routinely arrives stamped *before*
+        the drain that already accounted for that time. Honouring the stale
+        stamp would re-bill those seconds: `mark_busy` would clip the wait
+        closure to zero, leaving the emitted wait in place, and then open a
+        busy segment starting back inside it. Both counters then bill the same
+        wall clock, which is unbounded when the event backlog grows.
+        """
+        return max(now, self.last_drained_at)
 
     def mark_running(self, now: float) -> None:
         """Start the wait clock: a `pending` child is importing, not starving."""
+        now = self._clamp(now)
         if self.busy_since is None and self.wait_since is None:
             self.wait_since = now
 
@@ -249,6 +268,7 @@ def mark_busy(self, now: float) -> None:
         should never already be open; the guard is defensive and keeps the
         original start time if that invariant ever drifts.
         """
+        now = self._clamp(now)
         if self.wait_since is not None:
             self.wait_accumulated += max(0.0, now - self.wait_since)
             self.wait_since = None
@@ -261,6 +281,7 @@ def mark_idle(self, now: float) -> None:
         Guarded so an unexpected `idle` with no open segment is a no-op rather
         than a crash.
         """
+        now = self._clamp(now)
         if self.busy_since is not None:
             self.busy_accumulated += max(0.0, now - self.busy_since)
             self.busy_since = None
@@ -269,6 +290,7 @@ def mark_idle(self, now: float) -> None:
 
     def mark_stopped(self, now: float) -> None:
         """Close both segments so a released child stops folding wait forward."""
+        now = self._clamp(now)
         if self.busy_since is not None:
             self.busy_accumulated += max(0.0, now - self.busy_since)
             self.busy_since = None
@@ -286,6 +308,7 @@ def drain_busy(self, now: float) -> float:
         if self.busy_since is not None:
             self.busy_accumulated += max(0.0, now - self.busy_since)
             self.busy_since = now
+        self.last_drained_at = now
         banked = self.busy_accumulated
         self.busy_accumulated = 0.0
         return banked
@@ -295,6 +318,7 @@ def drain_wait(self, now: float) -> float:
         if self.wait_since is not None:
             self.wait_accumulated += max(0.0, now - self.wait_since)
             self.wait_since = now
+        self.last_drained_at = now
         banked = self.wait_accumulated
         self.wait_accumulated = 0.0
         return banked
@@ -1023,6 +1047,16 @@ def _emit_periodic_metrics(self) -> None:
             wait_time = 0.0
             for child in self._children.values():
                 state_counts[child.state] += 1
+
+                # Running children only: occupancy divides by `running_count`,
+                # so folding a `pending` or `exiting` child into the numerator
+                # measures one population against another. Neither has time to
+                # lose here. A `pending` child has not opened a segment yet,
+                # and `mark_stopped` deliberately closes an `exiting` child's
+                # segments so its tail stops counting against the live pool.
+                if child.state != "running":
+                    continue
+
                 busy_time += child.drain_busy(now)
                 wait_time += child.drain_wait(now)
 
@@ -1055,7 +1089,30 @@ def _emit_periodic_metrics(self) -> None:
 
         running_count = state_counts["running"]
         if running_count > 0 and elapsed > 0:
-            occupancy = busy_time / (elapsed * running_count)
+            # A child cannot be busy for longer than the interval, so this is a
+            # hard physical bound on both counters. Exceeding it means the
+            # accounting is double billing, and the clamp below would hide that
+            # behind a healthy-looking 1.0. Emit it so the metric cannot lie
+            # silently again.
+            ceiling = elapsed * running_count
+            if busy_time > ceiling or wait_time > ceiling:
+                self._metrics.incr(
+                    "taskworker.worker.occupancy.accounting_overflow",
+                    tags=tags,
+                )
+                logger.warning(
+                    "taskworker.worker.occupancy.accounting_overflow",
+                    extra={
+                        "busy_time": busy_time,
+                        "wait_time": wait_time,
+                        "ceiling": ceiling,
+                        "running_count": running_count,
+                        "elapsed": elapsed,
+                        "processing_pool": self._processing_pool_name,
+                    },
+                )
+
+            occupancy = busy_time / ceiling
             occupancy = min(occupancy, 1.0)
             self._metrics.gauge(
                 "taskworker.worker.occupancy",
@@ -1195,6 +1252,23 @@ def spawn_children_thread() -> None:
                     except queue.Empty:
                         break
 
+                # How stale the events we are about to apply are. The clamp in
+                # `TrackedChild._clamp` keeps busy + wait conserved when this
+                # loop falls behind, but it cannot recover *when* the work
+                # happened, so occupancy lags by roughly this age. Flat and
+                # sub-second is healthy; a rising line means this thread is not
+                # keeping up with the children and the signal is going stale.
+                if received:
+                    drain_at = time.monotonic()
+                    self._metrics.distribution(
+                        "taskworker.worker.child_message.age",
+                        drain_at - min(m.timestamp for m in received),
+                        tags={
+                            "processing_pool": self._processing_pool_name,
+                            "pod_name": self._pod_name,
+                        },
+                    )
+
                 with self._children_lock:
                     children = list(self._children.items())
 
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 4e58d7a2..5cb3f073 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -1298,6 +1298,10 @@ def _distribution_calls(metrics: mock.Mock, name: str) -> list[Any]:
     return [c for c in metrics.distribution.call_args_list if c.args[0] == name]
 
 
+def _incr_calls(metrics: mock.Mock, name: str) -> list[Any]:
+    return [c for c in metrics.incr.call_args_list if c.args[0] == name]
+
+
 def _gauge_calls(metrics: mock.Mock, name: str) -> list[Any]:
     return [c for c in metrics.gauge.call_args_list if c.args[0] == name]
 
@@ -1378,16 +1382,18 @@ def test_emit_periodic_metrics_divides_by_running_children() -> None:
     assert occupancy_calls[0].args[1] == pytest.approx(2 / 3)
 
 
-def test_emit_periodic_metrics_clamps_occupancy_to_one() -> None:
-    # A draining child can still be mid-task, so busy-time can exceed the running
-    # capacity for the interval; occupancy must clamp to 1.0.
+def test_emit_periodic_metrics_clamps_occupancy_and_flags_the_overflow() -> None:
+    # A child cannot be busy for longer than the interval, so 1.5s of busy over
+    # a 1s interval is an accounting fault, not a busy pool. Occupancy still has
+    # to clamp for KEDA, but the fault must be visible: reading a healthy 1.0
+    # while the numerator is nonsense is how the double-billing bug hid.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
     pool._last_occupancy_flush_at = 10.0
 
     with pool._children_lock:
-        pool._children[uuid4()] = _make_tracked_child("running", busy_accumulated=1.0)
-        pool._children[uuid4()] = _make_tracked_child("exiting", busy_accumulated=1.0)
+        pool._children[uuid4()] = _make_tracked_child("running", busy_accumulated=1.5)
+        pool._children[uuid4()] = _make_tracked_child("running", busy_accumulated=1.5)
 
     with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
         pool._emit_periodic_metrics()
@@ -1395,6 +1401,49 @@ def test_emit_periodic_metrics_clamps_occupancy_to_one() -> None:
     occupancy_calls = _gauge_calls(pool._metrics, "taskworker.worker.occupancy")
     assert len(occupancy_calls) == 1
     assert occupancy_calls[0].args[1] == pytest.approx(1.0)
+    assert len(_incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_overflow")) == 1
+
+
+def test_emit_periodic_metrics_does_not_flag_a_legitimately_full_pool() -> None:
+    # The guard must not fire on a pool that is simply saturated, or it is noise.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy")[0].args[1] == pytest.approx(
+        1.0
+    )
+    assert _incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_overflow") == []
+
+
+def test_emit_periodic_metrics_counters_exclude_non_running_children() -> None:
+    # occupancy divides by running_count, so the counters have to sum over the
+    # same population. An exiting child folded into the numerator inflates both
+    # the counters and the gauge against slots that are no longer taking work.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = _make_tracked_child("exiting", busy_accumulated=1.0)
+        pool._children[uuid4()] = _make_tracked_child("pending")
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    busy = _distribution_calls(pool._metrics, "taskworker.worker.child_busy_seconds")
+    assert busy[0].args[1] == pytest.approx(1.0)
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy")[0].args[1] == pytest.approx(
+        1.0
+    )
 
 
 def test_spawn_children_tracks_busy_and_idle_transitions() -> None:
@@ -1468,6 +1517,40 @@ def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
     assert child.busy_accumulated == pytest.approx(0.0)
 
 
+def test_tracked_child_stale_event_cannot_bill_an_interval_twice() -> None:
+    # The regression found in the sandbox sweep. The parent reads child events
+    # on a 100ms loop while the metrics thread drains on a 1s cadence, so a
+    # `busy` stamped at 10.2 can arrive after the 11.0 drain has already billed
+    # 10.2-11.0 as wait. Backdating busy_since to 10.2 then bills those same
+    # 0.8s again as busy, and the error grows with the event backlog: the sweep
+    # measured 580 busy-seconds per 1s flush across 24 children, 24x the
+    # physical ceiling, which the occupancy clamp turned into a healthy 1.0.
+    child = _make_tracked_child("running", wait_since=10.0)
+
+    assert child.drain_wait(11.0) == pytest.approx(1.0)
+    assert child.drain_busy(11.0) == pytest.approx(0.0)
+
+    child.mark_busy(10.2)  # stamped before the drain, delivered after it
+
+    busy = child.drain_busy(12.0)
+    wait = child.drain_wait(12.0)
+
+    # The second interval is 1s wide and cannot yield more than 1s of credit.
+    assert busy == pytest.approx(1.0)
+    assert wait == pytest.approx(0.0)
+
+
+def test_tracked_child_accepts_events_predating_its_first_drain() -> None:
+    # The watermark starts at 0.0 so a child that has never been flushed still
+    # records real segment widths rather than collapsing them to the drain time.
+    child = _make_tracked_child("running", wait_since=10.0)
+
+    child.mark_busy(10.4)
+
+    assert child.drain_wait(11.0) == pytest.approx(0.4)
+    assert child.drain_busy(11.0) == pytest.approx(0.6)
+
+
 def test_tracked_child_stops_accruing_wait_once_released() -> None:
     # A released child stops sending messages, so an open wait segment would
     # fold forward forever and make a recycling pool look starved.

From b64314dcc03e8a5feef2247f05db76a70d3ce39b Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Tue, 1 Sep 2026 14:39:12 -0400
Subject: [PATCH 4/9] move segment tracking to own class

---
 .../src/taskbroker_client/worker/worker.py    | 154 +++++++++---------
 clients/python/tests/worker/test_worker.py    |  94 +++++------
 2 files changed, 127 insertions(+), 121 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index 56a94964..630d6aa2 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -9,7 +9,7 @@
 import time
 from collections import deque
 from concurrent.futures import ThreadPoolExecutor
-from dataclasses import dataclass
+from dataclasses import dataclass, field
 from multiprocessing.context import ForkContext, ForkServerContext, SpawnContext
 from multiprocessing.process import BaseProcess
 from multiprocessing.synchronize import Event
@@ -225,105 +225,109 @@ class RequeueException(Exception):
 
 
 @dataclass
-class TrackedChild:
-    process: BaseProcess
-    state: ChildState
-    release: Event
-    # Time-weighted busy tracking
-    busy_since: float | None = None  # monotonic timestamp of the currently-open busy segment
-    busy_accumulated: float = 0.0  # the busy seconds banked since the last occupancy flush
-    # Mirror of the two fields above. Measured rather than inferred as
-    # `elapsed - busy`, which only holds for children running the whole interval.
-    wait_since: float | None = None  # monotonic timestamp of the currently-open wait segment
-    wait_accumulated: float = 0.0  # the waiting seconds banked since the last flush
-    # Everything up to here has already been drained and emitted. Segment
-    # boundaries stamped earlier than this are clamped forward to it. 0.0 means
-    # "never drained"; time.monotonic() is always well above it, so a child that
-    # has not been flushed yet accepts its events verbatim.
+class TimeSegment:
+    """Used to track a child proceses' time: either its busy clock or its wait clock.
+
+    `since` is the monotonic start of the currently-open time segment, or None when
+    the time segment is closed. `accumulated` holds seconds banked but not yet
+    emitted.
+    """
+
+    since: float | None = None
+    accumulated: float = 0.0
+
+    def open(self, now: float) -> None:
+        """Start a segment, keeping the earlier start if one is already open."""
+        if self.since is None:
+            self.since = now
+
+    def close(self, now: float) -> None:
+        """Bank the open segment up to `now` and close it. No-op if closed."""
+        if self.since is not None:
+            self.accumulated += max(0.0, now - self.since)
+            self.since = None
+
+    def drain(self, now: float) -> float:
+        """Return banked seconds and reset, leaving an open time segment open.
+
+        A still-open time segment is folded in up to `now` and restarted there, so a
+        task spanning several intervals contributes to each one.
+        """
+        if self.since is not None:
+            self.accumulated += max(0.0, now - self.since)
+            self.since = now
+        banked = self.accumulated
+        self.accumulated = 0.0
+        return banked
+
+
+@dataclass
+class ChildTimeAccounting:
+    """Time-weighted busy/wait accounting for one child.
+
+    A running child is always in exactly one of the two states, so over any
+    interval `drain_busy` + `drain_wait` must sum to that interval's width.
+
+    Wait time is measured rather than inferred as `elapsed - busy`, which only holds
+    for children that ran for the whole interval.
+    """
+
+    busy: TimeSegment = field(default_factory=TimeSegment)
+    wait: TimeSegment = field(default_factory=TimeSegment)
     last_drained_at: float = 0.0
 
     def _clamp(self, now: float) -> float:
         """Never let a segment boundary land inside an already-emitted interval.
 
-        The parent reads child events on a 100ms loop while the metrics thread
-        drains on a 1s cadence, so an event routinely arrives stamped *before*
-        the drain that already accounted for that time. Honouring the stale
-        stamp would re-bill those seconds: `mark_busy` would clip the wait
-        closure to zero, leaving the emitted wait in place, and then open a
-        busy segment starting back inside it. Both counters then bill the same
-        wall clock, which is unbounded when the event backlog grows.
+        Only child-supplied timestamps need this. The time segment drains are driven by the
+        metrics thread's own monotonic clock, which never runs backwards.
         """
         return max(now, self.last_drained_at)
 
     def mark_running(self, now: float) -> None:
         """Start the wait clock: a `pending` child is importing, not starving."""
-        now = self._clamp(now)
-        if self.busy_since is None and self.wait_since is None:
-            self.wait_since = now
+        if self.busy.since is None and self.wait.since is None:
+            self.wait.open(self._clamp(now))
 
     def mark_busy(self, now: float) -> None:
-        """Close the open wait segment and open a busy one.
-
-        `busy`/`idle` strictly alternate per child today, so a busy segment
-        should never already be open; the guard is defensive and keeps the
-        original start time if that invariant ever drifts.
-        """
+        """Close the open wait segment and open a busy one."""
         now = self._clamp(now)
-        if self.wait_since is not None:
-            self.wait_accumulated += max(0.0, now - self.wait_since)
-            self.wait_since = None
-        if self.busy_since is None:
-            self.busy_since = now
+        self.wait.close(now)
+        self.busy.open(now)
 
     def mark_idle(self, now: float) -> None:
-        """Close the open busy segment and open a wait one.
-
-        Guarded so an unexpected `idle` with no open segment is a no-op rather
-        than a crash.
-        """
+        """Close the open busy segment and open a wait one."""
         now = self._clamp(now)
-        if self.busy_since is not None:
-            self.busy_accumulated += max(0.0, now - self.busy_since)
-            self.busy_since = None
-        if self.wait_since is None:
-            self.wait_since = now
+        self.busy.close(now)
+        self.wait.open(now)
 
     def mark_stopped(self, now: float) -> None:
         """Close both segments so a released child stops folding wait forward."""
         now = self._clamp(now)
-        if self.busy_since is not None:
-            self.busy_accumulated += max(0.0, now - self.busy_since)
-            self.busy_since = None
-        if self.wait_since is not None:
-            self.wait_accumulated += max(0.0, now - self.wait_since)
-            self.wait_since = None
+        self.busy.close(now)
+        self.wait.close(now)
 
     def drain_busy(self, now: float) -> float:
-        """Return busy seconds since the last drain and reset the counter.
-
-        Any segment still open is folded in up to `now` and left open (its
-        start advanced to `now`) so a task spanning multiple intervals keeps
-        contributing to each one.
-        """
-        if self.busy_since is not None:
-            self.busy_accumulated += max(0.0, now - self.busy_since)
-            self.busy_since = now
+        """Return busy seconds since the last drain and reset the counter."""
+        banked = self.busy.drain(now)
         self.last_drained_at = now
-        banked = self.busy_accumulated
-        self.busy_accumulated = 0.0
         return banked
 
     def drain_wait(self, now: float) -> float:
         """Mirror of `drain_busy`, so a long block counts in every interval it spans."""
-        if self.wait_since is not None:
-            self.wait_accumulated += max(0.0, now - self.wait_since)
-            self.wait_since = now
+        banked = self.wait.drain(now)
         self.last_drained_at = now
-        banked = self.wait_accumulated
-        self.wait_accumulated = 0.0
         return banked
 
 
+@dataclass
+class TrackedChild:
+    process: BaseProcess
+    state: ChildState
+    release: Event
+    timing: ChildTimeAccounting = field(default_factory=ChildTimeAccounting)
+
+
 class PushTaskWorker:
     _mp_context: ForkContext | SpawnContext | ForkServerContext
 
@@ -1057,8 +1061,8 @@ def _emit_periodic_metrics(self) -> None:
                 if child.state != "running":
                     continue
 
-                busy_time += child.drain_busy(now)
-                wait_time += child.drain_wait(now)
+                busy_time += child.timing.drain_busy(now)
+                wait_time += child.timing.drain_wait(now)
 
             exiting_children = len(self._exiting_children)
 
@@ -1309,7 +1313,7 @@ def spawn_children_thread() -> None:
                         # This child is now running
                         if message.event == "running":
                             child.state = "running"
-                            child.mark_running(message.timestamp)
+                            child.timing.mark_running(message.timestamp)
 
                         # This child wants to exit, but we may not have enough running children to shut down right away
                         elif message.event == "exiting":
@@ -1319,12 +1323,12 @@ def spawn_children_thread() -> None:
                         # child's timestamp: this loop drains on a 100ms sleep,
                         # so stamping here credits work to the wrong interval.
                         elif message.event == "busy":
-                            child.mark_busy(message.timestamp)
+                            child.timing.mark_busy(message.timestamp)
 
                         # This child finished a task: close the open busy segment
                         # and bank the elapsed time.
                         elif message.event == "idle":
-                            child.mark_idle(message.timestamp)
+                            child.timing.mark_idle(message.timestamp)
 
                     while True:
                         # Compute how many children are still running
@@ -1346,7 +1350,7 @@ def spawn_children_thread() -> None:
                             continue
 
                         child.state = "exiting"
-                        child.mark_stopped(time.monotonic())
+                        child.timing.mark_stopped(time.monotonic())
                         child.release.set()
 
                     spawned = sum(1 for c in self._children.values() if c.state != "exiting")
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 5cb3f073..6efa8a04 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -44,10 +44,12 @@
 from taskbroker_client.state import current_task
 from taskbroker_client.types import InflightTaskActivation, ProcessingResult
 from taskbroker_client.worker.worker import (
+    ChildTimeAccounting,
     PushTaskWorker,
     ShutdownSignal,
     TaskWorker,
     TaskWorkerProcessingPool,
+    TimeSegment,
     TrackedChild,
     WorkerServicer,
 )
@@ -1287,10 +1289,10 @@ def _make_tracked_child(
         process=mock.Mock(),
         state=state,  # type: ignore[arg-type]
         release=mock.Mock(),
-        busy_since=busy_since,
-        busy_accumulated=busy_accumulated,
-        wait_since=wait_since,
-        wait_accumulated=wait_accumulated,
+        timing=ChildTimeAccounting(
+            busy=TimeSegment(since=busy_since, accumulated=busy_accumulated),
+            wait=TimeSegment(since=wait_since, accumulated=wait_accumulated),
+        ),
     )
 
 
@@ -1354,9 +1356,9 @@ def test_emit_periodic_metrics_time_weights_busy_over_the_interval() -> None:
     assert occupancy_calls[0].args[1] == pytest.approx(1.24 / 3)
 
     # The open segment is carried into the next interval; banks are drained.
-    assert pool._children[child_b].busy_since == pytest.approx(11.0)
+    assert pool._children[child_b].timing.busy.since == pytest.approx(11.0)
     for child in pool._children.values():
-        assert child.busy_accumulated == 0.0
+        assert child.timing.busy.accumulated == 0.0
     assert pool._last_occupancy_flush_at == pytest.approx(11.0)
 
 
@@ -1461,13 +1463,13 @@ def test_spawn_children_tracks_busy_and_idle_transitions() -> None:
 
         # "busy" opens a segment.
         messages.put(ChildMessage(child_id, "busy"))
-        _wait_for(lambda: pool._children[child_id].busy_since is not None)
+        _wait_for(lambda: pool._children[child_id].timing.busy.since is not None)
 
         # "idle" closes it and banks a positive amount of busy-time.
         messages.put(ChildMessage(child_id, "idle"))
         _wait_for(
-            lambda: pool._children[child_id].busy_since is None
-            and pool._children[child_id].busy_accumulated > 0
+            lambda: pool._children[child_id].timing.busy.since is None
+            and pool._children[child_id].timing.busy.accumulated > 0
         )
     finally:
         pool.shutdown()
@@ -1478,14 +1480,14 @@ def test_tracked_child_records_real_widths_for_events_in_one_batch() -> None:
     # every segment in a batch to zero width. Two 50ms tasks, 10ms apart:
     child = _make_tracked_child("running", wait_since=100.00)
 
-    child.mark_busy(100.00)
-    child.mark_idle(100.05)
-    child.mark_busy(100.06)
-    child.mark_idle(100.11)
+    child.timing.mark_busy(100.00)
+    child.timing.mark_idle(100.05)
+    child.timing.mark_busy(100.06)
+    child.timing.mark_idle(100.11)
 
     # 0.05 + 0.05 of work, and the 0.01 gap between them counted as waiting.
-    assert child.busy_accumulated == pytest.approx(0.10)
-    assert child.wait_accumulated == pytest.approx(0.01)
+    assert child.timing.busy.accumulated == pytest.approx(0.10)
+    assert child.timing.wait.accumulated == pytest.approx(0.01)
 
 
 def test_tracked_child_busy_and_wait_partition_the_interval() -> None:
@@ -1493,17 +1495,17 @@ def test_tracked_child_busy_and_wait_partition_the_interval() -> None:
     # to the interval width.
     child = _make_tracked_child("running", wait_since=10.0)
 
-    child.mark_busy(10.4)
-    busy = child.drain_busy(11.0)
-    wait = child.drain_wait(11.0)
+    child.timing.mark_busy(10.4)
+    busy = child.timing.drain_busy(11.0)
+    wait = child.timing.drain_wait(11.0)
 
     assert busy == pytest.approx(0.6)
     assert wait == pytest.approx(0.4)
     assert busy + wait == pytest.approx(1.0)
 
     # Both open segments are carried forward rather than restarted at zero.
-    assert child.busy_since == pytest.approx(11.0)
-    assert child.wait_since is None
+    assert child.timing.busy.since == pytest.approx(11.0)
+    assert child.timing.wait.since is None
 
 
 def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
@@ -1511,10 +1513,10 @@ def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
     # before that and processed just after must not subtract credited time.
     child = _make_tracked_child("running", busy_since=10.0)
 
-    child.drain_busy(11.0)  # credits 1.0s, advances busy_since to 11.0
-    child.mark_idle(10.95)  # stamped before the drain, delivered after
+    child.timing.drain_busy(11.0)  # credits 1.0s, advances busy_since to 11.0
+    child.timing.mark_idle(10.95)  # stamped before the drain, delivered after
 
-    assert child.busy_accumulated == pytest.approx(0.0)
+    assert child.timing.busy.accumulated == pytest.approx(0.0)
 
 
 def test_tracked_child_stale_event_cannot_bill_an_interval_twice() -> None:
@@ -1527,13 +1529,13 @@ def test_tracked_child_stale_event_cannot_bill_an_interval_twice() -> None:
     # physical ceiling, which the occupancy clamp turned into a healthy 1.0.
     child = _make_tracked_child("running", wait_since=10.0)
 
-    assert child.drain_wait(11.0) == pytest.approx(1.0)
-    assert child.drain_busy(11.0) == pytest.approx(0.0)
+    assert child.timing.drain_wait(11.0) == pytest.approx(1.0)
+    assert child.timing.drain_busy(11.0) == pytest.approx(0.0)
 
-    child.mark_busy(10.2)  # stamped before the drain, delivered after it
+    child.timing.mark_busy(10.2)  # stamped before the drain, delivered after it
 
-    busy = child.drain_busy(12.0)
-    wait = child.drain_wait(12.0)
+    busy = child.timing.drain_busy(12.0)
+    wait = child.timing.drain_wait(12.0)
 
     # The second interval is 1s wide and cannot yield more than 1s of credit.
     assert busy == pytest.approx(1.0)
@@ -1545,10 +1547,10 @@ def test_tracked_child_accepts_events_predating_its_first_drain() -> None:
     # records real segment widths rather than collapsing them to the drain time.
     child = _make_tracked_child("running", wait_since=10.0)
 
-    child.mark_busy(10.4)
+    child.timing.mark_busy(10.4)
 
-    assert child.drain_wait(11.0) == pytest.approx(0.4)
-    assert child.drain_busy(11.0) == pytest.approx(0.6)
+    assert child.timing.drain_wait(11.0) == pytest.approx(0.4)
+    assert child.timing.drain_busy(11.0) == pytest.approx(0.6)
 
 
 def test_tracked_child_stops_accruing_wait_once_released() -> None:
@@ -1556,20 +1558,20 @@ def test_tracked_child_stops_accruing_wait_once_released() -> None:
     # fold forward forever and make a recycling pool look starved.
     child = _make_tracked_child("running", wait_since=10.0)
 
-    child.mark_stopped(10.5)
-    assert child.drain_wait(20.0) == pytest.approx(0.5)
-    assert child.drain_wait(30.0) == pytest.approx(0.0)
+    child.timing.mark_stopped(10.5)
+    assert child.timing.drain_wait(20.0) == pytest.approx(0.5)
+    assert child.timing.drain_wait(30.0) == pytest.approx(0.0)
 
 
 def test_tracked_child_pending_accrues_neither_busy_nor_wait() -> None:
     # Warmup is not starvation: a child importing the app has no slot to fill.
     child = _make_tracked_child("pending")
 
-    assert child.drain_busy(11.0) == pytest.approx(0.0)
-    assert child.drain_wait(11.0) == pytest.approx(0.0)
+    assert child.timing.drain_busy(11.0) == pytest.approx(0.0)
+    assert child.timing.drain_wait(11.0) == pytest.approx(0.0)
 
-    child.mark_running(11.0)
-    assert child.drain_wait(12.0) == pytest.approx(1.0)
+    child.timing.mark_running(11.0)
+    assert child.timing.drain_wait(12.0) == pytest.approx(1.0)
 
 
 def test_emit_periodic_metrics_emits_busy_and_wait_seconds() -> None:
@@ -1631,11 +1633,11 @@ def test_spawn_children_uses_the_child_timestamp_not_the_drain_time() -> None:
 
         stamped_at = time.monotonic() - 5.0
         messages.put(ChildMessage(child_id, "busy", timestamp=stamped_at))
-        _wait_for(lambda: pool._children[child_id].busy_since is not None)
+        _wait_for(lambda: pool._children[child_id].timing.busy.since is not None)
 
         # The drain lands up to 100ms later on another thread; the segment has
         # to start when the child said it did.
-        assert pool._children[child_id].busy_since == pytest.approx(stamped_at)
+        assert pool._children[child_id].timing.busy.since == pytest.approx(stamped_at)
     finally:
         pool.shutdown()
 
@@ -1654,19 +1656,19 @@ def test_spawn_children_tracks_wait_between_tasks() -> None:
 
         # Reporting in opens a wait segment: available, blocked in get().
         messages.put(ChildMessage(child_id, "running", timestamp=base))
-        _wait_for(lambda: pool._children[child_id].wait_since == pytest.approx(base))
+        _wait_for(lambda: pool._children[child_id].timing.wait.since == pytest.approx(base))
 
         # 2s of waiting, then 1s of work, then waiting again.
         messages.put(ChildMessage(child_id, "busy", timestamp=base + 2.0))
         messages.put(ChildMessage(child_id, "idle", timestamp=base + 3.0))
         # `wait_since` is already set by "running" above, so wait on banked busy.
-        _wait_for(lambda: pool._children[child_id].busy_accumulated > 0)
+        _wait_for(lambda: pool._children[child_id].timing.busy.accumulated > 0)
 
         child = pool._children[child_id]
-        assert child.wait_accumulated == pytest.approx(2.0)
-        assert child.busy_accumulated == pytest.approx(1.0)
-        assert child.busy_since is None
-        assert child.wait_since == pytest.approx(base + 3.0)
+        assert child.timing.wait.accumulated == pytest.approx(2.0)
+        assert child.timing.busy.accumulated == pytest.approx(1.0)
+        assert child.timing.busy.since is None
+        assert child.timing.wait.since == pytest.approx(base + 3.0)
     finally:
         pool.shutdown()
 

From bbac43bcc31fcc3eb0a8ce3e32ebf347248e398e Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Wed, 2 Sep 2026 11:21:57 -0400
Subject: [PATCH 5/9] comments

---
 .../src/taskbroker_client/worker/worker.py    | 211 ++++++++----------
 .../taskbroker_client/worker/workerchild.py   |  20 +-
 2 files changed, 110 insertions(+), 121 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index 630d6aa2..0885e70e 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -1,5 +1,6 @@
 from __future__ import annotations
 
+import ctypes
 import logging
 import multiprocessing
 import os
@@ -9,7 +10,7 @@
 import time
 from collections import deque
 from concurrent.futures import ThreadPoolExecutor
-from dataclasses import dataclass, field
+from dataclasses import dataclass
 from multiprocessing.context import ForkContext, ForkServerContext, SpawnContext
 from multiprocessing.process import BaseProcess
 from multiprocessing.synchronize import Event
@@ -40,6 +41,12 @@
 )
 from taskbroker_client.metrics import MetricsBackend
 from taskbroker_client.types import InflightTaskActivation, ProcessingResult
+from taskbroker_client.worker.childtiming import (
+    NO_SLOT,
+    SLOT_WIDTH,
+    ChildTimeAccounting,
+    slot_count,
+)
 from taskbroker_client.worker.client import (
     HealthCheckSettings,
     HostTemporarilyUnavailable,
@@ -224,108 +231,14 @@ class RequeueException(Exception):
 ChildState = Literal["pending", "running", "exiting"]
 
 
-@dataclass
-class TimeSegment:
-    """Used to track a child proceses' time: either its busy clock or its wait clock.
-
-    `since` is the monotonic start of the currently-open time segment, or None when
-    the time segment is closed. `accumulated` holds seconds banked but not yet
-    emitted.
-    """
-
-    since: float | None = None
-    accumulated: float = 0.0
-
-    def open(self, now: float) -> None:
-        """Start a segment, keeping the earlier start if one is already open."""
-        if self.since is None:
-            self.since = now
-
-    def close(self, now: float) -> None:
-        """Bank the open segment up to `now` and close it. No-op if closed."""
-        if self.since is not None:
-            self.accumulated += max(0.0, now - self.since)
-            self.since = None
-
-    def drain(self, now: float) -> float:
-        """Return banked seconds and reset, leaving an open time segment open.
-
-        A still-open time segment is folded in up to `now` and restarted there, so a
-        task spanning several intervals contributes to each one.
-        """
-        if self.since is not None:
-            self.accumulated += max(0.0, now - self.since)
-            self.since = now
-        banked = self.accumulated
-        self.accumulated = 0.0
-        return banked
-
-
-@dataclass
-class ChildTimeAccounting:
-    """Time-weighted busy/wait accounting for one child.
-
-    A running child is always in exactly one of the two states, so over any
-    interval `drain_busy` + `drain_wait` must sum to that interval's width.
-
-    Wait time is measured rather than inferred as `elapsed - busy`, which only holds
-    for children that ran for the whole interval.
-    """
-
-    busy: TimeSegment = field(default_factory=TimeSegment)
-    wait: TimeSegment = field(default_factory=TimeSegment)
-    last_drained_at: float = 0.0
-
-    def _clamp(self, now: float) -> float:
-        """Never let a segment boundary land inside an already-emitted interval.
-
-        Only child-supplied timestamps need this. The time segment drains are driven by the
-        metrics thread's own monotonic clock, which never runs backwards.
-        """
-        return max(now, self.last_drained_at)
-
-    def mark_running(self, now: float) -> None:
-        """Start the wait clock: a `pending` child is importing, not starving."""
-        if self.busy.since is None and self.wait.since is None:
-            self.wait.open(self._clamp(now))
-
-    def mark_busy(self, now: float) -> None:
-        """Close the open wait segment and open a busy one."""
-        now = self._clamp(now)
-        self.wait.close(now)
-        self.busy.open(now)
-
-    def mark_idle(self, now: float) -> None:
-        """Close the open busy segment and open a wait one."""
-        now = self._clamp(now)
-        self.busy.close(now)
-        self.wait.open(now)
-
-    def mark_stopped(self, now: float) -> None:
-        """Close both segments so a released child stops folding wait forward."""
-        now = self._clamp(now)
-        self.busy.close(now)
-        self.wait.close(now)
-
-    def drain_busy(self, now: float) -> float:
-        """Return busy seconds since the last drain and reset the counter."""
-        banked = self.busy.drain(now)
-        self.last_drained_at = now
-        return banked
-
-    def drain_wait(self, now: float) -> float:
-        """Mirror of `drain_busy`, so a long block counts in every interval it spans."""
-        banked = self.wait.drain(now)
-        self.last_drained_at = now
-        return banked
-
-
 @dataclass
 class TrackedChild:
     process: BaseProcess
     state: ChildState
     release: Event
-    timing: ChildTimeAccounting = field(default_factory=ChildTimeAccounting)
+    # Bound to this child's shared-memory slot at spawn time, so there is no
+    # sensible default: an accountant with no slot silently measures nothing.
+    timing: ChildTimeAccounting
 
 
 class PushTaskWorker:
@@ -998,6 +911,18 @@ def __init__(
         )
         self._children: Dict[UUID, TrackedChild] = {}
         self._exiting_children: Deque[UUID] = deque()
+
+        # Children write their own busy/wait totals here and the parent diffs
+        # them once a second. Sized for two generations because
+        # `spawn_children_thread` ignores exiting children when deciding how
+        # many to spawn, so a full set of unreaped children can briefly overlap
+        # a full set of replacements. Slots are handed out and returned under
+        # `_children_lock`.
+        self._timing_slots: int = slot_count(concurrency)
+        self._timing_shm: ctypes.Array[ctypes.c_double] = self._mp_context.RawArray(
+            "d", SLOT_WIDTH * self._timing_slots
+        )
+        self._free_timing_slots: Deque[int] = deque(range(self._timing_slots))
         self._children_lock = threading.Lock()
         self._last_occupancy_flush_at = time.monotonic()
         self._shutdown_event = self._mp_context.Event()
@@ -1007,6 +932,50 @@ def __init__(
         self._metrics_thread: threading.Thread | None = None
         self._spawn_children_thread: threading.Thread | None = None
 
+    def _acquire_timing_slot(self) -> int:
+        """Take a zeroed shared-memory slot for a new child.
+
+        `NO_SLOT` means the pool ran out, which the two-generation sizing is
+        meant to make impossible. That child then contributes to neither the
+        occupancy numerator nor `running_count`, so the ratio stays consistent
+        across the children that are accounted for, and the metric below says
+        the sizing was wrong.
+        """
+        with self._children_lock:
+            if not self._free_timing_slots:
+                slot = NO_SLOT
+            else:
+                slot = self._free_timing_slots.popleft()
+
+        if slot == NO_SLOT:
+            logger.error(
+                "taskworker.child.timing_slot_exhausted",
+                extra={
+                    "slots": self._timing_slots,
+                    "processing_pool": self._processing_pool_name,
+                },
+            )
+            self._metrics.incr(
+                "taskworker.worker.child.timing_slot_exhausted",
+                tags={"processing_pool": self._processing_pool_name},
+            )
+            return NO_SLOT
+
+        base = slot * SLOT_WIDTH
+        for offset in range(SLOT_WIDTH):
+            self._timing_shm[base + offset] = 0.0
+
+        return slot
+
+    def _release_timing_slot(self, slot: int) -> None:
+        """Return a slot whose child never started. The reap path returns slots
+        inline because it already holds `_children_lock`."""
+        if slot == NO_SLOT:
+            return
+
+        with self._children_lock:
+            self._free_timing_slots.append(slot)
+
     @property
     def ready_count(self) -> int:
         """Number of children that have finished warming up and are consuming."""
@@ -1055,14 +1024,15 @@ def _emit_periodic_metrics(self) -> None:
                 # Running children only: occupancy divides by `running_count`,
                 # so folding a `pending` or `exiting` child into the numerator
                 # measures one population against another. Neither has time to
-                # lose here. A `pending` child has not opened a segment yet,
-                # and `mark_stopped` deliberately closes an `exiting` child's
-                # segments so its tail stops counting against the live pool.
+                # lose here. A `pending` child is not being accounted yet, and
+                # `mark_stopped` deliberately stops accounting an `exiting`
+                # child so its tail does not count against the live pool.
                 if child.state != "running":
                     continue
 
-                busy_time += child.timing.drain_busy(now)
-                wait_time += child.timing.drain_wait(now)
+                busy, wait = child.timing.sample(now)
+                busy_time += busy
+                wait_time += wait
 
             exiting_children = len(self._exiting_children)
 
@@ -1283,6 +1253,13 @@ def spawn_children_thread() -> None:
                         c.process.join(timeout=0)
                         self._children.pop(cid)
 
+                        # Reclaim here rather than on the `exiting` transition:
+                        # a released child can still publish once before it
+                        # breaks out of its loop, and handing that slot to a
+                        # replacement would mix two children's totals.
+                        if c.timing.slot != NO_SLOT:
+                            self._free_timing_slots.append(c.timing.slot)
+
                         logger.info(
                             "taskworker.child.exited",
                             extra={
@@ -1310,26 +1287,18 @@ def spawn_children_thread() -> None:
 
                             continue
 
-                        # This child is now running
+                        # This child is now running. Baseline against the slot
+                        # as it stands rather than the child's timestamp: the
+                        # child only enters `running_count` here, so starting
+                        # the numerator here keeps the ratio consistent.
                         if message.event == "running":
                             child.state = "running"
-                            child.timing.mark_running(message.timestamp)
+                            child.timing.mark_running(time.monotonic())
 
                         # This child wants to exit, but we may not have enough running children to shut down right away
                         elif message.event == "exiting":
                             self._exiting_children.append(message.child_id)
 
-                        # Close the wait segment and open a busy one, at the
-                        # child's timestamp: this loop drains on a 100ms sleep,
-                        # so stamping here credits work to the wrong interval.
-                        elif message.event == "busy":
-                            child.timing.mark_busy(message.timestamp)
-
-                        # This child finished a task: close the open busy segment
-                        # and bank the elapsed time.
-                        elif message.event == "idle":
-                            child.timing.mark_idle(message.timestamp)
-
                     while True:
                         # Compute how many children are still running
                         running = sum(1 for c in self._children.values() if c.state == "running")
@@ -1350,7 +1319,7 @@ def spawn_children_thread() -> None:
                             continue
 
                         child.state = "exiting"
-                        child.timing.mark_stopped(time.monotonic())
+                        child.timing.mark_stopped()
                         child.release.set()
 
                     spawned = sum(1 for c in self._children.values() if c.state != "exiting")
@@ -1361,6 +1330,7 @@ def spawn_children_thread() -> None:
                 for _ in range(needed):
                     child_id = uuid4()
                     release = self._mp_context.Event()
+                    timing_slot = self._acquire_timing_slot()
 
                     process = self._mp_context.Process(
                         name=f"taskworker-child-{child_id}",
@@ -1378,6 +1348,8 @@ def spawn_children_thread() -> None:
                             self._future_checking_frequency,
                             messages,
                             release,
+                            self._timing_shm,
+                            timing_slot,
                         ),
                     )
 
@@ -1389,10 +1361,15 @@ def spawn_children_thread() -> None:
                                 process=process,
                                 state="pending",
                                 release=release,
+                                timing=ChildTimeAccounting(shm=self._timing_shm, slot=timing_slot),
                             )
 
                             self._children[child_id] = child
                     except Exception as e:
+                        # The child never came up, so nothing will ever write
+                        # to its slot.
+                        self._release_timing_slot(timing_slot)
+
                         logger.exception(
                             "taskworker.child.spawn.failed",
                             extra={
diff --git a/clients/python/src/taskbroker_client/worker/workerchild.py b/clients/python/src/taskbroker_client/worker/workerchild.py
index 3229132e..20fadf4a 100644
--- a/clients/python/src/taskbroker_client/worker/workerchild.py
+++ b/clients/python/src/taskbroker_client/worker/workerchild.py
@@ -1,6 +1,7 @@
 from __future__ import annotations
 
 import contextlib
+import ctypes
 import logging
 import multiprocessing
 import queue
@@ -40,6 +41,7 @@
 from taskbroker_client.state import clear_current_task, current_task, set_current_task
 from taskbroker_client.task import Task
 from taskbroker_client.types import ContextHook, InflightTaskActivation, ProcessingResult
+from taskbroker_client.worker.childtiming import ChildTimeWriter
 
 logger = logging.getLogger(__name__)
 
@@ -169,7 +171,7 @@ def _log_task_retry_exhausted(
 @dataclass(frozen=True)
 class ChildMessage:
     child_id: UUID
-    event: Literal["running", "exiting", "busy", "idle"]
+    event: Literal["running", "exiting"]
     # Stamped at the event, not when the parent drains it 100ms later.
     # CLOCK_MONOTONIC is system-wide, so a child's stamp is valid in the parent.
     # compare=False: the timestamp is payload, not identity.
@@ -189,6 +191,8 @@ def child_process(
     future_checking_frequency: float,
     messages: multiprocessing.Queue[ChildMessage],
     parent_release: Event,
+    timing_shm: ctypes.Array[ctypes.c_double] | None,
+    timing_slot: int,
 ) -> None:
     """
     The entrypoint for spawned worker children.
@@ -200,6 +204,13 @@ def child_process(
     app = import_app(app_module)
     app.load_modules()
     metrics = app.metrics
+
+    # Busy/wait accounting goes straight into shared memory rather than over
+    # `messages`. The parent's drain thread competes for CPU with the children
+    # it measures, so at two events per task it falls behind under saturation
+    # and occupancy goes stale. This costs the parent one read per child per
+    # second instead.
+    timing = ChildTimeWriter(timing_shm, timing_slot)
     # Signals when the parent worker pool terminates the child
     local_shutdown = threading.Event()
 
@@ -381,7 +392,7 @@ def check_task_future_completion(
             # the child did since its last dequeue has finished, and what follows
             # is waiting for the next task.
             if is_busy:
-                messages.put_nowait(ChildMessage(child_id, "idle"))
+                timing.mark_idle(time.monotonic())
                 is_busy = False
 
             if max_task_count and processed_task_count >= max_task_count:
@@ -441,7 +452,7 @@ def check_task_future_completion(
 
             # Open the busy segment as soon as we have a task. The slot is now
             # unavailable for new work, whatever stage of handling it is in.
-            messages.put_nowait(ChildMessage(child_id, "busy"))
+            timing.mark_busy(time.monotonic())
             is_busy = True
 
             task_func = _get_known_task(inflight.activation)
@@ -629,7 +640,7 @@ def check_task_future_completion(
         # signal can land while a segment is still open. Close it so a child that
         # is going away doesn't keep contributing busy time to the pool's occupancy.
         if is_busy:
-            messages.put_nowait(ChildMessage(child_id, "idle"))
+            timing.close(time.monotonic())
             is_busy = False
 
         # Once we get the shutdown signal, drain any pending futures
@@ -889,6 +900,7 @@ def _task_execution_complete(
         )
 
     # Tell the parent that this child has warmed up and is ready to consume tasks
+    timing.mark_running(time.monotonic())
     messages.put_nowait(ChildMessage(child_id, "running"))
 
     # Run the worker loop

From abccb485ef9efb320f9cc1aa9b0aa39eab1d9238 Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Wed, 2 Sep 2026 12:58:48 -0400
Subject: [PATCH 6/9] Move child busy/wait accounting into shared memory

Occupancy was only accurate while the parent's spawn-children thread kept
up with the child event stream. Every task pushed two ChildMessage objects
through a multiprocessing.Queue, each pickled in the child and unpickled in
a parent thread competing for CPU with the children it measures. Sandbox
run 1788289180 showed the result: under a 100ms all-CPU task at ~276
messages/s, child_message.age ramped from 0.25s to 81.4s inside one stage
and never recovered, and occupancy read 0.430 against a true 0.996. The
C=64 control on the 40ms task, at 6x the message rate but with CPU
headroom, stayed flat at 0.199s and accurate to 0.014.

Children now write their own cumulative busy/wait totals into a RawArray
slot and the parent diffs them at flush, so the cost is O(children) per
second instead of O(tasks) per second. Only lifecycle events still cross
the queue, two per child rather than two per task.

Slots are cumulative and absolute rather than deltas, which is what makes a
torn read survivable: a bad sample is transient and the next one re-derives
the truth from the slot. A seqlock guards the four-field publish. Folding
the open segment forward at read time preserves the property that a child
in a long task contributes to every interval it spans, which is why this is
shared memory rather than children emitting their own metrics.

The watermark from the previous commit is gone; it existed only to defend
against stale busy/idle events and there are none left. Metric names,
the occupancy formula, accounting_overflow and the KEDA trigger are all
unchanged, so no dashboard or scaler edits are needed.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
---
 .../taskbroker_client/worker/childtiming.py   | 228 +++++++++
 .../src/taskbroker_client/worker/worker.py    |  15 +-
 clients/python/tests/worker/test_worker.py    | 437 ++++++++++++------
 3 files changed, 530 insertions(+), 150 deletions(-)
 create mode 100644 clients/python/src/taskbroker_client/worker/childtiming.py

diff --git a/clients/python/src/taskbroker_client/worker/childtiming.py b/clients/python/src/taskbroker_client/worker/childtiming.py
new file mode 100644
index 00000000..34d9a50d
--- /dev/null
+++ b/clients/python/src/taskbroker_client/worker/childtiming.py
@@ -0,0 +1,228 @@
+"""Shared-memory busy/wait accounting for worker children.
+
+Once a second the parent needs to know how many seconds each child spent
+executing versus waiting for work. To accomplish that each child owns a slot
+in a ``RawArray`` of doubles and writes its own cumulative totals there. The
+parent reads and diffs the slots at flush time.
+
+Slot layout, five doubles per child::
+
+    0  version         seqlock; odd means a write is in progress
+    1  busy_total      cumulative seconds closed into busy
+    2  wait_total      cumulative seconds closed into wait
+    3  segment_start   time.monotonic() when the currently-open segment began
+    4  segment_kind    KIND_NONE, KIND_WAIT or KIND_BUSY
+
+Two properties carry the design.
+
+Every value is absolute and cumulative rather than a delta, which is what makes
+a torn read survivable: a bad sample is transient and the next one re-derives
+the truth from the slot, so error cannot accumulate.
+
+``KIND_NONE`` is zero, so a freshly zeroed slot reads as "this child has not
+accounted for anything yet" rather than as an open segment starting at time
+zero.
+
+``time.monotonic()`` is CLOCK_MONOTONIC, which is system-wide, so a child's
+timestamps are directly comparable in the parent.
+"""
+
+from __future__ import annotations
+
+import ctypes
+from dataclasses import dataclass
+
+# Offsets within a slot, and the slot stride.
+SLOT_VERSION = 0
+SLOT_BUSY_TOTAL = 1
+SLOT_WAIT_TOTAL = 2
+SLOT_SEGMENT_START = 3
+SLOT_SEGMENT_KIND = 4
+SLOT_WIDTH = 5
+
+# Kind values. NONE must be 0.0 so that a zeroed slot means "nothing open".
+KIND_NONE = 0.0
+KIND_WAIT = 1.0
+KIND_BUSY = 2.0
+
+# Slot index handed to a child when the pool has none left. Every read and
+# write becomes a no-op and the parent leaves that child out of occupancy.
+NO_SLOT = -1
+
+# A writer holds the seqlock for four stores, so a reader that loses three
+# races in a row is seeing something other than ordinary contention.
+SEQLOCK_READ_ATTEMPTS = 3
+
+
+def slot_count(concurrency: int) -> int:
+    """How many slots a pool of `concurrency` children needs.
+
+    Twice concurrency. `spawn_children_thread` counts only non-exiting children
+    when deciding how many to spawn, so a full generation of exiting-but-unreaped
+    children can briefly coexist with a full generation of replacements.
+    """
+    return max(1, concurrency * 2)
+
+
+class ChildTimeWriter:
+    """Child-side writer for one slot.
+
+    The child is the only writer for its slot, so it keeps the authoritative
+    totals as plain Python floats and republishes the whole slot on each
+    transition. That avoids a read-modify-write against shared memory.
+    """
+
+    __slots__ = ("_shm", "_slot", "_base", "_busy_total", "_wait_total", "_start", "_kind")
+
+    def __init__(self, shm: ctypes.Array[ctypes.c_double] | None, slot: int) -> None:
+        self._shm = shm
+        self._slot = NO_SLOT if shm is None else slot
+        self._base = slot * SLOT_WIDTH
+        self._busy_total = 0.0
+        self._wait_total = 0.0
+        self._start = 0.0
+        self._kind = KIND_NONE
+
+    def _publish(self) -> None:
+        if self._slot == NO_SLOT or self._shm is None:
+            return
+
+        shm = self._shm
+        base = self._base
+
+        version = shm[base + SLOT_VERSION]
+        # Odd version: a reader that sees this discards what it read.
+        shm[base + SLOT_VERSION] = version + 1.0
+        shm[base + SLOT_BUSY_TOTAL] = self._busy_total
+        shm[base + SLOT_WAIT_TOTAL] = self._wait_total
+        shm[base + SLOT_SEGMENT_START] = self._start
+        shm[base + SLOT_SEGMENT_KIND] = self._kind
+        shm[base + SLOT_VERSION] = version + 2.0
+
+    def _close_open(self, now: float) -> None:
+        if self._kind == KIND_BUSY:
+            self._busy_total += max(0.0, now - self._start)
+        elif self._kind == KIND_WAIT:
+            self._wait_total += max(0.0, now - self._start)
+        self._kind = KIND_NONE
+
+    def mark_running(self, now: float) -> None:
+        """Open the wait clock. A warmed-up child with no task yet is waiting."""
+        if self._kind != KIND_NONE:
+            return
+
+        self._start = now
+        self._kind = KIND_WAIT
+        self._publish()
+
+    def mark_busy(self, now: float) -> None:
+        """Close the open wait segment and open a busy one."""
+        self._close_open(now)
+        self._start = now
+        self._kind = KIND_BUSY
+        self._publish()
+
+    def mark_idle(self, now: float) -> None:
+        """Close the open busy segment and open a wait one."""
+        self._close_open(now)
+        self._start = now
+        self._kind = KIND_WAIT
+        self._publish()
+
+    def close(self, now: float) -> None:
+        """Close whatever is open so a departing child stops folding time forward."""
+        self._close_open(now)
+        self._publish()
+
+
+@dataclass
+class ChildTimeAccounting:
+    """Parent-side reader for one child's slot.
+
+    Holds the previous absolute reading and returns deltas. A child sitting in a
+    long task therefore contributes to every interval it spans, instead of
+    dumping its whole duration into the interval it happens to finish in.
+    """
+
+    shm: ctypes.Array[ctypes.c_double] | None
+    slot: int = NO_SLOT
+    _prev_busy: float = 0.0
+    _prev_wait: float = 0.0
+    _accounted: bool = False
+
+    def mark_running(self, now: float) -> None:
+        """Start counting this child, baselining against the slot as it stands.
+
+        Baselining rather than zeroing means whatever the child banked between
+        spawning and the parent seeing its `running` message is not credited
+        retroactively. The child is excluded from `running_count` over that same
+        window, so the numerator and the denominator start together.
+        """
+        reading = self._read(now)
+        if reading is None:
+            # Slots are zeroed at allocation, so a failed first read costs at
+            # most the few microseconds since the child came up.
+            self._prev_busy = 0.0
+            self._prev_wait = 0.0
+        else:
+            self._prev_busy, self._prev_wait = reading
+
+        self._accounted = True
+
+    def mark_stopped(self) -> None:
+        """Stop counting this child, so an exiting child's tail does not land on
+        the live pool's occupancy."""
+        self._accounted = False
+
+    def sample(self, now: float) -> tuple[float, float]:
+        """Return (busy, wait) seconds accrued since the previous sample."""
+        if not self._accounted:
+            return (0.0, 0.0)
+
+        reading = self._read(now)
+        if reading is None:
+            # Leave the baseline alone: the next sample then covers both
+            # intervals. Deferring the attribution beats dropping it.
+            return (0.0, 0.0)
+
+        busy_now, wait_now = reading
+        busy = max(0.0, busy_now - self._prev_busy)
+        wait = max(0.0, wait_now - self._prev_wait)
+        self._prev_busy = busy_now
+        self._prev_wait = wait_now
+        return (busy, wait)
+
+    def _read(self, now: float) -> tuple[float, float] | None:
+        """Seqlock read of absolute busy/wait, including the segment still open.
+
+        None means the read could not be taken cleanly and the caller should
+        keep whatever baseline it already has.
+        """
+        if self.slot == NO_SLOT or self.shm is None:
+            return None
+
+        shm = self.shm
+        base = self.slot * SLOT_WIDTH
+
+        for _ in range(SEQLOCK_READ_ATTEMPTS):
+            version = shm[base + SLOT_VERSION]
+            if version % 2.0:
+                continue
+
+            busy = shm[base + SLOT_BUSY_TOTAL]
+            wait = shm[base + SLOT_WAIT_TOTAL]
+            start = shm[base + SLOT_SEGMENT_START]
+            kind = shm[base + SLOT_SEGMENT_KIND]
+
+            if shm[base + SLOT_VERSION] != version:
+                continue
+
+            # Fold in the segment the child is in right now.
+            if kind == KIND_BUSY:
+                busy += max(0.0, now - start)
+            elif kind == KIND_WAIT:
+                wait += max(0.0, now - start)
+
+            return (busy, wait)
+
+        return None
diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index 0885e70e..a70d85b5 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -1018,6 +1018,7 @@ def _emit_periodic_metrics(self) -> None:
 
             busy_time = 0.0
             wait_time = 0.0
+            accounted_running = 0
             for child in self._children.values():
                 state_counts[child.state] += 1
 
@@ -1030,6 +1031,14 @@ def _emit_periodic_metrics(self) -> None:
                 if child.state != "running":
                     continue
 
+                # A child with no slot reports nothing, so leaving it in the
+                # denominator would read as an idle child rather than as a
+                # missing measurement. `timing_slot_exhausted` is what
+                # surfaces it instead.
+                if child.timing.slot == NO_SLOT:
+                    continue
+
+                accounted_running += 1
                 busy, wait = child.timing.sample(now)
                 busy_time += busy
                 wait_time += wait
@@ -1061,7 +1070,11 @@ def _emit_periodic_metrics(self) -> None:
                 max(0.0, wait_time)
             )
 
-        running_count = state_counts["running"]
+        # Children the pool could not give a slot to are excluded on both
+        # sides, so occupancy stays a consistent ratio over the children that
+        # are actually accounted for. `state_counts` still reports every
+        # running child to the `children` gauge.
+        running_count = accounted_running
         if running_count > 0 and elapsed > 0:
             # A child cannot be busy for longer than the interval, so this is a
             # hard physical bound on both counters. Exceeding it means the
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 6efa8a04..7b06155f 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -1,6 +1,8 @@
 import contextlib
+import itertools
 import os
 import queue
+import random
 import signal
 import threading
 import time
@@ -43,13 +45,26 @@
 from taskbroker_client.retry import NoRetriesRemainingError
 from taskbroker_client.state import current_task
 from taskbroker_client.types import InflightTaskActivation, ProcessingResult
-from taskbroker_client.worker.worker import (
+from taskbroker_client.worker.childtiming import (
+    KIND_BUSY,
+    KIND_NONE,
+    KIND_WAIT,
+    NO_SLOT,
+    SLOT_BUSY_TOTAL,
+    SLOT_SEGMENT_KIND,
+    SLOT_SEGMENT_START,
+    SLOT_VERSION,
+    SLOT_WAIT_TOTAL,
+    SLOT_WIDTH,
     ChildTimeAccounting,
+    ChildTimeWriter,
+    slot_count,
+)
+from taskbroker_client.worker.worker import (
     PushTaskWorker,
     ShutdownSignal,
     TaskWorker,
     TaskWorkerProcessingPool,
-    TimeSegment,
     TrackedChild,
     WorkerServicer,
 )
@@ -316,6 +331,8 @@ def child_process(
         future_checking_frequency,
         messages,
         parent_release,
+        ctx.RawArray("d", SLOT_WIDTH),
+        0,
     )
 
 
@@ -412,6 +429,9 @@ def Process(self, *args: Any, **kwargs: Any) -> _FakeProcess:
         self.processes.append(process)
         return process
 
+    def RawArray(self, typecode: str, size: int) -> Any:
+        return get_context("fork").RawArray(typecode, size)
+
 
 def _make_fake_context_pool(
     fake_context: _FakeContext,
@@ -1277,6 +1297,13 @@ def ready_count() -> int:
     pool_shutdown.assert_called_once_with()
 
 
+# Slots for children built by `_make_tracked_child`. Independent of any pool:
+# the flush reads through `child.timing.shm`, not the pool's array.
+_TEST_SLOTS = 512
+_TEST_TIMING_SHM = get_context("fork").RawArray("d", SLOT_WIDTH * _TEST_SLOTS)
+_TEST_SLOT_SEQ = itertools.count()
+
+
 def _make_tracked_child(
     state: str,
     *,
@@ -1285,14 +1312,41 @@ def _make_tracked_child(
     wait_since: float | None = None,
     wait_accumulated: float = 0.0,
 ) -> TrackedChild:
+    """Seed a child's slot so its next sample reports the given time.
+
+    `*_accumulated` is time the child has already closed; `*_since` leaves a
+    segment open at that monotonic time, which the parent folds forward at
+    sample time exactly as it would for a task still running.
+    """
+    slot = next(_TEST_SLOT_SEQ) % _TEST_SLOTS
+    base = slot * SLOT_WIDTH
+
+    for offset in range(SLOT_WIDTH):
+        _TEST_TIMING_SHM[base + offset] = 0.0
+
+    timing = ChildTimeAccounting(shm=_TEST_TIMING_SHM, slot=slot)
+    # Baseline against the zeroed slot, so everything seeded below lands in
+    # the first sample.
+    timing.mark_running(0.0)
+
+    if busy_since is not None:
+        kind, start = KIND_BUSY, busy_since
+    elif wait_since is not None:
+        kind, start = KIND_WAIT, wait_since
+    else:
+        kind, start = KIND_NONE, 0.0
+
+    _TEST_TIMING_SHM[base + SLOT_VERSION] = 2.0
+    _TEST_TIMING_SHM[base + SLOT_BUSY_TOTAL] = busy_accumulated
+    _TEST_TIMING_SHM[base + SLOT_WAIT_TOTAL] = wait_accumulated
+    _TEST_TIMING_SHM[base + SLOT_SEGMENT_START] = start
+    _TEST_TIMING_SHM[base + SLOT_SEGMENT_KIND] = kind
+
     return TrackedChild(
         process=mock.Mock(),
         state=state,  # type: ignore[arg-type]
         release=mock.Mock(),
-        timing=ChildTimeAccounting(
-            busy=TimeSegment(since=busy_since, accumulated=busy_accumulated),
-            wait=TimeSegment(since=wait_since, accumulated=wait_accumulated),
-        ),
+        timing=timing,
     )
 
 
@@ -1355,10 +1409,12 @@ def test_emit_periodic_metrics_time_weights_busy_over_the_interval() -> None:
     assert len(occupancy_calls) == 1
     assert occupancy_calls[0].args[1] == pytest.approx(1.24 / 3)
 
-    # The open segment is carried into the next interval; banks are drained.
-    assert pool._children[child_b].timing.busy.since == pytest.approx(11.0)
+    # B's segment is still open, so the next interval picks up where this one
+    # stopped rather than re-reporting the 0.60 already credited.
+    assert pool._children[child_b].timing.sample(12.0) == pytest.approx((1.0, 0.0))
     for child in pool._children.values():
-        assert child.timing.busy.accumulated == 0.0
+        if child.state == "running":
+            assert child.timing.sample(12.0)[0] == pytest.approx(0.0)
     assert pool._last_occupancy_flush_at == pytest.approx(11.0)
 
 
@@ -1425,6 +1481,39 @@ def test_emit_periodic_metrics_does_not_flag_a_legitimately_full_pool() -> None:
     assert _incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_overflow") == []
 
 
+def test_emit_periodic_metrics_excludes_slotless_children_from_occupancy() -> None:
+    # A child the pool could not give a slot to reports nothing. Leaving it in
+    # the denominator would read as a genuinely idle child and halve occupancy,
+    # which is the sort of quiet undercount this whole change exists to remove.
+    # It still belongs in the `children` gauge: the pod really does have it.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    slotless = _make_tracked_child("running")
+    slotless.timing.slot = NO_SLOT
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = slotless
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    # One accounted child, busy for the whole interval.
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy")[0].args[1] == pytest.approx(
+        1.0
+    )
+    assert _incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_overflow") == []
+
+    running_gauges = [
+        c
+        for c in pool._metrics.gauge.call_args_list
+        if c.args[0] == "taskworker.worker.children" and c.kwargs["tags"]["state"] == "running"
+    ]
+    assert running_gauges[0].args[1] == 2.0
+
+
 def test_emit_periodic_metrics_counters_exclude_non_running_children() -> None:
     # occupancy divides by running_count, so the counters have to sum over the
     # same population. An exiting child folded into the numerator inflates both
@@ -1448,130 +1537,195 @@ def test_emit_periodic_metrics_counters_exclude_non_running_children() -> None:
     )
 
 
-def test_spawn_children_tracks_busy_and_idle_transitions() -> None:
+def test_spawn_children_binds_each_child_to_its_own_timing_slot() -> None:
+    # The parent hands the slot to the child at spawn and reads the same slot
+    # at flush. If those ever disagree the pool measures nothing.
     fake_context = _FakeContext()
-    pool = _make_fake_context_pool(fake_context, concurrency=1)
+    pool = _make_fake_context_pool(fake_context, concurrency=2)
 
     pool.start_spawn_children_thread()
     try:
-        _wait_for(lambda: len(fake_context.processes) == 1)
+        _wait_for(lambda: len(fake_context.processes) == 2)
         messages = fake_context.queues[-1]
-        child_id = fake_context.processes[0].args[0]
 
-        messages.put(ChildMessage(child_id, "running"))
-        _wait_for(lambda: pool.ready_count == 1)
-
-        # "busy" opens a segment.
-        messages.put(ChildMessage(child_id, "busy"))
-        _wait_for(lambda: pool._children[child_id].timing.busy.since is not None)
-
-        # "idle" closes it and banks a positive amount of busy-time.
-        messages.put(ChildMessage(child_id, "idle"))
-        _wait_for(
-            lambda: pool._children[child_id].timing.busy.since is None
-            and pool._children[child_id].timing.busy.accumulated > 0
-        )
+        slots: set[int] = set()
+        for process in fake_context.processes:
+            child_id = process.args[0]
+            shm, slot = process.args[-2], process.args[-1]
+            slots.add(slot)
+
+            messages.put(ChildMessage(child_id, "running"))
+            # _wait_for blocks here, so the closure is resolved inside the
+            # iteration and does not need a default-argument capture.
+            _wait_for(lambda: pool._children[child_id].state == "running")
+            assert pool._children[child_id].timing.slot == slot
+            assert shm is pool._timing_shm
+
+        # Two children, two distinct slots.
+        assert len(slots) == 2
     finally:
         pool.shutdown()
 
 
-def test_tracked_child_records_real_widths_for_events_in_one_batch() -> None:
-    # The regression this change exists for: stamping at drain time collapsed
-    # every segment in a batch to zero width. Two 50ms tasks, 10ms apart:
-    child = _make_tracked_child("running", wait_since=100.00)
+def _writer_and_reader(slot: int = 0) -> tuple[ChildTimeWriter, ChildTimeAccounting]:
+    shm = get_context("fork").RawArray("d", SLOT_WIDTH * (slot + 1))
+    return ChildTimeWriter(shm, slot), ChildTimeAccounting(shm=shm, slot=slot)
+
+
+def test_child_timing_round_trips_through_shared_memory() -> None:
+    # The whole point of the slot: the child records the transition itself, so
+    # nothing has to survive a queue to be counted correctly.
+    writer, reader = _writer_and_reader()
+
+    writer.mark_running(0.0)
+    reader.mark_running(0.0)
+    writer.mark_busy(1.0)
+
+    assert reader.sample(2.0) == pytest.approx((1.0, 1.0))
+
+
+def test_child_timing_credits_a_long_task_to_every_interval_it_spans() -> None:
+    # A child only knows a segment's width when it ends. Folding the open
+    # segment forward at read time is what stops a 60s task reporting zero for
+    # 60 flushes and then 60s at once.
+    writer, reader = _writer_and_reader()
+
+    writer.mark_running(0.0)
+    reader.mark_running(0.0)
+    writer.mark_busy(0.0)
+
+    assert reader.sample(1.0) == pytest.approx((1.0, 0.0))
+    assert reader.sample(2.0) == pytest.approx((1.0, 0.0))
+
+    writer.mark_idle(2.5)
+    assert reader.sample(3.0) == pytest.approx((0.5, 0.5))
+
+
+def test_child_timing_busy_and_wait_partition_every_interval() -> None:
+    # A running child is always in exactly one state, so busy + wait over any
+    # sequence of samples has to equal the wall time. This is the invariant
+    # `occupancy.accounting_overflow` guards in production.
+    writer, reader = _writer_and_reader()
+    writer.mark_running(0.0)
+    reader.mark_running(0.0)
+
+    rng = random.Random(20260902)
+    now = 0.0
+    busy = False
+    total_busy = total_wait = 0.0
+
+    for i in range(500):
+        now += rng.uniform(0.001, 0.05)
+        busy = not busy
+        (writer.mark_busy if busy else writer.mark_idle)(now)
+
+        if i % 7 == 0:
+            b, w = reader.sample(now)
+            total_busy += b
+            total_wait += w
+
+    b, w = reader.sample(now)
+    total_busy += b
+    total_wait += w
 
-    child.timing.mark_busy(100.00)
-    child.timing.mark_idle(100.05)
-    child.timing.mark_busy(100.06)
-    child.timing.mark_idle(100.11)
+    assert total_busy + total_wait == pytest.approx(now)
 
-    # 0.05 + 0.05 of work, and the 0.01 gap between them counted as waiting.
-    assert child.timing.busy.accumulated == pytest.approx(0.10)
-    assert child.timing.wait.accumulated == pytest.approx(0.01)
 
+def test_child_timing_defers_rather_than_drops_a_torn_read() -> None:
+    # An odd version means the child was mid-publish. Returning zero without
+    # advancing the baseline means the next sample covers both intervals, so a
+    # torn read delays attribution instead of losing it.
+    writer, reader = _writer_and_reader()
+    writer.mark_running(0.0)
+    reader.mark_running(0.0)
+    writer.mark_busy(0.0)
 
-def test_tracked_child_busy_and_wait_partition_the_interval() -> None:
-    # A running child is always in exactly one state, so the drains must sum
-    # to the interval width.
-    child = _make_tracked_child("running", wait_since=10.0)
+    assert reader.sample(1.0) == pytest.approx((1.0, 0.0))
 
-    child.timing.mark_busy(10.4)
-    busy = child.timing.drain_busy(11.0)
-    wait = child.timing.drain_wait(11.0)
+    reader.shm[SLOT_VERSION] += 1.0  # type: ignore[index]
+    assert reader.sample(2.0) == pytest.approx((0.0, 0.0))
 
-    assert busy == pytest.approx(0.6)
-    assert wait == pytest.approx(0.4)
-    assert busy + wait == pytest.approx(1.0)
+    reader.shm[SLOT_VERSION] += 1.0  # type: ignore[index]
+    assert reader.sample(3.0) == pytest.approx((2.0, 0.0))
 
-    # Both open segments are carried forward rather than restarted at zero.
-    assert child.timing.busy.since == pytest.approx(11.0)
-    assert child.timing.wait.since is None
 
+def test_child_timing_stops_accruing_once_the_child_is_released() -> None:
+    # A released child keeps its wait segment open until it dies. Without this
+    # the segment folds forward forever and a recycling pool looks starved.
+    writer, reader = _writer_and_reader()
+    writer.mark_running(0.0)
+    reader.mark_running(0.0)
 
-def test_tracked_child_ignores_events_older_than_the_last_drain() -> None:
-    # drain_busy folds forward to the parent's clock, so a message stamped just
-    # before that and processed just after must not subtract credited time.
-    child = _make_tracked_child("running", busy_since=10.0)
+    assert reader.sample(0.5)[1] == pytest.approx(0.5)
 
-    child.timing.drain_busy(11.0)  # credits 1.0s, advances busy_since to 11.0
-    child.timing.mark_idle(10.95)  # stamped before the drain, delivered after
+    reader.mark_stopped()
+    assert reader.sample(20.0) == pytest.approx((0.0, 0.0))
 
-    assert child.timing.busy.accumulated == pytest.approx(0.0)
 
+def test_child_timing_ignores_a_child_with_no_slot() -> None:
+    # Degraded mode when the pool runs out of slots. It must report nothing
+    # rather than raise, since the parent also leaves it out of running_count.
+    shm = get_context("fork").RawArray("d", SLOT_WIDTH)
+    writer = ChildTimeWriter(shm, NO_SLOT)
+    reader = ChildTimeAccounting(shm=shm, slot=NO_SLOT)
 
-def test_tracked_child_stale_event_cannot_bill_an_interval_twice() -> None:
-    # The regression found in the sandbox sweep. The parent reads child events
-    # on a 100ms loop while the metrics thread drains on a 1s cadence, so a
-    # `busy` stamped at 10.2 can arrive after the 11.0 drain has already billed
-    # 10.2-11.0 as wait. Backdating busy_since to 10.2 then bills those same
-    # 0.8s again as busy, and the error grows with the event backlog: the sweep
-    # measured 580 busy-seconds per 1s flush across 24 children, 24x the
-    # physical ceiling, which the occupancy clamp turned into a healthy 1.0.
-    child = _make_tracked_child("running", wait_since=10.0)
+    writer.mark_running(0.0)
+    writer.mark_busy(1.0)
+    reader.mark_running(0.0)
 
-    assert child.timing.drain_wait(11.0) == pytest.approx(1.0)
-    assert child.timing.drain_busy(11.0) == pytest.approx(0.0)
+    assert reader.sample(10.0) == pytest.approx((0.0, 0.0))
+    assert shm[SLOT_SEGMENT_KIND] == KIND_NONE
 
-    child.timing.mark_busy(10.2)  # stamped before the drain, delivered after it
 
-    busy = child.timing.drain_busy(12.0)
-    wait = child.timing.drain_wait(12.0)
+def test_child_timing_excludes_time_banked_before_the_parent_saw_running() -> None:
+    # The child opens its wait clock at warmup, but the parent only counts it in
+    # running_count once the `running` message lands. Baselining at that moment
+    # keeps the numerator and the denominator starting together.
+    writer, reader = _writer_and_reader()
 
-    # The second interval is 1s wide and cannot yield more than 1s of credit.
-    assert busy == pytest.approx(1.0)
-    assert wait == pytest.approx(0.0)
+    writer.mark_running(0.0)
+    reader.mark_running(5.0)  # parent drained the message 5s later
 
+    assert reader.sample(6.0) == pytest.approx((0.0, 1.0))
 
-def test_tracked_child_accepts_events_predating_its_first_drain() -> None:
-    # The watermark starts at 0.0 so a child that has never been flushed still
-    # records real segment widths rather than collapsing them to the drain time.
-    child = _make_tracked_child("running", wait_since=10.0)
 
-    child.timing.mark_busy(10.4)
+def test_acquire_timing_slot_zeroes_a_recycled_slot() -> None:
+    # Slots outlive children. A replacement must not inherit its predecessor's
+    # totals, or its first sample reports the dead child's whole lifetime.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=1)
 
-    assert child.timing.drain_wait(11.0) == pytest.approx(0.4)
-    assert child.timing.drain_busy(11.0) == pytest.approx(0.6)
+    # Drain the free list so the release below is the only slot available. Reuse
+    # is FIFO, which deliberately leaves the longest possible gap between a slot
+    # being returned and handed out again.
+    slot = pool._acquire_timing_slot()
+    rest = [pool._acquire_timing_slot() for _ in range(slot_count(1) - 1)]
+    assert NO_SLOT not in rest
 
+    writer = ChildTimeWriter(pool._timing_shm, slot)
+    writer.mark_running(0.0)
+    writer.mark_busy(0.0)
+    writer.mark_idle(30.0)
 
-def test_tracked_child_stops_accruing_wait_once_released() -> None:
-    # A released child stops sending messages, so an open wait segment would
-    # fold forward forever and make a recycling pool look starved.
-    child = _make_tracked_child("running", wait_since=10.0)
+    pool._release_timing_slot(slot)
+    recycled = pool._acquire_timing_slot()
+    assert recycled == slot
 
-    child.timing.mark_stopped(10.5)
-    assert child.timing.drain_wait(20.0) == pytest.approx(0.5)
-    assert child.timing.drain_wait(30.0) == pytest.approx(0.0)
+    reader = ChildTimeAccounting(shm=pool._timing_shm, slot=recycled)
+    reader.mark_running(0.0)
+    assert reader.sample(1.0) == pytest.approx((0.0, 0.0))
 
 
-def test_tracked_child_pending_accrues_neither_busy_nor_wait() -> None:
-    # Warmup is not starvation: a child importing the app has no slot to fill.
-    child = _make_tracked_child("pending")
+def test_acquire_timing_slot_reports_exhaustion_instead_of_raising() -> None:
+    # Sizing should make this unreachable, so if it ever fires the metric is how
+    # we find out. The pool has to keep spawning either way.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=1)
+    pool._metrics = mock.Mock()
 
-    assert child.timing.drain_busy(11.0) == pytest.approx(0.0)
-    assert child.timing.drain_wait(11.0) == pytest.approx(0.0)
+    taken = [pool._acquire_timing_slot() for _ in range(slot_count(1))]
+    assert NO_SLOT not in taken
 
-    child.timing.mark_running(11.0)
-    assert child.timing.drain_wait(12.0) == pytest.approx(1.0)
+    assert pool._acquire_timing_slot() == NO_SLOT
+    assert len(_incr_calls(pool._metrics, "taskworker.worker.child.timing_slot_exhausted")) == 1
 
 
 def test_emit_periodic_metrics_emits_busy_and_wait_seconds() -> None:
@@ -1618,7 +1772,10 @@ def test_emit_periodic_metrics_emits_counters_during_warmup() -> None:
     assert len(_distribution_calls(pool._metrics, "taskworker.worker.child_wait_seconds")) == 1
 
 
-def test_spawn_children_uses_the_child_timestamp_not_the_drain_time() -> None:
+def test_spawn_children_reads_transitions_the_child_wrote() -> None:
+    # End to end through the real handoff: the child publishes into the slot
+    # it was given, and the parent's accountant reports that split without a
+    # single message crossing the queue.
     fake_context = _FakeContext()
     pool = _make_fake_context_pool(fake_context, concurrency=1)
 
@@ -1626,49 +1783,24 @@ def test_spawn_children_uses_the_child_timestamp_not_the_drain_time() -> None:
     try:
         _wait_for(lambda: len(fake_context.processes) == 1)
         messages = fake_context.queues[-1]
-        child_id = fake_context.processes[0].args[0]
+        process = fake_context.processes[0]
+        child_id = process.args[0]
+        writer = ChildTimeWriter(process.args[-2], process.args[-1])
 
+        writer.mark_running(0.0)
         messages.put(ChildMessage(child_id, "running"))
         _wait_for(lambda: pool.ready_count == 1)
 
-        stamped_at = time.monotonic() - 5.0
-        messages.put(ChildMessage(child_id, "busy", timestamp=stamped_at))
-        _wait_for(lambda: pool._children[child_id].timing.busy.since is not None)
-
-        # The drain lands up to 100ms later on another thread; the segment has
-        # to start when the child said it did.
-        assert pool._children[child_id].timing.busy.since == pytest.approx(stamped_at)
-    finally:
-        pool.shutdown()
-
-
-def test_spawn_children_tracks_wait_between_tasks() -> None:
-    fake_context = _FakeContext()
-    pool = _make_fake_context_pool(fake_context, concurrency=1)
-
-    pool.start_spawn_children_thread()
-    try:
-        _wait_for(lambda: len(fake_context.processes) == 1)
-        messages = fake_context.queues[-1]
-        child_id = fake_context.processes[0].args[0]
-
-        base = time.monotonic() - 10.0
-
-        # Reporting in opens a wait segment: available, blocked in get().
-        messages.put(ChildMessage(child_id, "running", timestamp=base))
-        _wait_for(lambda: pool._children[child_id].timing.wait.since == pytest.approx(base))
+        child = pool._children[child_id]
+        # Rebaseline onto the child's clock; the parent normally does this the
+        # moment it drains `running`, against its own monotonic reading.
+        child.timing.mark_running(0.0)
 
-        # 2s of waiting, then 1s of work, then waiting again.
-        messages.put(ChildMessage(child_id, "busy", timestamp=base + 2.0))
-        messages.put(ChildMessage(child_id, "idle", timestamp=base + 3.0))
-        # `wait_since` is already set by "running" above, so wait on banked busy.
-        _wait_for(lambda: pool._children[child_id].timing.busy.accumulated > 0)
+        # 2s waiting, 1s of work, then waiting again.
+        writer.mark_busy(2.0)
+        writer.mark_idle(3.0)
 
-        child = pool._children[child_id]
-        assert child.timing.wait.accumulated == pytest.approx(2.0)
-        assert child.timing.busy.accumulated == pytest.approx(1.0)
-        assert child.timing.busy.since is None
-        assert child.timing.wait.since == pytest.approx(base + 3.0)
+        assert child.timing.sample(4.0) == pytest.approx((1.0, 3.0))
     finally:
         pool.shutdown()
 
@@ -1698,7 +1830,7 @@ def test_spawn_children_releases_draining_child_above_min_concurrency() -> None:
         messages = fake_context.queues[-1]
         first_process = fake_context.processes[0]
         first_child_id = first_process.args[0]
-        first_release = first_process.args[-1]
+        first_release = first_process.args[-3]
 
         messages.put(ChildMessage(first_child_id, "running"))
         second_process = fake_context.processes[1]
@@ -1724,7 +1856,7 @@ def test_spawn_children_defers_draining_child_at_min_concurrency() -> None:
         messages = fake_context.queues[-1]
         first_process = fake_context.processes[0]
         first_child_id = first_process.args[0]
-        first_release = first_process.args[-1]
+        first_release = first_process.args[-3]
 
         second_process = fake_context.processes[1]
         second_child_id = second_process.args[0]
@@ -1881,6 +2013,7 @@ def test_child_process_emits_running_message() -> None:
     ctx = get_context("fork")
     child_id = uuid4()
     messages = ctx.Queue()
+    timing_shm = ctx.RawArray("d", SLOT_WIDTH)
     parent_release = ctx.Event()
     parent_release.set()
 
@@ -1898,6 +2031,8 @@ def test_child_process_emits_running_message() -> None:
         future_checking_frequency=0.1,
         messages=messages,
         parent_release=parent_release,
+        timing_shm=timing_shm,
+        timing_slot=0,
     )
 
     # The child signals readiness once warmup is done, before consuming
@@ -1915,6 +2050,7 @@ def test_child_process_emits_exiting_once_and_continues_until_release(
     todo = ctx.Queue()
     processed = ctx.Queue()
     messages = ctx.Queue()
+    timing_shm = ctx.RawArray("d", SLOT_WIDTH)
     parent_release = ctx.Event()
 
     todo.put(SIMPLE_TASK)
@@ -1933,25 +2069,20 @@ def test_child_process_emits_exiting_once_and_continues_until_release(
             0.1,
             messages,
             parent_release,
+            timing_shm,
+            0,
         ),
     )
     process.start()
     try:
-        running_message = messages.get(timeout=5)
-        busy_message = messages.get(timeout=5)
-        idle_message = messages.get(timeout=5)
-        exiting_message = messages.get(timeout=5)
-
-        assert running_message == ChildMessage(child_id, "running")
-        assert busy_message == ChildMessage(child_id, "busy")
-        assert idle_message == ChildMessage(child_id, "idle")
-        assert exiting_message == ChildMessage(child_id, "exiting")
+        # Only lifecycle events cross the queue now, two per child rather than
+        # two per task. That reduction is the whole point of the slot.
+        assert messages.get(timeout=5) == ChildMessage(child_id, "running")
+        assert messages.get(timeout=5) == ChildMessage(child_id, "exiting")
         assert processed.get(timeout=5).task_id == SIMPLE_TASK.activation.id
 
         todo.put(SIMPLE_TASK)
         assert processed.get(timeout=5).task_id == SIMPLE_TASK.activation.id
-        assert messages.get(timeout=5) == ChildMessage(child_id, "busy")
-        assert messages.get(timeout=5) == ChildMessage(child_id, "idle")
 
         time.sleep(0.2)
         assert process.is_alive()
@@ -1968,13 +2099,14 @@ def test_child_process_emits_exiting_once_and_continues_until_release(
     assert mock_capture_checkin.call_count == 0
 
 
-def test_child_process_emits_busy_and_idle_messages() -> None:
+def test_child_process_records_busy_and_idle_in_its_slot() -> None:
     todo: queue.Queue[InflightTaskActivation] = queue.Queue()
     processed: queue.Queue[ProcessingResult] = queue.Queue()
     shutdown = Event()
     ctx = get_context("fork")
     child_id = uuid4()
     messages = ctx.Queue()
+    timing_shm = ctx.RawArray("d", SLOT_WIDTH)
     parent_release = ctx.Event()
     parent_release.set()
 
@@ -1992,13 +2124,20 @@ def test_child_process_emits_busy_and_idle_messages() -> None:
         future_checking_frequency=0.1,
         messages=messages,
         parent_release=parent_release,
+        timing_shm=timing_shm,
+        timing_slot=0,
     )
 
     assert messages.get(timeout=1) == ChildMessage(child_id, "running")
-    assert messages.get(timeout=1) == ChildMessage(child_id, "busy")
-    assert messages.get(timeout=1) == ChildMessage(child_id, "idle")
     assert processed.get(timeout=1).task_id == SIMPLE_TASK.activation.id
 
+    # One task ran to completion, so the child closed a busy segment into its
+    # slot and reopened the wait clock behind it.
+    assert timing_shm[SLOT_BUSY_TOTAL] > 0.0
+    assert timing_shm[SLOT_SEGMENT_KIND] == KIND_WAIT
+    assert timing_shm[SLOT_VERSION] % 2 == 0
+    assert timing_shm[SLOT_SEGMENT_START] > 0.0
+
 
 def test_child_process_remove_start_time_kwargs() -> None:
     activation = InflightTaskActivation(

From ce505e030e916eca4ea3c571198d9b9839f222c8 Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Wed, 2 Sep 2026 16:06:32 -0400
Subject: [PATCH 7/9] Emit queue_wait, and fix the timestamp it is built on

Occupancy cannot separate a pool whose children are starved from one with
no work to do. Both leave children idle, and they need opposite scaling
decisions. The discriminator is whether work exists, which children cannot
see because they only ever see work they were handed.

execution_latency already carries that information but cannot be alerted on
with a single threshold, because it is queue_wait + execution_duration and
the second term is exactly what differs per pool: a pool running 4s tasks
would trip a 2s threshold while perfectly healthy.

queue_wait is the term that does not scale with task duration. Measured on
process-segments-push over 7 days, execution_latency p95 holds a flat floor
of 1.008-1.11s while execution_duration swings 3x, so the wait is pipeline
overhead rather than task cost and one threshold is meaningful across pools.
Healthy reads ~1s; a starved sandbox pod reads 330s.

Also fixes the timestamp both metrics are derived from. ToDatetime() returns
a naive datetime holding UTC and .timestamp() then reads it as local time,
so task_added_time was wrong by the host's UTC offset. Containers run UTC so
this was latent in production, but it silently skewed every latency reading
off-cluster, and it is what surfaced when the new test asserted a known wait.
seconds+nanos is exact and timezone-free.

Datadog only. queue_wait is computed per task in the child, and the
Prometheus registry lives in the parent process, so exposing it for scraping
would need the same cross-process plumbing this branch added for busy/wait.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
---
 .../taskbroker_client/worker/workerchild.py   | 35 ++++++++-
 clients/python/tests/worker/test_worker.py    | 77 ++++++++++++++++++-
 2 files changed, 109 insertions(+), 3 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/workerchild.py b/clients/python/src/taskbroker_client/worker/workerchild.py
index 20fadf4a..ee70d3aa 100644
--- a/clients/python/src/taskbroker_client/worker/workerchild.py
+++ b/clients/python/src/taskbroker_client/worker/workerchild.py
@@ -687,7 +687,9 @@ def _execute_activation(
                 transaction.set_data("taskworker-task.args", args)
                 transaction.set_data("taskworker-task.kwargs", kwargs)
 
-            task_added_time = activation.received_at.ToDatetime().timestamp()
+            # See the note in record_task_execution: ToDatetime().timestamp()
+            # misreads a naive UTC datetime as local time.
+            task_added_time = activation.received_at.seconds + activation.received_at.nanos / 1e9
             # latency attribute needs to be in milliseconds
             latency = (time.time() - task_added_time) * 1000
 
@@ -739,9 +741,28 @@ def record_task_execution(
         taskbroker_host: str,
         futures_enqueued_time: float | None = None,
     ) -> None:
-        task_added_time = activation.received_at.ToDatetime().timestamp()
+        # seconds+nanos rather than ToDatetime().timestamp(): ToDatetime()
+        # returns a NAIVE datetime holding UTC, and .timestamp() then reads it
+        # as local time, so the value is wrong by the host's UTC offset
+        # anywhere TZ is not UTC. Containers run UTC so this was latent, but it
+        # silently skewed every latency reading off-cluster.
+        task_added_time = activation.received_at.seconds + activation.received_at.nanos / 1e9
         execution_duration = completion_time - start_time
         execution_latency = completion_time - task_added_time
+        # `execution_latency` minus the part that is the task's own cost, i.e.
+        # how long the activation sat between the broker receiving it and a
+        # child picking it up.
+        #
+        # This is the term that does NOT scale with task duration, which is
+        # what makes a single threshold meaningful across pools running very
+        # different work: a backed-up 4ms pool and a backed-up 4s pool read the
+        # same wait, where total latency would read 4s apart while both are
+        # healthy.
+        #
+        # Clamped because `received_at` is stamped on the broker and
+        # `start_time` here, so clock skew between pods can otherwise emit a
+        # negative sample and distort the percentiles this is read on.
+        queue_wait = max(0.0, start_time - task_added_time)
         futures_duration = time.time() - futures_enqueued_time if futures_enqueued_time else 0
 
         logger.debug(
@@ -783,6 +804,16 @@ def record_task_execution(
                 "taskbroker_host": taskbroker_host,
             },
         )
+        metrics.distribution(
+            "taskworker.worker.queue_wait",
+            queue_wait,
+            tags={
+                "namespace": activation.namespace,
+                "taskname": activation.taskname,
+                "processing_pool": processing_pool_name,
+                "taskbroker_host": taskbroker_host,
+            },
+        )
         if futures_duration != 0:
             metrics.distribution(
                 "taskworker.worker.future_completion_duration",
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 7b06155f..f3044827 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -8,7 +8,7 @@
 import time
 from collections.abc import Iterator, MutableMapping
 from concurrent.futures import Future
-from datetime import datetime
+from datetime import datetime, timezone
 from multiprocessing import Event, get_context
 from multiprocessing.synchronize import Event as MultiprocessingEvent
 from pathlib import Path
@@ -2139,6 +2139,81 @@ def test_child_process_records_busy_and_idle_in_its_slot() -> None:
     assert timing_shm[SLOT_SEGMENT_START] > 0.0
 
 
+def _run_one_task_capturing_metrics(received_at_offset: float) -> mock.Mock:
+    """Run a single task through a child, with `received_at` set relative to now.
+
+    Returns the mocked metrics backend so callers can assert on what was emitted.
+    """
+    from examples.app import app as example_app
+
+    activation = TaskActivation(
+        id="queue-wait",
+        taskname="examples.simple_task",
+        namespace="examples",
+        parameters_bytes=msgpack.packb({"args": [], "kwargs": {}}, use_bin_type=True),
+        processing_deadline_duration=2,
+    )
+    activation.received_at.FromDatetime(
+        datetime.fromtimestamp(time.time() + received_at_offset, tz=timezone.utc)
+    )
+
+    todo: queue.Queue[InflightTaskActivation] = queue.Queue()
+    processed: queue.Queue[ProcessingResult] = queue.Queue()
+    todo.put(
+        InflightTaskActivation(host="localhost:50051", receive_timestamp=0, activation=activation)
+    )
+
+    # MagicMock, not Mock: the child uses metrics.timer() and
+    # metrics.track_memory_usage() as context managers.
+    metrics = mock.MagicMock()
+    with mock.patch.object(example_app, "metrics", metrics):
+        child_process(
+            "examples.app:app",
+            todo,
+            processed,
+            Event(),
+            1,
+            "test",
+            "fork",
+            False,
+            0.1,
+        )
+
+    assert processed.get(timeout=1).task_id == "queue-wait"
+    return metrics
+
+
+def test_child_process_emits_queue_wait_excluding_execution_time() -> None:
+    # queue_wait is execution_latency minus the task's own cost. That is the term
+    # that does not scale with task duration, which is what lets one alert
+    # threshold cover pools running very different work.
+    metrics = _run_one_task_capturing_metrics(received_at_offset=-2.0)
+
+    wait = _distribution_calls(metrics, "taskworker.worker.queue_wait")
+    latency = _distribution_calls(metrics, "taskworker.worker.execution_latency")
+    duration = _distribution_calls(metrics, "taskworker.worker.execution_duration")
+    assert len(wait) == 1 and len(latency) == 1 and len(duration) == 1
+
+    # The activation was stamped 2s ago and picked up immediately.
+    assert wait[0].args[1] == pytest.approx(2.0, abs=0.5)
+    # And it partitions the end-to-end latency with the execution itself.
+    assert wait[0].args[1] + duration[0].args[1] == pytest.approx(latency[0].args[1], abs=0.01)
+
+    assert wait[0].kwargs["tags"]["processing_pool"] == "test"
+    assert wait[0].kwargs["tags"]["taskname"] == "examples.simple_task"
+
+
+def test_child_process_queue_wait_clamps_negative_clock_skew() -> None:
+    # `received_at` is stamped on the broker and the start time here, so an
+    # NTP-skewed pod can make the difference negative. A negative sample would
+    # distort the percentiles this metric is read on.
+    metrics = _run_one_task_capturing_metrics(received_at_offset=+5.0)
+
+    wait = _distribution_calls(metrics, "taskworker.worker.queue_wait")
+    assert len(wait) == 1
+    assert wait[0].args[1] == 0.0
+
+
 def test_child_process_remove_start_time_kwargs() -> None:
     activation = InflightTaskActivation(
         host="localhost:50051",

From eb8c97587263020097765c5cd9108056ed0c344e Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Wed, 2 Sep 2026 16:14:28 -0400
Subject: [PATCH 8/9] Trim comments to one line

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
---
 .../taskbroker_client/worker/childtiming.py   | 70 +++++---------
 .../src/taskbroker_client/worker/worker.py    | 65 +++----------
 .../taskbroker_client/worker/workerchild.py   | 31 +-----
 clients/python/tests/worker/test_worker.py    | 94 ++++++-------------
 4 files changed, 67 insertions(+), 193 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/childtiming.py b/clients/python/src/taskbroker_client/worker/childtiming.py
index 34d9a50d..3f6501d0 100644
--- a/clients/python/src/taskbroker_client/worker/childtiming.py
+++ b/clients/python/src/taskbroker_client/worker/childtiming.py
@@ -1,30 +1,20 @@
 """Shared-memory busy/wait accounting for worker children.
 
-Once a second the parent needs to know how many seconds each child spent
-executing versus waiting for work. To accomplish that each child owns a slot
-in a ``RawArray`` of doubles and writes its own cumulative totals there. The
-parent reads and diffs the slots at flush time.
+Children write their own cumulative totals into a slot; the parent diffs them at
+flush. Costs O(children) per second rather than O(tasks) per second, and there is
+no queue to fall behind.
 
 Slot layout, five doubles per child::
 
     0  version         seqlock; odd means a write is in progress
     1  busy_total      cumulative seconds closed into busy
     2  wait_total      cumulative seconds closed into wait
-    3  segment_start   time.monotonic() when the currently-open segment began
+    3  segment_start   time.monotonic() when the open segment began
     4  segment_kind    KIND_NONE, KIND_WAIT or KIND_BUSY
 
-Two properties carry the design.
-
-Every value is absolute and cumulative rather than a delta, which is what makes
-a torn read survivable: a bad sample is transient and the next one re-derives
-the truth from the slot, so error cannot accumulate.
-
-``KIND_NONE`` is zero, so a freshly zeroed slot reads as "this child has not
-accounted for anything yet" rather than as an open segment starting at time
-zero.
-
-``time.monotonic()`` is CLOCK_MONOTONIC, which is system-wide, so a child's
-timestamps are directly comparable in the parent.
+Values are absolute and cumulative, so a torn read costs one transient sample
+that the next flush re-derives. time.monotonic() is CLOCK_MONOTONIC, which is
+system-wide, so a child's timestamps are valid in the parent.
 """
 
 from __future__ import annotations
@@ -32,7 +22,6 @@
 import ctypes
 from dataclasses import dataclass
 
-# Offsets within a slot, and the slot stride.
 SLOT_VERSION = 0
 SLOT_BUSY_TOTAL = 1
 SLOT_WAIT_TOTAL = 2
@@ -40,36 +29,28 @@
 SLOT_SEGMENT_KIND = 4
 SLOT_WIDTH = 5
 
-# Kind values. NONE must be 0.0 so that a zeroed slot means "nothing open".
+# NONE must be 0.0 so a zeroed slot reads as "nothing open".
 KIND_NONE = 0.0
 KIND_WAIT = 1.0
 KIND_BUSY = 2.0
 
-# Slot index handed to a child when the pool has none left. Every read and
-# write becomes a no-op and the parent leaves that child out of occupancy.
+# Handed to a child when the pool has no slot left. Reads and writes are no-ops.
 NO_SLOT = -1
 
-# A writer holds the seqlock for four stores, so a reader that loses three
-# races in a row is seeing something other than ordinary contention.
 SEQLOCK_READ_ATTEMPTS = 3
 
 
 def slot_count(concurrency: int) -> int:
-    """How many slots a pool of `concurrency` children needs.
-
-    Twice concurrency. `spawn_children_thread` counts only non-exiting children
-    when deciding how many to spawn, so a full generation of exiting-but-unreaped
-    children can briefly coexist with a full generation of replacements.
-    """
+    """Twice concurrency, so a generation of unreaped exiting children can
+    overlap a generation of replacements."""
     return max(1, concurrency * 2)
 
 
 class ChildTimeWriter:
     """Child-side writer for one slot.
 
-    The child is the only writer for its slot, so it keeps the authoritative
-    totals as plain Python floats and republishes the whole slot on each
-    transition. That avoids a read-modify-write against shared memory.
+    Sole writer, so it keeps authoritative totals as plain floats and
+    republishes the whole slot on each transition.
     """
 
     __slots__ = ("_shm", "_slot", "_base", "_busy_total", "_wait_total", "_start", "_kind")
@@ -91,7 +72,7 @@ def _publish(self) -> None:
         base = self._base
 
         version = shm[base + SLOT_VERSION]
-        # Odd version: a reader that sees this discards what it read.
+        # Odd: a reader that sees this discards what it read.
         shm[base + SLOT_VERSION] = version + 1.0
         shm[base + SLOT_BUSY_TOTAL] = self._busy_total
         shm[base + SLOT_WAIT_TOTAL] = self._wait_total
@@ -139,9 +120,8 @@ def close(self, now: float) -> None:
 class ChildTimeAccounting:
     """Parent-side reader for one child's slot.
 
-    Holds the previous absolute reading and returns deltas. A child sitting in a
-    long task therefore contributes to every interval it spans, instead of
-    dumping its whole duration into the interval it happens to finish in.
+    Holds the previous absolute reading and returns deltas, so a child in a long
+    task contributes to every interval it spans.
     """
 
     shm: ctypes.Array[ctypes.c_double] | None
@@ -153,15 +133,12 @@ class ChildTimeAccounting:
     def mark_running(self, now: float) -> None:
         """Start counting this child, baselining against the slot as it stands.
 
-        Baselining rather than zeroing means whatever the child banked between
-        spawning and the parent seeing its `running` message is not credited
-        retroactively. The child is excluded from `running_count` over that same
-        window, so the numerator and the denominator start together.
+        Baselining rather than zeroing drops whatever the child banked before the
+        parent saw its `running` message, which is the same window over which it
+        is absent from `running_count`.
         """
         reading = self._read(now)
         if reading is None:
-            # Slots are zeroed at allocation, so a failed first read costs at
-            # most the few microseconds since the child came up.
             self._prev_busy = 0.0
             self._prev_wait = 0.0
         else:
@@ -170,8 +147,7 @@ def mark_running(self, now: float) -> None:
         self._accounted = True
 
     def mark_stopped(self) -> None:
-        """Stop counting this child, so an exiting child's tail does not land on
-        the live pool's occupancy."""
+        """Stop counting, so an exiting child's tail misses the live pool."""
         self._accounted = False
 
     def sample(self, now: float) -> tuple[float, float]:
@@ -181,8 +157,7 @@ def sample(self, now: float) -> tuple[float, float]:
 
         reading = self._read(now)
         if reading is None:
-            # Leave the baseline alone: the next sample then covers both
-            # intervals. Deferring the attribution beats dropping it.
+            # Baseline untouched, so the next sample covers both intervals.
             return (0.0, 0.0)
 
         busy_now, wait_now = reading
@@ -195,8 +170,7 @@ def sample(self, now: float) -> tuple[float, float]:
     def _read(self, now: float) -> tuple[float, float] | None:
         """Seqlock read of absolute busy/wait, including the segment still open.
 
-        None means the read could not be taken cleanly and the caller should
-        keep whatever baseline it already has.
+        None means the read could not be taken cleanly.
         """
         if self.slot == NO_SLOT or self.shm is None:
             return None
diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index a70d85b5..d2823d7d 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -139,8 +139,7 @@ def __init__(
             registry=self.registry,
         )
 
-        # Additive and unclamped, unlike the gauge above: the scaler sums across
-        # pods and divides once, and no interval clips at 1.0.
+        # Additive and unclamped: the scaler sums across pods and divides once.
         self.child_busy_seconds = prometheus_client.Counter(
             "taskworker_worker_child_busy_seconds",
             "Cumulative child-seconds spent executing tasks.",
@@ -148,8 +147,7 @@ def __init__(
             registry=self.registry,
         )
 
-        # What occupancy cannot express: slots that are free with nothing to do.
-        # Near zero under a backlog means saturated, so more pods help.
+        # What occupancy cannot express: free slots with nothing to do.
         self.child_wait_seconds = prometheus_client.Counter(
             "taskworker_worker_child_wait_seconds",
             "Cumulative child-seconds spent blocked waiting for a task to arrive.",
@@ -236,8 +234,7 @@ class TrackedChild:
     process: BaseProcess
     state: ChildState
     release: Event
-    # Bound to this child's shared-memory slot at spawn time, so there is no
-    # sensible default: an accountant with no slot silently measures nothing.
+    # No default: an accountant with no slot silently measures nothing.
     timing: ChildTimeAccounting
 
 
@@ -912,12 +909,7 @@ def __init__(
         self._children: Dict[UUID, TrackedChild] = {}
         self._exiting_children: Deque[UUID] = deque()
 
-        # Children write their own busy/wait totals here and the parent diffs
-        # them once a second. Sized for two generations because
-        # `spawn_children_thread` ignores exiting children when deciding how
-        # many to spawn, so a full set of unreaped children can briefly overlap
-        # a full set of replacements. Slots are handed out and returned under
-        # `_children_lock`.
+        # Two generations: unreaped exiting children overlap their replacements.
         self._timing_slots: int = slot_count(concurrency)
         self._timing_shm: ctypes.Array[ctypes.c_double] = self._mp_context.RawArray(
             "d", SLOT_WIDTH * self._timing_slots
@@ -1022,19 +1014,11 @@ def _emit_periodic_metrics(self) -> None:
             for child in self._children.values():
                 state_counts[child.state] += 1
 
-                # Running children only: occupancy divides by `running_count`,
-                # so folding a `pending` or `exiting` child into the numerator
-                # measures one population against another. Neither has time to
-                # lose here. A `pending` child is not being accounted yet, and
-                # `mark_stopped` deliberately stops accounting an `exiting`
-                # child so its tail does not count against the live pool.
+                # Running only: the numerator must match occupancy's divisor.
                 if child.state != "running":
                     continue
 
-                # A child with no slot reports nothing, so leaving it in the
-                # denominator would read as an idle child rather than as a
-                # missing measurement. `timing_slot_exhausted` is what
-                # surfaces it instead.
+                # A slotless child reports nothing; counting it would read as idle.
                 if child.timing.slot == NO_SLOT:
                     continue
 
@@ -1048,8 +1032,7 @@ def _emit_periodic_metrics(self) -> None:
         elapsed = now - self._last_occupancy_flush_at
         self._last_occupancy_flush_at = now
 
-        # Emitted during warmup too: zero is correct for a counter, unlike for
-        # the occupancy gauge below where it drags the fleet average down.
+        # Emitted during warmup too: zero is correct for a counter.
         self._metrics.distribution(
             "taskworker.worker.child_busy_seconds",
             busy_time,
@@ -1061,8 +1044,7 @@ def _emit_periodic_metrics(self) -> None:
             tags=tags,
         )
         if self._prom is not None:
-            # inc(0.0) registers the series on the first flush, so a new pod
-            # reads as idle rather than as missing.
+            # inc(0.0) registers the series, so a new pod reads idle not missing.
             self._prom.child_busy_seconds.labels(processing_pool=self._processing_pool_name).inc(
                 max(0.0, busy_time)
             )
@@ -1070,17 +1052,10 @@ def _emit_periodic_metrics(self) -> None:
                 max(0.0, wait_time)
             )
 
-        # Children the pool could not give a slot to are excluded on both
-        # sides, so occupancy stays a consistent ratio over the children that
-        # are actually accounted for. `state_counts` still reports every
-        # running child to the `children` gauge.
+        # Slotless children are out of both sides; the gauge still counts them.
         running_count = accounted_running
         if running_count > 0 and elapsed > 0:
-            # A child cannot be busy for longer than the interval, so this is a
-            # hard physical bound on both counters. Exceeding it means the
-            # accounting is double billing, and the clamp below would hide that
-            # behind a healthy-looking 1.0. Emit it so the metric cannot lie
-            # silently again.
+            # Physical bound. Exceeding it means the clamp below is hiding a bug.
             ceiling = elapsed * running_count
             if busy_time > ceiling or wait_time > ceiling:
                 self._metrics.incr(
@@ -1239,12 +1214,7 @@ def spawn_children_thread() -> None:
                     except queue.Empty:
                         break
 
-                # How stale the events we are about to apply are. The clamp in
-                # `TrackedChild._clamp` keeps busy + wait conserved when this
-                # loop falls behind, but it cannot recover *when* the work
-                # happened, so occupancy lags by roughly this age. Flat and
-                # sub-second is healthy; a rising line means this thread is not
-                # keeping up with the children and the signal is going stale.
+                # Lifecycle-queue lag. A rising line means this thread is behind.
                 if received:
                     drain_at = time.monotonic()
                     self._metrics.distribution(
@@ -1266,10 +1236,7 @@ def spawn_children_thread() -> None:
                         c.process.join(timeout=0)
                         self._children.pop(cid)
 
-                        # Reclaim here rather than on the `exiting` transition:
-                        # a released child can still publish once before it
-                        # breaks out of its loop, and handing that slot to a
-                        # replacement would mix two children's totals.
+                        # Not at `exiting`: a released child can still publish once.
                         if c.timing.slot != NO_SLOT:
                             self._free_timing_slots.append(c.timing.slot)
 
@@ -1300,10 +1267,7 @@ def spawn_children_thread() -> None:
 
                             continue
 
-                        # This child is now running. Baseline against the slot
-                        # as it stands rather than the child's timestamp: the
-                        # child only enters `running_count` here, so starting
-                        # the numerator here keeps the ratio consistent.
+                        # Baseline here, where it also enters `running_count`.
                         if message.event == "running":
                             child.state = "running"
                             child.timing.mark_running(time.monotonic())
@@ -1379,8 +1343,7 @@ def spawn_children_thread() -> None:
 
                             self._children[child_id] = child
                     except Exception as e:
-                        # The child never came up, so nothing will ever write
-                        # to its slot.
+                        # Never came up, so nothing will write to its slot.
                         self._release_timing_slot(timing_slot)
 
                         logger.exception(
diff --git a/clients/python/src/taskbroker_client/worker/workerchild.py b/clients/python/src/taskbroker_client/worker/workerchild.py
index ee70d3aa..3e71ef8a 100644
--- a/clients/python/src/taskbroker_client/worker/workerchild.py
+++ b/clients/python/src/taskbroker_client/worker/workerchild.py
@@ -172,8 +172,6 @@ def _log_task_retry_exhausted(
 class ChildMessage:
     child_id: UUID
     event: Literal["running", "exiting"]
-    # Stamped at the event, not when the parent drains it 100ms later.
-    # CLOCK_MONOTONIC is system-wide, so a child's stamp is valid in the parent.
     # compare=False: the timestamp is payload, not identity.
     timestamp: float = field(default_factory=time.monotonic, compare=False)
 
@@ -205,11 +203,7 @@ def child_process(
     app.load_modules()
     metrics = app.metrics
 
-    # Busy/wait accounting goes straight into shared memory rather than over
-    # `messages`. The parent's drain thread competes for CPU with the children
-    # it measures, so at two events per task it falls behind under saturation
-    # and occupancy goes stale. This costs the parent one read per child per
-    # second instead.
+    # Straight to shared memory: `messages` cannot keep up at two events per task.
     timing = ChildTimeWriter(timing_shm, timing_slot)
     # Signals when the parent worker pool terminates the child
     local_shutdown = threading.Event()
@@ -687,8 +681,7 @@ def _execute_activation(
                 transaction.set_data("taskworker-task.args", args)
                 transaction.set_data("taskworker-task.kwargs", kwargs)
 
-            # See the note in record_task_execution: ToDatetime().timestamp()
-            # misreads a naive UTC datetime as local time.
+            # ToDatetime().timestamp() misreads a naive UTC datetime as local.
             task_added_time = activation.received_at.seconds + activation.received_at.nanos / 1e9
             # latency attribute needs to be in milliseconds
             latency = (time.time() - task_added_time) * 1000
@@ -741,27 +734,11 @@ def record_task_execution(
         taskbroker_host: str,
         futures_enqueued_time: float | None = None,
     ) -> None:
-        # seconds+nanos rather than ToDatetime().timestamp(): ToDatetime()
-        # returns a NAIVE datetime holding UTC, and .timestamp() then reads it
-        # as local time, so the value is wrong by the host's UTC offset
-        # anywhere TZ is not UTC. Containers run UTC so this was latent, but it
-        # silently skewed every latency reading off-cluster.
+        # ToDatetime().timestamp() reads a naive UTC datetime as local time.
         task_added_time = activation.received_at.seconds + activation.received_at.nanos / 1e9
         execution_duration = completion_time - start_time
         execution_latency = completion_time - task_added_time
-        # `execution_latency` minus the part that is the task's own cost, i.e.
-        # how long the activation sat between the broker receiving it and a
-        # child picking it up.
-        #
-        # This is the term that does NOT scale with task duration, which is
-        # what makes a single threshold meaningful across pools running very
-        # different work: a backed-up 4ms pool and a backed-up 4s pool read the
-        # same wait, where total latency would read 4s apart while both are
-        # healthy.
-        #
-        # Clamped because `received_at` is stamped on the broker and
-        # `start_time` here, so clock skew between pods can otherwise emit a
-        # negative sample and distort the percentiles this is read on.
+        # Latency minus the task's own cost, so it does not scale with duration.
         queue_wait = max(0.0, start_time - task_added_time)
         futures_duration = time.time() - futures_enqueued_time if futures_enqueued_time else 0
 
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index f3044827..4c034bff 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -1297,8 +1297,7 @@ def ready_count() -> int:
     pool_shutdown.assert_called_once_with()
 
 
-# Slots for children built by `_make_tracked_child`. Independent of any pool:
-# the flush reads through `child.timing.shm`, not the pool's array.
+# Independent of any pool: the flush reads through `child.timing.shm`.
 _TEST_SLOTS = 512
 _TEST_TIMING_SHM = get_context("fork").RawArray("d", SLOT_WIDTH * _TEST_SLOTS)
 _TEST_SLOT_SEQ = itertools.count()
@@ -1325,8 +1324,7 @@ def _make_tracked_child(
         _TEST_TIMING_SHM[base + offset] = 0.0
 
     timing = ChildTimeAccounting(shm=_TEST_TIMING_SHM, slot=slot)
-    # Baseline against the zeroed slot, so everything seeded below lands in
-    # the first sample.
+    # Baseline against the zeroed slot, so the seeding below lands in sample 1.
     timing.mark_running(0.0)
 
     if busy_since is not None:
@@ -1409,8 +1407,7 @@ def test_emit_periodic_metrics_time_weights_busy_over_the_interval() -> None:
     assert len(occupancy_calls) == 1
     assert occupancy_calls[0].args[1] == pytest.approx(1.24 / 3)
 
-    # B's segment is still open, so the next interval picks up where this one
-    # stopped rather than re-reporting the 0.60 already credited.
+    # B's segment is still open, so the next interval resumes, not re-reports.
     assert pool._children[child_b].timing.sample(12.0) == pytest.approx((1.0, 0.0))
     for child in pool._children.values():
         if child.state == "running":
@@ -1441,10 +1438,7 @@ def test_emit_periodic_metrics_divides_by_running_children() -> None:
 
 
 def test_emit_periodic_metrics_clamps_occupancy_and_flags_the_overflow() -> None:
-    # A child cannot be busy for longer than the interval, so 1.5s of busy over
-    # a 1s interval is an accounting fault, not a busy pool. Occupancy still has
-    # to clamp for KEDA, but the fault must be visible: reading a healthy 1.0
-    # while the numerator is nonsense is how the double-billing bug hid.
+    # 1.5s of busy in a 1s interval is a fault; the clamp must not hide it.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
     pool._last_occupancy_flush_at = 10.0
@@ -1482,10 +1476,7 @@ def test_emit_periodic_metrics_does_not_flag_a_legitimately_full_pool() -> None:
 
 
 def test_emit_periodic_metrics_excludes_slotless_children_from_occupancy() -> None:
-    # A child the pool could not give a slot to reports nothing. Leaving it in
-    # the denominator would read as a genuinely idle child and halve occupancy,
-    # which is the sort of quiet undercount this whole change exists to remove.
-    # It still belongs in the `children` gauge: the pod really does have it.
+    # A slotless child in the denominator would read as idle and halve occupancy.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
     pool._last_occupancy_flush_at = 10.0
@@ -1515,9 +1506,7 @@ def test_emit_periodic_metrics_excludes_slotless_children_from_occupancy() -> No
 
 
 def test_emit_periodic_metrics_counters_exclude_non_running_children() -> None:
-    # occupancy divides by running_count, so the counters have to sum over the
-    # same population. An exiting child folded into the numerator inflates both
-    # the counters and the gauge against slots that are no longer taking work.
+    # The counters must sum over the same population occupancy divides by.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
     pool._last_occupancy_flush_at = 10.0
@@ -1538,8 +1527,7 @@ def test_emit_periodic_metrics_counters_exclude_non_running_children() -> None:
 
 
 def test_spawn_children_binds_each_child_to_its_own_timing_slot() -> None:
-    # The parent hands the slot to the child at spawn and reads the same slot
-    # at flush. If those ever disagree the pool measures nothing.
+    # If spawn and flush disagree on the slot, the pool measures nothing.
     fake_context = _FakeContext()
     pool = _make_fake_context_pool(fake_context, concurrency=2)
 
@@ -1555,8 +1543,7 @@ def test_spawn_children_binds_each_child_to_its_own_timing_slot() -> None:
             slots.add(slot)
 
             messages.put(ChildMessage(child_id, "running"))
-            # _wait_for blocks here, so the closure is resolved inside the
-            # iteration and does not need a default-argument capture.
+            # _wait_for blocks, so the closure resolves inside the iteration.
             _wait_for(lambda: pool._children[child_id].state == "running")
             assert pool._children[child_id].timing.slot == slot
             assert shm is pool._timing_shm
@@ -1573,8 +1560,7 @@ def _writer_and_reader(slot: int = 0) -> tuple[ChildTimeWriter, ChildTimeAccount
 
 
 def test_child_timing_round_trips_through_shared_memory() -> None:
-    # The whole point of the slot: the child records the transition itself, so
-    # nothing has to survive a queue to be counted correctly.
+    # The child records the transition itself; nothing crosses a queue.
     writer, reader = _writer_and_reader()
 
     writer.mark_running(0.0)
@@ -1585,9 +1571,7 @@ def test_child_timing_round_trips_through_shared_memory() -> None:
 
 
 def test_child_timing_credits_a_long_task_to_every_interval_it_spans() -> None:
-    # A child only knows a segment's width when it ends. Folding the open
-    # segment forward at read time is what stops a 60s task reporting zero for
-    # 60 flushes and then 60s at once.
+    # Without this a 60s task reports zero for 60 flushes, then 60s at once.
     writer, reader = _writer_and_reader()
 
     writer.mark_running(0.0)
@@ -1602,9 +1586,7 @@ def test_child_timing_credits_a_long_task_to_every_interval_it_spans() -> None:
 
 
 def test_child_timing_busy_and_wait_partition_every_interval() -> None:
-    # A running child is always in exactly one state, so busy + wait over any
-    # sequence of samples has to equal the wall time. This is the invariant
-    # `occupancy.accounting_overflow` guards in production.
+    # The invariant `occupancy.accounting_overflow` guards in production.
     writer, reader = _writer_and_reader()
     writer.mark_running(0.0)
     reader.mark_running(0.0)
@@ -1632,9 +1614,7 @@ def test_child_timing_busy_and_wait_partition_every_interval() -> None:
 
 
 def test_child_timing_defers_rather_than_drops_a_torn_read() -> None:
-    # An odd version means the child was mid-publish. Returning zero without
-    # advancing the baseline means the next sample covers both intervals, so a
-    # torn read delays attribution instead of losing it.
+    # Leaving the baseline alone delays attribution instead of losing it.
     writer, reader = _writer_and_reader()
     writer.mark_running(0.0)
     reader.mark_running(0.0)
@@ -1650,8 +1630,7 @@ def test_child_timing_defers_rather_than_drops_a_torn_read() -> None:
 
 
 def test_child_timing_stops_accruing_once_the_child_is_released() -> None:
-    # A released child keeps its wait segment open until it dies. Without this
-    # the segment folds forward forever and a recycling pool looks starved.
+    # Otherwise the segment folds forward forever and a recycling pool looks starved.
     writer, reader = _writer_and_reader()
     writer.mark_running(0.0)
     reader.mark_running(0.0)
@@ -1663,8 +1642,7 @@ def test_child_timing_stops_accruing_once_the_child_is_released() -> None:
 
 
 def test_child_timing_ignores_a_child_with_no_slot() -> None:
-    # Degraded mode when the pool runs out of slots. It must report nothing
-    # rather than raise, since the parent also leaves it out of running_count.
+    # Degraded mode: report nothing rather than raise.
     shm = get_context("fork").RawArray("d", SLOT_WIDTH)
     writer = ChildTimeWriter(shm, NO_SLOT)
     reader = ChildTimeAccounting(shm=shm, slot=NO_SLOT)
@@ -1678,9 +1656,7 @@ def test_child_timing_ignores_a_child_with_no_slot() -> None:
 
 
 def test_child_timing_excludes_time_banked_before_the_parent_saw_running() -> None:
-    # The child opens its wait clock at warmup, but the parent only counts it in
-    # running_count once the `running` message lands. Baselining at that moment
-    # keeps the numerator and the denominator starting together.
+    # Numerator and denominator must start together, at the `running` message.
     writer, reader = _writer_and_reader()
 
     writer.mark_running(0.0)
@@ -1690,13 +1666,10 @@ def test_child_timing_excludes_time_banked_before_the_parent_saw_running() -> No
 
 
 def test_acquire_timing_slot_zeroes_a_recycled_slot() -> None:
-    # Slots outlive children. A replacement must not inherit its predecessor's
-    # totals, or its first sample reports the dead child's whole lifetime.
+    # A replacement must not inherit its predecessor's totals.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=1)
 
-    # Drain the free list so the release below is the only slot available. Reuse
-    # is FIFO, which deliberately leaves the longest possible gap between a slot
-    # being returned and handed out again.
+    # Drain the free list: reuse is FIFO, so a release is not reused next.
     slot = pool._acquire_timing_slot()
     rest = [pool._acquire_timing_slot() for _ in range(slot_count(1) - 1)]
     assert NO_SLOT not in rest
@@ -1716,8 +1689,7 @@ def test_acquire_timing_slot_zeroes_a_recycled_slot() -> None:
 
 
 def test_acquire_timing_slot_reports_exhaustion_instead_of_raising() -> None:
-    # Sizing should make this unreachable, so if it ever fires the metric is how
-    # we find out. The pool has to keep spawning either way.
+    # Should be unreachable; the pool has to keep spawning either way.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=1)
     pool._metrics = mock.Mock()
 
@@ -1749,16 +1721,14 @@ def test_emit_periodic_metrics_emits_busy_and_wait_seconds() -> None:
     assert busy[0].args[1] == pytest.approx(1.75)
     assert wait[0].args[1] == pytest.approx(0.25)
 
-    # The scaler divides the pair, recovering occupancy without needing the
-    # flush interval or the running-child count.
+    # The scaler divides the pair, needing neither interval nor child count.
     assert busy[0].args[1] / (busy[0].args[1] + wait[0].args[1]) == pytest.approx(0.875)
     occupancy_calls = _gauge_calls(pool._metrics, "taskworker.worker.occupancy")
     assert occupancy_calls[0].args[1] == pytest.approx(1.75 / 2)
 
 
 def test_emit_periodic_metrics_emits_counters_during_warmup() -> None:
-    # Emitted with no running children, unlike occupancy: zero is correct for a
-    # counter and separates "idle" from "not reporting".
+    # Unlike occupancy: zero separates "idle" from "not reporting".
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
     pool._metrics = mock.Mock()
 
@@ -1773,9 +1743,7 @@ def test_emit_periodic_metrics_emits_counters_during_warmup() -> None:
 
 
 def test_spawn_children_reads_transitions_the_child_wrote() -> None:
-    # End to end through the real handoff: the child publishes into the slot
-    # it was given, and the parent's accountant reports that split without a
-    # single message crossing the queue.
+    # End to end through the real handoff, with no message crossing the queue.
     fake_context = _FakeContext()
     pool = _make_fake_context_pool(fake_context, concurrency=1)
 
@@ -1792,8 +1760,7 @@ def test_spawn_children_reads_transitions_the_child_wrote() -> None:
         _wait_for(lambda: pool.ready_count == 1)
 
         child = pool._children[child_id]
-        # Rebaseline onto the child's clock; the parent normally does this the
-        # moment it drains `running`, against its own monotonic reading.
+        # Rebaseline onto the child's clock; normally done when draining `running`.
         child.timing.mark_running(0.0)
 
         # 2s waiting, 1s of work, then waiting again.
@@ -2075,8 +2042,7 @@ def test_child_process_emits_exiting_once_and_continues_until_release(
     )
     process.start()
     try:
-        # Only lifecycle events cross the queue now, two per child rather than
-        # two per task. That reduction is the whole point of the slot.
+        # Lifecycle only now: two per child rather than two per task.
         assert messages.get(timeout=5) == ChildMessage(child_id, "running")
         assert messages.get(timeout=5) == ChildMessage(child_id, "exiting")
         assert processed.get(timeout=5).task_id == SIMPLE_TASK.activation.id
@@ -2131,8 +2097,7 @@ def test_child_process_records_busy_and_idle_in_its_slot() -> None:
     assert messages.get(timeout=1) == ChildMessage(child_id, "running")
     assert processed.get(timeout=1).task_id == SIMPLE_TASK.activation.id
 
-    # One task ran to completion, so the child closed a busy segment into its
-    # slot and reopened the wait clock behind it.
+    # One task completed, so a busy segment closed and the wait clock reopened.
     assert timing_shm[SLOT_BUSY_TOTAL] > 0.0
     assert timing_shm[SLOT_SEGMENT_KIND] == KIND_WAIT
     assert timing_shm[SLOT_VERSION] % 2 == 0
@@ -2163,8 +2128,7 @@ def _run_one_task_capturing_metrics(received_at_offset: float) -> mock.Mock:
         InflightTaskActivation(host="localhost:50051", receive_timestamp=0, activation=activation)
     )
 
-    # MagicMock, not Mock: the child uses metrics.timer() and
-    # metrics.track_memory_usage() as context managers.
+    # MagicMock: the child uses metrics.timer() as a context manager.
     metrics = mock.MagicMock()
     with mock.patch.object(example_app, "metrics", metrics):
         child_process(
@@ -2184,9 +2148,7 @@ def _run_one_task_capturing_metrics(received_at_offset: float) -> mock.Mock:
 
 
 def test_child_process_emits_queue_wait_excluding_execution_time() -> None:
-    # queue_wait is execution_latency minus the task's own cost. That is the term
-    # that does not scale with task duration, which is what lets one alert
-    # threshold cover pools running very different work.
+    # Latency minus the task's own cost, so one threshold covers every pool.
     metrics = _run_one_task_capturing_metrics(received_at_offset=-2.0)
 
     wait = _distribution_calls(metrics, "taskworker.worker.queue_wait")
@@ -2204,9 +2166,7 @@ def test_child_process_emits_queue_wait_excluding_execution_time() -> None:
 
 
 def test_child_process_queue_wait_clamps_negative_clock_skew() -> None:
-    # `received_at` is stamped on the broker and the start time here, so an
-    # NTP-skewed pod can make the difference negative. A negative sample would
-    # distort the percentiles this metric is read on.
+    # An NTP-skewed pod would otherwise emit a negative sample.
     metrics = _run_one_task_capturing_metrics(received_at_offset=+5.0)
 
     wait = _distribution_calls(metrics, "taskworker.worker.queue_wait")

From ccc6326bfdbf516cebabf431179ffe2530428b4b Mon Sep 17 00:00:00 2001
From: Enoch Tang <enoch.tang@sentry.io>
Date: Wed, 2 Sep 2026 16:40:28 -0400
Subject: [PATCH 9/9] Add observability for occupancy under-reporting

Sandbox cell 6 (C=32 with recycling every 150 tasks) showed busy + wait at
0.70 of elapsed * running_count for its first four minutes, converging to
0.98 after. execution_duration was flat throughout, so the workload did not
change and roughly 20% of executed time was going unaccounted. Occupancy
read 0.729 against a true 0.996.

accounting_overflow stayed silent through all of it, because it only tests
busy > ceiling. It is structurally blind to the under-count direction, which
is the exact failure this project started from.

Three additions, chosen to identify the cause rather than just alarm:

accounting_ratio is (busy + wait) / ceiling, the continuous form of what the
overflow guard tests as a threshold. eligible_ratio is the same numerator
over the time children were actually eligible to accrue in, which differs
for a child baselined part-way through an interval: the ceiling counts it
whole. If eligible_ratio reads ~1.0 while accounting_ratio reads low, the
denominator is at fault and no time is missing. If both read low, time is
genuinely lost and sample_outcome says where: not_accounted, read_failed or
clamped, the last meaning a cumulative total went backwards, which is a torn
read or a reused slot.

accounting_deficit fires below 0.9 and logs the decomposition, mirroring the
overflow guard so the metric can no longer under-report silently.

sample() now returns SampleResult rather than a tuple, carrying eligibility
and the reason alongside busy and wait.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
---
 .../taskbroker_client/worker/childtiming.py   |  39 ++++-
 .../src/taskbroker_client/worker/worker.py    |  54 ++++++-
 clients/python/tests/worker/test_worker.py    | 139 +++++++++++++++---
 3 files changed, 204 insertions(+), 28 deletions(-)

diff --git a/clients/python/src/taskbroker_client/worker/childtiming.py b/clients/python/src/taskbroker_client/worker/childtiming.py
index 3f6501d0..1bf26446 100644
--- a/clients/python/src/taskbroker_client/worker/childtiming.py
+++ b/clients/python/src/taskbroker_client/worker/childtiming.py
@@ -40,6 +40,21 @@
 SEQLOCK_READ_ATTEMPTS = 3
 
 
+@dataclass(frozen=True)
+class SampleResult:
+    """One child's contribution to a flush, plus why it may be short.
+
+    `eligible` is how much of the interval this child could have accrued in at
+    all. It differs from the interval width for a child baselined part-way
+    through, which the `elapsed * running_count` ceiling treats as whole.
+    """
+
+    busy: float = 0.0
+    wait: float = 0.0
+    eligible: float = 0.0
+    reason: str = "ok"
+
+
 def slot_count(concurrency: int) -> int:
     """Twice concurrency, so a generation of unreaped exiting children can
     overlap a generation of replacements."""
@@ -129,6 +144,9 @@ class ChildTimeAccounting:
     _prev_busy: float = 0.0
     _prev_wait: float = 0.0
     _accounted: bool = False
+    # When this child started being counted, so a flush can tell a short
+    # sample apart from a child that was only eligible for part of it.
+    _baselined_at: float = 0.0
 
     def mark_running(self, now: float) -> None:
         """Start counting this child, baselining against the slot as it stands.
@@ -145,27 +163,34 @@ def mark_running(self, now: float) -> None:
             self._prev_busy, self._prev_wait = reading
 
         self._accounted = True
+        self._baselined_at = now
 
     def mark_stopped(self) -> None:
         """Stop counting, so an exiting child's tail misses the live pool."""
         self._accounted = False
 
-    def sample(self, now: float) -> tuple[float, float]:
-        """Return (busy, wait) seconds accrued since the previous sample."""
+    def sample(self, now: float, interval_start: float = 0.0) -> SampleResult:
+        """Return this child's busy/wait since the previous sample."""
         if not self._accounted:
-            return (0.0, 0.0)
+            return SampleResult(reason="not_accounted")
+
+        eligible = max(0.0, now - max(interval_start, self._baselined_at))
 
         reading = self._read(now)
         if reading is None:
             # Baseline untouched, so the next sample covers both intervals.
-            return (0.0, 0.0)
+            return SampleResult(eligible=eligible, reason="read_failed")
 
         busy_now, wait_now = reading
-        busy = max(0.0, busy_now - self._prev_busy)
-        wait = max(0.0, wait_now - self._prev_wait)
+        raw_busy = busy_now - self._prev_busy
+        raw_wait = wait_now - self._prev_wait
+        # A total going backwards means a torn read or a reused slot, and the
+        # clamp below silently drops that time.
+        reason = "clamped" if raw_busy < 0.0 or raw_wait < 0.0 else "ok"
+
         self._prev_busy = busy_now
         self._prev_wait = wait_now
-        return (busy, wait)
+        return SampleResult(max(0.0, raw_busy), max(0.0, raw_wait), eligible, reason)
 
     def _read(self, now: float) -> tuple[float, float] | None:
         """Seqlock read of absolute busy/wait, including the segment still open.
diff --git a/clients/python/src/taskbroker_client/worker/worker.py b/clients/python/src/taskbroker_client/worker/worker.py
index d2823d7d..c2c1803b 100644
--- a/clients/python/src/taskbroker_client/worker/worker.py
+++ b/clients/python/src/taskbroker_client/worker/worker.py
@@ -1011,6 +1011,9 @@ def _emit_periodic_metrics(self) -> None:
             busy_time = 0.0
             wait_time = 0.0
             accounted_running = 0
+            eligible_time = 0.0
+            outcomes: dict[str, int] = {}
+            interval_start = self._last_occupancy_flush_at
             for child in self._children.values():
                 state_counts[child.state] += 1
 
@@ -1023,9 +1026,11 @@ def _emit_periodic_metrics(self) -> None:
                     continue
 
                 accounted_running += 1
-                busy, wait = child.timing.sample(now)
-                busy_time += busy
-                wait_time += wait
+                result = child.timing.sample(now, interval_start)
+                busy_time += result.busy
+                wait_time += result.wait
+                eligible_time += result.eligible
+                outcomes[result.reason] = outcomes.get(result.reason, 0) + 1
 
             exiting_children = len(self._exiting_children)
 
@@ -1074,6 +1079,49 @@ def _emit_periodic_metrics(self) -> None:
                     },
                 )
 
+            # How much of the ceiling the counters actually account for. The
+            # overflow guard above is one-sided; this is the other direction,
+            # where occupancy reads low because time went missing rather than
+            # because the pool was idle.
+            self._metrics.gauge(
+                "taskworker.worker.occupancy.accounting_ratio",
+                (busy_time + wait_time) / ceiling,
+                tags=tags,
+            )
+            # Same numerator against the time children were actually eligible
+            # for. A child baselined mid-interval counts whole in `ceiling` but
+            # only partly here, so if this reads ~1.0 while the ratio above
+            # reads low, the denominator is the fault, not the accounting.
+            if eligible_time > 0:
+                self._metrics.gauge(
+                    "taskworker.worker.occupancy.eligible_ratio",
+                    (busy_time + wait_time) / eligible_time,
+                    tags=tags,
+                )
+            for reason, count in outcomes.items():
+                self._metrics.incr(
+                    "taskworker.worker.occupancy.sample_outcome",
+                    count,
+                    tags={**tags, "reason": reason},
+                )
+            if busy_time + wait_time < ceiling * 0.9:
+                self._metrics.incr(
+                    "taskworker.worker.occupancy.accounting_deficit",
+                    tags=tags,
+                )
+                logger.warning(
+                    "taskworker.worker.occupancy.accounting_deficit",
+                    extra={
+                        "busy_time": busy_time,
+                        "wait_time": wait_time,
+                        "eligible_time": eligible_time,
+                        "running_count": running_count,
+                        "elapsed": elapsed,
+                        "outcomes": outcomes,
+                        "processing_pool": self._processing_pool_name,
+                    },
+                )
+
             occupancy = busy_time / ceiling
             occupancy = min(occupancy, 1.0)
             self._metrics.gauge(
diff --git a/clients/python/tests/worker/test_worker.py b/clients/python/tests/worker/test_worker.py
index 4c034bff..33a79c88 100644
--- a/clients/python/tests/worker/test_worker.py
+++ b/clients/python/tests/worker/test_worker.py
@@ -1310,6 +1310,7 @@ def _make_tracked_child(
     busy_accumulated: float = 0.0,
     wait_since: float | None = None,
     wait_accumulated: float = 0.0,
+    baselined_at: float | None = None,
 ) -> TrackedChild:
     """Seed a child's slot so its next sample reports the given time.
 
@@ -1325,7 +1326,7 @@ def _make_tracked_child(
 
     timing = ChildTimeAccounting(shm=_TEST_TIMING_SHM, slot=slot)
     # Baseline against the zeroed slot, so the seeding below lands in sample 1.
-    timing.mark_running(0.0)
+    timing.mark_running(0.0 if baselined_at is None else baselined_at)
 
     if busy_since is not None:
         kind, start = KIND_BUSY, busy_since
@@ -1348,6 +1349,11 @@ def _make_tracked_child(
     )
 
 
+def _bw(result: Any) -> tuple[float, float]:
+    """The (busy, wait) pair from a SampleResult, dropping the diagnostics."""
+    return (result.busy, result.wait)
+
+
 def _distribution_calls(metrics: mock.Mock, name: str) -> list[Any]:
     return [c for c in metrics.distribution.call_args_list if c.args[0] == name]
 
@@ -1408,10 +1414,10 @@ def test_emit_periodic_metrics_time_weights_busy_over_the_interval() -> None:
     assert occupancy_calls[0].args[1] == pytest.approx(1.24 / 3)
 
     # B's segment is still open, so the next interval resumes, not re-reports.
-    assert pool._children[child_b].timing.sample(12.0) == pytest.approx((1.0, 0.0))
+    assert _bw(pool._children[child_b].timing.sample(12.0)) == pytest.approx((1.0, 0.0))
     for child in pool._children.values():
         if child.state == "running":
-            assert child.timing.sample(12.0)[0] == pytest.approx(0.0)
+            assert child.timing.sample(12.0).busy == pytest.approx(0.0)
     assert pool._last_occupancy_flush_at == pytest.approx(11.0)
 
 
@@ -1475,6 +1481,103 @@ def test_emit_periodic_metrics_does_not_flag_a_legitimately_full_pool() -> None:
     assert _incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_overflow") == []
 
 
+def test_emit_periodic_metrics_separates_a_short_sample_from_a_short_interval() -> None:
+    # The discriminator for the cell-6 deficit. A child baselined mid-interval can
+    # only accrue over part of it, but `elapsed * running_count` counts it whole,
+    # so occupancy reads low with no time actually missing. eligible_ratio near 1.0
+    # while accounting_ratio reads low means the denominator is at fault.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.5, baselined_at=10.5)
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    # 1.0 + 0.5 busy-seconds against a ceiling of 2.0.
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy.accounting_ratio")[0].args[
+        1
+    ] == pytest.approx(0.75)
+    # But only 1.5 child-seconds were ever available.
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy.eligible_ratio")[0].args[
+        1
+    ] == pytest.approx(1.0)
+    # Nothing went missing, so every sample is clean.
+    reasons = {
+        c.kwargs["tags"]["reason"]
+        for c in _incr_calls(pool._metrics, "taskworker.worker.occupancy.sample_outcome")
+    }
+    assert reasons == {"ok"}
+
+
+def test_emit_periodic_metrics_flags_a_deficit_and_names_the_reason() -> None:
+    # The mirror of accounting_overflow. Occupancy reading low because time went
+    # missing is the exact failure this project started from, and the overflow
+    # guard is blind to it.
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    stalled = _make_tracked_child("running", busy_since=10.0)
+    stalled.timing.mark_stopped()
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = stalled
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    assert len(_incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_deficit")) == 1
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy.accounting_ratio")[0].args[
+        1
+    ] == pytest.approx(0.5)
+    reasons = {
+        c.kwargs["tags"]["reason"]
+        for c in _incr_calls(pool._metrics, "taskworker.worker.occupancy.sample_outcome")
+    }
+    assert reasons == {"ok", "not_accounted"}
+
+
+def test_emit_periodic_metrics_does_not_flag_a_deficit_when_time_is_all_there() -> None:
+    pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
+    pool._metrics = mock.Mock()
+    pool._last_occupancy_flush_at = 10.0
+
+    with pool._children_lock:
+        pool._children[uuid4()] = _make_tracked_child("running", busy_since=10.0)
+        pool._children[uuid4()] = _make_tracked_child("running", wait_since=10.0)
+
+    with mock.patch("taskbroker_client.worker.worker.time.monotonic", return_value=11.0):
+        pool._emit_periodic_metrics()
+
+    assert _incr_calls(pool._metrics, "taskworker.worker.occupancy.accounting_deficit") == []
+    assert _gauge_calls(pool._metrics, "taskworker.worker.occupancy.accounting_ratio")[0].args[
+        1
+    ] == pytest.approx(1.0)
+
+
+def test_sample_reports_a_clamped_read_rather_than_hiding_it() -> None:
+    # A total going backwards means a torn read or a reused slot. The clamp keeps
+    # the number sane but drops real time, so the drop has to be visible.
+    writer, reader = _writer_and_reader()
+    writer.mark_running(0.0)
+    reader.mark_running(0.0)
+    writer.mark_busy(0.0)
+    assert reader.sample(1.0).reason == "ok"
+
+    # Rewind the slot underneath the reader, as slot reuse would.
+    reader.shm[SLOT_BUSY_TOTAL] = 0.0  # type: ignore[index]
+    reader.shm[SLOT_SEGMENT_START] = 2.0  # type: ignore[index]
+
+    result = reader.sample(2.0)
+    assert result.reason == "clamped"
+    assert result.busy == 0.0
+
+
 def test_emit_periodic_metrics_excludes_slotless_children_from_occupancy() -> None:
     # A slotless child in the denominator would read as idle and halve occupancy.
     pool = _make_result_thread_pool(_SendResultCapture(), concurrency=4)
@@ -1567,7 +1670,7 @@ def test_child_timing_round_trips_through_shared_memory() -> None:
     reader.mark_running(0.0)
     writer.mark_busy(1.0)
 
-    assert reader.sample(2.0) == pytest.approx((1.0, 1.0))
+    assert _bw(reader.sample(2.0)) == pytest.approx((1.0, 1.0))
 
 
 def test_child_timing_credits_a_long_task_to_every_interval_it_spans() -> None:
@@ -1578,11 +1681,11 @@ def test_child_timing_credits_a_long_task_to_every_interval_it_spans() -> None:
     reader.mark_running(0.0)
     writer.mark_busy(0.0)
 
-    assert reader.sample(1.0) == pytest.approx((1.0, 0.0))
-    assert reader.sample(2.0) == pytest.approx((1.0, 0.0))
+    assert _bw(reader.sample(1.0)) == pytest.approx((1.0, 0.0))
+    assert _bw(reader.sample(2.0)) == pytest.approx((1.0, 0.0))
 
     writer.mark_idle(2.5)
-    assert reader.sample(3.0) == pytest.approx((0.5, 0.5))
+    assert _bw(reader.sample(3.0)) == pytest.approx((0.5, 0.5))
 
 
 def test_child_timing_busy_and_wait_partition_every_interval() -> None:
@@ -1602,11 +1705,11 @@ def test_child_timing_busy_and_wait_partition_every_interval() -> None:
         (writer.mark_busy if busy else writer.mark_idle)(now)
 
         if i % 7 == 0:
-            b, w = reader.sample(now)
+            b, w = _bw(reader.sample(now))
             total_busy += b
             total_wait += w
 
-    b, w = reader.sample(now)
+    b, w = _bw(reader.sample(now))
     total_busy += b
     total_wait += w
 
@@ -1620,13 +1723,13 @@ def test_child_timing_defers_rather_than_drops_a_torn_read() -> None:
     reader.mark_running(0.0)
     writer.mark_busy(0.0)
 
-    assert reader.sample(1.0) == pytest.approx((1.0, 0.0))
+    assert _bw(reader.sample(1.0)) == pytest.approx((1.0, 0.0))
 
     reader.shm[SLOT_VERSION] += 1.0  # type: ignore[index]
-    assert reader.sample(2.0) == pytest.approx((0.0, 0.0))
+    assert _bw(reader.sample(2.0)) == pytest.approx((0.0, 0.0))
 
     reader.shm[SLOT_VERSION] += 1.0  # type: ignore[index]
-    assert reader.sample(3.0) == pytest.approx((2.0, 0.0))
+    assert _bw(reader.sample(3.0)) == pytest.approx((2.0, 0.0))
 
 
 def test_child_timing_stops_accruing_once_the_child_is_released() -> None:
@@ -1635,10 +1738,10 @@ def test_child_timing_stops_accruing_once_the_child_is_released() -> None:
     writer.mark_running(0.0)
     reader.mark_running(0.0)
 
-    assert reader.sample(0.5)[1] == pytest.approx(0.5)
+    assert reader.sample(0.5).wait == pytest.approx(0.5)
 
     reader.mark_stopped()
-    assert reader.sample(20.0) == pytest.approx((0.0, 0.0))
+    assert _bw(reader.sample(20.0)) == pytest.approx((0.0, 0.0))
 
 
 def test_child_timing_ignores_a_child_with_no_slot() -> None:
@@ -1651,7 +1754,7 @@ def test_child_timing_ignores_a_child_with_no_slot() -> None:
     writer.mark_busy(1.0)
     reader.mark_running(0.0)
 
-    assert reader.sample(10.0) == pytest.approx((0.0, 0.0))
+    assert _bw(reader.sample(10.0)) == pytest.approx((0.0, 0.0))
     assert shm[SLOT_SEGMENT_KIND] == KIND_NONE
 
 
@@ -1662,7 +1765,7 @@ def test_child_timing_excludes_time_banked_before_the_parent_saw_running() -> No
     writer.mark_running(0.0)
     reader.mark_running(5.0)  # parent drained the message 5s later
 
-    assert reader.sample(6.0) == pytest.approx((0.0, 1.0))
+    assert _bw(reader.sample(6.0)) == pytest.approx((0.0, 1.0))
 
 
 def test_acquire_timing_slot_zeroes_a_recycled_slot() -> None:
@@ -1685,7 +1788,7 @@ def test_acquire_timing_slot_zeroes_a_recycled_slot() -> None:
 
     reader = ChildTimeAccounting(shm=pool._timing_shm, slot=recycled)
     reader.mark_running(0.0)
-    assert reader.sample(1.0) == pytest.approx((0.0, 0.0))
+    assert _bw(reader.sample(1.0)) == pytest.approx((0.0, 0.0))
 
 
 def test_acquire_timing_slot_reports_exhaustion_instead_of_raising() -> None:
@@ -1767,7 +1870,7 @@ def test_spawn_children_reads_transitions_the_child_wrote() -> None:
         writer.mark_busy(2.0)
         writer.mark_idle(3.0)
 
-        assert child.timing.sample(4.0) == pytest.approx((1.0, 3.0))
+        assert _bw(child.timing.sample(4.0)) == pytest.approx((1.0, 3.0))
     finally:
         pool.shutdown()