Skip to content

detector_data leaks ~60 MB per cycle in uncollected reference cycles from sciline graph updates, OOM-killing the service #1264

Description

@SimonHeybrock

Summary

detector_data grows by roughly 50-65 MB per processing cycle and is eventually OOM-killed. On TBL, with the Timepix3 and ORCA detector views running, the service reached 29.9 GB resident on a 32 GB host and was killed 34 minutes after start.

The growth is entirely cyclic garbage: the live set stays constant. Every discarded object is reclaimable, but CPython's generation-2 collector never runs, because it is triggered by object counts and the wasted memory is a small number of very large arrays. Timepix3 makes it acute only because its arrays are the biggest (a 4096x4096 image is 134 MB); the mechanism applies to every instrument and every detector view.

This is not specific to saturation. In the minutes before the OOM the service was reporting batches=30, empty_batches=267-278 — i.e. not saturated — and still died four minutes later.

Evidence

Out of memory: Killed process ... (python) total-vm:34583736kB, anon-rss:31345108kB, ...
livedata-detector@tbl.service: Main process exited, code=killed, status=9/KILL
livedata-detector@tbl.service: Failed with result 'oom-kill'.
livedata-detector@tbl.service: Consumed 20min 9.441s CPU time.

errors=0 throughout; no exception, no traceback. Only detector_data died; monitor_data, data_reduction and timeseries were untouched.

Mechanism

Once per chunk, for every job:

  1. ess/reduce/streaming.py:505StreamProcessor.accumulate does self._process_chunk_workflow[key] = value, inserting the incoming data into the task graph as a parameter. Same pattern at :525 in finalize and :442/:449 in set_context. Reached from src/ess/livedata/workflows/stream_processor_workflow.py:222 and :225.
  2. sciline/data_graph.py:186DataGraph.__setitem__ forwards to self._cbgraph[key] = ....
  3. cyclebane/graph.py:537Graph.__setitem__ rebuilds the graph and assigns self.graph = graph, dropping the previous networkx.DiGraph.
  4. A networkx graph whose view attributes (edges, adj, degree, ...) have been materialised is self-referential: G.__dict__['edges'] = OutEdgeView(G), and the view stores self._graph = G. Such a graph is reclaimable only by the cyclic collector, and its node attribute dicts still transitively hold the previous cycle's arrays — measured payloads include a 134 MB DataArray {dim_0:4096, dim_1:4096}, a 134 MB DataArray {detector_number: 16777216} and a 67 MB Variable {4096,4096} int32.
  5. Those graphs are live when generations 0 and 1 run, so they are promoted to generation 2 and only then become garbage. Over a 419-cycle run: 445 gen-0 collections, 40 gen-1, and 3 gen-2 — all three during startup, none in steady state. Nothing ever frees them.

Crucially, __setitem__ discards about 5.8 self-referential graphs per call, not one: _remove_ancestors, relabel_nodes and compose each build intermediates, and the validation loop's graph.pred[node] / graph.nodes[node] accesses materialise views on those intermediates.

There is currently no gc handling anywhere in src/ess/livedata/.

Reproduction

Everything below was measured against the versions pinned in requirements/base.txt: sciline==25.11.1, cyclebane==24.10.0.

python -m venv pinvenv
./pinvenv/bin/pip install "sciline==25.11.1" "cyclebane==24.10.0" numpy

Minimal — no ESSlivedata code at all

import gc, sys
from typing import NewType
import numpy as np
import sciline

Chunk = NewType('Chunk', np.ndarray)
Result = NewType('Result', float)


def total(chunk: Chunk) -> Result:
    return Result(float(chunk[0]))


def rss_mb() -> float:
    with open('/proc/self/statm') as f:
        return int(f.read().split()[1]) * 4096 / 1e6


do_collect = 'collect' in sys.argv
pipeline = sciline.Pipeline([total])
for i in range(60):
    # 4096x4096 float32 = 67 MB, the size of one Timepix3 detector image.
    pipeline[Chunk] = np.full(4096 * 4096, float(i), dtype=np.float32)
    pipeline.compute(Result)
    if do_collect:
        gc.collect()
    if i % 10 == 0:
        print(f'{i:>5} {rss_mb():>9.1f}')
print(f'end {rss_mb():.1f} MB')
gc.collect()
print(f'after final gc.collect(): {rss_mb():.1f} MB')
$ ./pinvenv/bin/python minimal_leak.py
   50       663.1
  end 1393.0 MB
after final gc.collect(): 117.8 MB

$ ./pinvenv/bin/python minimal_leak.py collect
   50       126.1
  end 126.1 MB

Unbounded growth; one gc.collect() recovers all of it; collecting every iteration keeps it flat. With gc.disable() the same loop reaches 4078 MB.

Full service

A harness driving the real pipeline in-process — real routing adapter, OrchestratingProcessor with AdaptiveMessageBatcher, JobManager/Job/StreamProcessorWorkflow, real da00/x5f2 sink serializer with the bytes discarded, only the Kafka transport faked (real ev44 flatbuffers via FakeConsumer on the production topic/source, ~45 msgs/s, ~135k events/cycle, real 4096x4096 grid, real tbl_detector_timepix3 workflow with ROI and device outputs):

420 cycles RSS
no gc.collect() 1768 MB (c0) -> 5440 (c160) -> 9408 (c300) -> 9640 (c419); +65 MB/cycle, no plateau
gc.collect() each cycle 2018 (c20) -> 2163 (c259); slope -2.9 MB/cycle

Periodic gc.collect() + malloc_trim probes inside the leaking run show the live set is constant — 1689 MB at c30, 1897 MB at c419 — and each probe reclaimed exactly the accumulated garbage (7342 MB at c419).

I can attach this harness on request; it is ~400 lines and depends on repo internals.

Ruled out

  • glibc fragmentation. MALLOC_MMAP_THRESHOLD_/MALLOC_TRIM_THRESHOLD_=128K changed nothing (8.4 GB at cycle 140). A single gc.collect() took 8370 MB to 1337 MB. Allocation-size variation does cause real arena growth (+13.0 MB/update with fluctuating event counts vs +5.1 constant) but it plateaus around 3.1 GB.
  • scipp. group_event_data over the 16.7M-bin grid, sc.values, and bins.concat were each run 300 times on fixed-size inputs; all plateau, none leak.
  • librdkafka producer buffering. sink.py calls flush(timeout=3) after every batch and it never timed out.
  • ToNXevent_data peak-retaining buffers. Real (_ensure_capacity doubles and never shrinks; clear() and release_buffers() free nothing), but it needs growing batch sizes to fire and SimpleMessageBatcher windows by data time, so a backlog cannot inflate batches. It shows up as a decelerating creep in the live set (1.1 MB/cycle at c30-80 falling to 0.22 MB/cycle at c300-419) — two orders of magnitude below the primary leak. Worth its own issue.

Mitigation, and its cost

Measured in the minimal reproduction on the pinned versions:

RSS gc.collect() cost
per-cycle gc.collect() flat mean 9.94 ms, max 10.68 ms
gc.freeze() at startup + per-cycle gc.collect() flat mean 0.41 ms, max 0.48 ms

In the full service the same comparison was 84 ms without freeze and 0.6 ms mean / 2.1 ms max with it — the difference matters, because a Timepix3 view update already costs ~840 ms against a ~1 s batch cadence.

gc.freeze() after service construction moves everything alive at that point into the permanent generation, so the per-cycle collect only walks objects created since.

Caveats, if we ship this:

  • gc.freeze() permanently exempts everything alive at call time. Safe immediately after construction, but anything frozen that later becomes garbage leaks silently.
  • Full-collect cost scales with the number of tracked objects, so it will drift upward as jobs accumulate. It should be measured, not assumed.
  • It does not remove the CPU cost of building ~6 throwaway graphs per chunk.

This is a symptom fix. It makes the collector run often enough to reclaim garbage that should not be created. It should be labelled as such and not close this issue.

Potential root-cause fixes

In increasing order of depth and payoff.

Break the cycles in cyclebane. Have Graph.__setitem__ leave no self-referential graphs behind. Note that the obvious version of this does not work: patching __setitem__ to drop the cached view attributes from the graph it replaces has no effect (4078 MB both patched and unpatched, with the cyclic collector disabled), because the intermediates built inside the call are self-referential too. A correct fix has to deal with all of them, or avoid materialising views on graphs that are about to be discarded.

Stop rebuilding the graph per chunk. StreamProcessor.accumulate reassigning a graph parameter for every incoming chunk means a full graph rebuild per chunk, with 134 MB payloads living in graph node attribute dicts. A task graph is being used as a data container. If per-chunk data were passed as an argument rather than written into the graph structure, neither the cycles nor the count-based GC heuristic would matter. This is the fix that makes the problem go away permanently, and it is an ess.reduce/sciline design question rather than something we can do here.

Not fixable by us: CPython triggers generation-2 collection on object counts, not bytes, so a handful of 100 MB arrays trips nothing. This is the reason the other two layers become fatal rather than merely wasteful.

Related findings

Separate defects found while investigating; each probably warrants its own issue rather than being folded in here.

  • Preprocessing is not gated on active jobs. MessagePreprocessor.preprocess_messages (core/orchestrating_processor.py:122) runs for every stream that arrives regardless of whether any job consumes it, and _accumulators has no eviction path. Once Timepix3 has been seen, GroupByPixel.get() keeps grouping into 16.7M bins every batch forever — about 100 ms and 440 MB of transient allocation per batch, for nothing. Stopping a workflow does not stop paying for it.
  • queue.buffering.max.kbytes: 104857600 in config/defaults/kafka_dev.yaml and kafka_docker.yaml.jinja is in kilobytes, so it is 100 GB, not the 100 MB the adjacent comment claims. It sits directly under message.max.bytes, which is in bytes. At 100 GB the BufferError backpressure path in kafka/sink.py is unreachable — the host dies first. Should be 102400.
  • num_bins is bounded without reference to pixel count. parameter_models.py:87 allows le=10000. Timepix3 view memory scales at a measured 4.24 MB per TOA bin (two 512x512xN float64 histograms; theory says 4.19), so the maximum is roughly 42 GB for a single job, settable from the dashboard. The bound should be on pixels * bins, not bins alone.
  • Timepix3 view cost. ~840 ms per update against a ~1 s batch cadence, so one view consumes ~84% of the budget and two saturate the service (observed in production: batches 30 -> 21 per 30 s). Attribution per update: _concat_bins 432 ms, sc.values 210 ms, group_event_data 96 ms — all set by the declared 4096x4096 grid size. Overlaps with the discussion in the Timepix3 resolution PR.

Activity

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

Metadata

Metadata

Assignees

Labels

area:backendServices, Kafka, message pipeline, preprocessors, job handlingbugupstreamBlocked on Panel, Bokeh, HoloViews or another dependency

Type

No type

Projects

No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions