test: test_streaming_span_duration hangs >900s on slow CPU-only Ollama runner

[planetf1]

Symptom

test/telemetry/test_tracing_backend.py::test_streaming_span_duration was killed by pytest-timeout (>900s) on the Python 3.13 CI runner in PR #1262. The 3.11 and 3.12 runners passed. Main branch CI passes consistently on all three Python versions, so this is intermittent rather than a deterministic 3.13 failure.

CI run: https://github.com/generative-computing/mellea/actions/runs/27607850677/job/81624294814

Diagnosis

Ollama topology

Each matrix job (3.11, 3.12, 3.13) starts its own isolated Ollama instance on its own ephemeral runner — there is no shared resource. The 3.13 runner logged:

WARNING: No NVIDIA/AMD GPU detected. Ollama will run in CPU-only mode.

All generation on that runner was CPU-bound.

Where it hangs

The test issues a real streaming generation request (ModelOption.STREAM: True) against Ollama. The 3.13 runner's CPU-only Ollama stalled mid-stream — chunks stopped arriving. The call stack at timeout was:

asyncio run_until_complete → run_forever → _run_once → selector.poll(timeout=-1)

timeout=-1 means the event loop had no ready callbacks and no timers — it was parked indefinitely on epoll waiting for I/O that never arrived. Tracing the path:

1. OllamaModelBackend defaults timeout=None (ollama.py:91), so the underlying httpx client has no read timeout on the stream.
2. The async queue feeder (async_helpers.py:40-47) is suspended on async for item in aresponse — Ollama stopped sending chunks.
3. The feeder never reaches await aqueue.put(None) (the stream-end sentinel).
4. astream() blocks forever on await self._async_queue.get() (core/base.py:660).
5. avalue() loops calling astream() while not self._computed (core/base.py:592-593) — also blocked.
6. drain_background_tasks() (line 308 of the test) was never reached.

The entire 900s budget was consumed waiting for Ollama to resume. The only thing that eventually unblocked the test was pytest-timeout's SIGALRM.

Why Python 3.13 specifically this time

This is coincidence, not a 3.13 asyncio incompatibility. The pattern (asyncio.Queue, create_task, async for over httpx) behaves identically on 3.11–3.13. The 3.13 runner drew a slower/more-loaded CPU runner, and CPU-only granite4.1:3b stalled under that load. The same hang will recur non-deterministically on whichever matrix leg gets an unlucky runner.

Timeline evidence

Time	Event
10:03:38	test_multiple_generations_separate_spans PASSED
10:03:38	test_streaming_span_duration started
10:18:38	pytest-timeout SIGALRM fires — exactly 900s later

The other non-streaming tests in this file all passed because they use non-streaming generation, which completes or fails fast rather than stalling indefinitely.

Secondary finding: fixture thread leak

_reset_tracing_state() (test_tracing_backend.py:35-42) nulls the OTel provider globals without calling provider.shutdown(), leaking OtelBatchLogRecordProcessor background threads on each reset. 12+ leaked threads were visible in the timeout dump. These are idle daemons — not the cause of the hang — but worth cleaning up.

Root cause

OllamaModelBackend has no client-side read timeout on streaming responses. A mid-stream Ollama stall converts what should be a fast failure into an indefinite hang that can only be resolved by an external timeout.

[planetf1]

Second occurrence: test_ollama_generate_from_raw_metrics_integration

The same hang has now been observed in a second telemetry test — test/telemetry/test_metrics_backend.py::test_ollama_generate_from_raw_metrics_integration — under identical conditions (Python 3.13 matrix leg, CPU-only Ollama runner, >900s pytest-timeout kill).

CI run (PR #1292): https://github.com/generative-computing/mellea/actions/runs/27814082841/job/82310896499

The same failure appeared on worktree-issue-1136 in the same CI run batch, confirming this is not specific to PR #1292.

How it manifests

test_ollama_generate_from_raw_metrics_integration calls generate_from_raw, which issues a non-streaming Ollama request. However, the test body awaits the result on a CPU-only runner where the model is slow to respond. The 900s timeout fires before the response arrives.

What this tells us

The root cause documented above (no client-side read timeout on the Ollama backend) affects both streaming and non-streaming paths. Any test that issues a real Ollama request without its own tight timeout is at risk on a loaded CPU-only runner.

Scope of affected tests

All tests in test/telemetry/test_metrics_backend.py and test/telemetry/test_tracing_backend.py that issue live Ollama calls are candidates for this hang. The fix (adding a client-side read timeout to OllamaModelBackend) would protect all of them.

[planetf1]

Investigation update — PR #1302 closed

PR #1302 attempted to fix this by adding a default timeout to OllamaModelBackend (tried 60 s, then 300 s). The fix converted the 900 s hang into a fast httpx.ReadTimeout, but it introduced a second class of failures on other Ollama tests. Closing it while we figure out the right approach.

What we learned

The scalar timeout is the wrong tool. A float passed to the Ollama SDK becomes an httpx per-operation timeout applied equally to connect, read, write, and pool. For streaming requests the read timeout fires if no chunk arrives within the window — that's exactly what we want. But for non-streaming requests it fires if Ollama hasn't returned the complete response within the window, which includes model loading time.

There are two distinct problems:

1. Streaming stall (original issue) — Ollama stops emitting chunks mid-stream; no data arrives for 900 s; event loop parks on selector.poll(-1). A per-chunk read timeout of ~60 s would catch this.

2. Mid-run cold loads on saturated runners — OLLAMA_KEEP_ALIVE=5m0s causes Ollama to unload the model after 5 minutes of inactivity. Tests that run >5 min after the last Ollama call pay a full cold-load penalty (2–3 min on a fresh runner, potentially >5 min when the runner is loaded after 30+ min of other tests). This did not occur during the initial model load because the runner was still fresh. It only surfaces later in the run.

The 60 s / 300 s default tripped on the second problem — test_span_not_closed_prematurely, test_multiple_generations_separate_spans (3.12/3.13), and test_ollama_generate_from_raw_metrics_integration (3.11) all failed with httpx.ReadTimeout on non-streaming requests when they hit a post-eviction cold load on a loaded runner.

Candidate fixes

Problem 1 (streaming stall): asyncio.timeout(60) inside send_to_queue around async for item in aresponse. This is targeted: only streaming requests go through send_to_queue, so non-streaming tests are completely unaffected. The event loop would have a timer scheduled, preventing indefinite selector.poll(-1) parking.

Problem 2 (mid-run cold loads): Set OLLAMA_KEEP_ALIVE to a value longer than the total test-suite runtime (e.g. 60m or 0 to disable eviction) in quality.yml. This keeps the model warm for the whole run, so no test pays a surprise reload penalty. The initial cold load at the start of the run is fine; it's the mid-run reloads on a degraded runner that cause failures.

The streaming-path fix (Problem 1) can land independently; the CI KEEP_ALIVE change (Problem 2) is separately useful for general test-suite reliability.