bvandeusenandClaude Opus 5.5
f802c9f153
The first instrumented drop on dev read "dropped after 10.0s … (completed: parse=0.1s)": the whole stall is inside record_metrics. It now marks its three steps (flush of the rows, the rule and state reads, the per-sample evaluation) on the caller's phases, and the drop line carries the request's samples and metric row count. Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
59 lines
1.9 KiB
Python
59 lines
1.9 KiB
Python
"""A slow ingest says where its time went, and one dropped when the agent hung
|
|
up says how far it got (#5149)."""
|
|
import logging
|
|
|
|
from plugins.host_agent import routes
|
|
|
|
|
|
class _Clock:
|
|
def __init__(self):
|
|
self.t = 100.0
|
|
|
|
def __call__(self):
|
|
return self.t
|
|
|
|
|
|
async def test_a_slow_ingest_logs_its_phases(app, monkeypatch, caplog):
|
|
clock = _Clock()
|
|
monkeypatch.setattr(routes.time, "monotonic", clock)
|
|
async with app.app_context():
|
|
phases = routes._Phases()
|
|
clock.t += 0.1
|
|
phases.mark("parse")
|
|
clock.t += 8.0
|
|
phases.mark("metrics")
|
|
clock.t += 0.4
|
|
phases.mark("commit")
|
|
with caplog.at_level(logging.WARNING):
|
|
phases.report("web-1", 12, 480, 30, 900)
|
|
line = caplog.text
|
|
assert "slow 8.5s for host=web-1" in line
|
|
assert "parse=0.1s metrics=8.0s commit=0.4s" in line
|
|
assert "samples=12 metric_rows=480 containers=30 log_lines=900" in line
|
|
|
|
|
|
async def test_a_quick_ingest_logs_nothing(app, monkeypatch, caplog):
|
|
clock = _Clock()
|
|
monkeypatch.setattr(routes.time, "monotonic", clock)
|
|
async with app.app_context():
|
|
phases = routes._Phases()
|
|
clock.t += 0.3
|
|
phases.mark("commit")
|
|
with caplog.at_level(logging.WARNING):
|
|
phases.report("web-1", 1, 40, 0, 0)
|
|
assert "host_agent ingest" not in caplog.text
|
|
|
|
|
|
async def test_a_dropped_ingest_says_how_far_it_got(app, monkeypatch, caplog):
|
|
clock = _Clock()
|
|
monkeypatch.setattr(routes.time, "monotonic", clock)
|
|
async with app.app_context():
|
|
phases = routes._Phases()
|
|
clock.t += 0.2
|
|
phases.mark("parse")
|
|
phases.size = "samples=21 metric_rows=840"
|
|
clock.t += 9.9
|
|
with caplog.at_level(logging.WARNING):
|
|
phases.cancelled("abcd1234")
|
|
assert "dropped after 10.1s for token=abcd1234… (completed: parse=0.2s) samples=21 metric_rows=840" in caplog.text
|