Skip to content

Commit 0dcb6e4

Browse files
Brian KrafftCopilot
andcommitted
fix: address R2 adversarial findings — isolate observability from execution
Critical (P0→fixed): - Observability errors can no longer discard valid execution results (all metric/trace calls wrapped in isolated try/except blocks) - Import-time crash guard: graceful fallback if prometheus_client missing - _gauge_incremented flag prevents negative gauge values Security: - Strict label sanitization: regex [a-zA-Z0-9_-]{1,32} with unknown fallback - Health probe errors use opaque 'not available' (no type(e).__name__ leak) - Health probe metadata removed (no internal skill count exposure) Reliability: - Health probes now timeout after 5s via ThreadPoolExecutor - start_trace() auto-finishes orphaned active trace (re-entrancy safe) - Span.finish() is idempotent (no double-finish corruption) - max_spans guard returns sentinel span (no parent pollution) Tests: 1,828 passed (+1 probe timeout test) Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
1 parent 95f0e7c commit 0dcb6e4

5 files changed

Lines changed: 120 additions & 46 deletions

File tree

openspace/agents/grounding/execution.py

Lines changed: 52 additions & 31 deletions
Original file line numberDiff line numberDiff line change
@@ -13,8 +13,12 @@
1313
import time
1414
from typing import Any, Dict, List, Optional
1515

16-
from openspace.observability.metrics import metrics as _metrics
17-
from openspace.observability.tracing import tracer as _tracer
16+
try:
17+
from openspace.observability.metrics import metrics as _metrics
18+
from openspace.observability.tracing import tracer as _tracer
19+
except ImportError:
20+
_metrics = None # type: ignore[assignment]
21+
_tracer = None # type: ignore[assignment]
1822
from openspace.prompts import GroundingAgentPrompts
1923
from openspace.utils.logging import Logger
2024

@@ -105,16 +109,21 @@ async def process(agent, context: Dict[str, Any]) -> Dict[str, Any]:
105109
tools=tools,
106110
)
107111

112+
# ── Observability setup (isolated — must not kill execution) ──────
113+
_gauge_incremented = False
108114
try:
109-
# ── Observability: trace + metrics inside try to prevent leaks ──
110115
_instr_hash = hashlib.sha256(instruction.encode()).hexdigest()[:12]
111-
trace = _tracer.start_trace(
116+
_tracer.start_trace(
112117
"grounding.process",
113118
instruction_hash=_instr_hash,
114119
instruction_length=len(instruction),
115120
)
116121
_metrics.execution_in_flight.labels(agent=_agent_label).inc()
122+
_gauge_incremented = True
123+
except Exception:
124+
logger.debug("Observability setup failed", exc_info=True)
117125

126+
try:
118127
while current_iteration < max_iterations:
119128
current_iteration += 1
120129
logger.info(
@@ -293,33 +302,42 @@ async def process(agent, context: Dict[str, Any]) -> Dict[str, Any]:
293302
f"{result.get('status')}"
294303
)
295304

296-
# ── Observability: record success metrics ────────────────────
297-
_elapsed = time.monotonic() - _exec_start
298-
_metrics.execution_latency.labels(agent=_agent_label, status="success").observe(_elapsed)
299-
_metrics.execution_iterations.labels(agent=_agent_label).observe(current_iteration)
300-
_metrics.execution_total.labels(agent=_agent_label, status="success").inc()
301-
_metrics.execution_in_flight.labels(agent=_agent_label).dec()
302-
root_span = _tracer.current_span()
303-
if root_span:
304-
root_span.attributes["iterations"] = current_iteration
305-
root_span.attributes["status"] = result.get("status", "unknown")
306-
_tracer.finish_trace()
305+
# ── Observability: record success (isolated — must not discard result)
306+
try:
307+
_elapsed = time.monotonic() - _exec_start
308+
_metrics.execution_latency.labels(agent=_agent_label, status="success").observe(_elapsed)
309+
_metrics.execution_iterations.labels(agent=_agent_label).observe(current_iteration)
310+
_metrics.execution_total.labels(agent=_agent_label, status="success").inc()
311+
if _gauge_incremented:
312+
_metrics.execution_in_flight.labels(agent=_agent_label).dec()
313+
_gauge_incremented = False
314+
root_span = _tracer.current_span()
315+
if root_span:
316+
root_span.attributes["iterations"] = current_iteration
317+
root_span.attributes["status"] = result.get("status", "unknown")
318+
_tracer.finish_trace()
319+
except Exception:
320+
logger.debug("Observability recording failed", exc_info=True)
307321

308322
return result
309323

310324
except Exception as e:
311325
logger.error(f"Grounding Agent: Execution failed: {e}")
312326

313-
# ── Observability: record error metrics ──────────────────────
314-
_elapsed = time.monotonic() - _exec_start
315-
_metrics.execution_latency.labels(agent=_agent_label, status="error").observe(_elapsed)
316-
_metrics.execution_total.labels(agent=_agent_label, status="error").inc()
317-
_metrics.execution_in_flight.labels(agent=_agent_label).dec()
318-
root_span = _tracer.current_span()
319-
if root_span:
320-
root_span.add_event("error", error_type=type(e).__name__)
321-
root_span.status = "error"
322-
_tracer.finish_trace()
327+
# ── Observability: record error (isolated — must not mask result)
328+
try:
329+
_elapsed = time.monotonic() - _exec_start
330+
_metrics.execution_latency.labels(agent=_agent_label, status="error").observe(_elapsed)
331+
_metrics.execution_total.labels(agent=_agent_label, status="error").inc()
332+
if _gauge_incremented:
333+
_metrics.execution_in_flight.labels(agent=_agent_label).dec()
334+
root_span = _tracer.current_span()
335+
if root_span:
336+
root_span.add_event("error", error_type=type(e).__name__)
337+
root_span.status = "error"
338+
_tracer.finish_trace()
339+
except Exception:
340+
logger.debug("Observability recording failed", exc_info=True)
323341

324342
result = {
325343
"error": type(e).__name__,
@@ -367,16 +385,19 @@ def _build_retrieved_tools_list(
367385
return retrieved_tools_list
368386

369387

388+
import re
389+
370390
# ── Label sanitization ───────────────────────────────────────────────
371391

372-
# Prometheus label values should be bounded. We keep a short allowlist
373-
# and map everything else to "unknown" to prevent cardinality bombs.
374-
_LABEL_MAX_LEN = 64
392+
# Prometheus label values must be bounded and safe. Strict allowlist
393+
# prevents cardinality bombs and scraper injection.
394+
_LABEL_MAX_LEN = 32
395+
_LABEL_SAFE_RE = re.compile(r"[^a-zA-Z0-9_\-]")
375396

376397

377398
def _sanitize_label(value: str) -> str:
378-
"""Clamp a label value to a safe length and replace spaces."""
399+
"""Sanitize a string for use as a Prometheus label value."""
379400
if not value:
380401
return "unknown"
381-
clean = value[:_LABEL_MAX_LEN].replace(" ", "_")
382-
return clean
402+
clean = _LABEL_SAFE_RE.sub("_", value[:_LABEL_MAX_LEN])
403+
return clean or "unknown"

openspace/mcp/server.py

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -162,17 +162,17 @@ def _probe_skill_store() -> HealthProbe:
162162
_probe_skill_store._cached = SkillStore()
163163
store = _probe_skill_store._cached
164164
count = len(store.list_skills()) if hasattr(store, "list_skills") else 0
165-
return HealthProbe(ok=True, detail=f"{count} skills", metadata={"count": count})
166-
except Exception as exc:
167-
return HealthProbe(ok=False, detail=f"{type(exc).__name__}")
165+
return HealthProbe(ok=True, detail=f"{count} skills")
166+
except Exception:
167+
return HealthProbe(ok=False, detail="not available")
168168

169169
def _probe_grounding() -> HealthProbe:
170170
try:
171171
from openspace.agents.grounding_agent import GroundingAgent
172172

173173
return HealthProbe(ok=True, detail="module loaded")
174-
except Exception as exc:
175-
return HealthProbe(ok=False, detail=f"{type(exc).__name__}")
174+
except Exception:
175+
return HealthProbe(ok=False, detail="not available")
176176

177177
def _probe_mcp_tools() -> HealthProbe:
178178
return HealthProbe(ok=True, detail="tools registered")

openspace/observability/health.py

Lines changed: 23 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -19,11 +19,15 @@
1919

2020
from __future__ import annotations
2121

22+
import concurrent.futures
2223
import time
2324
from dataclasses import dataclass, field
2425
from enum import Enum
2526
from typing import Any, Callable, Dict, List, Optional
2627

28+
# Per-probe timeout in seconds
29+
_PROBE_TIMEOUT = 5.0
30+
2731

2832
class HealthStatus(str, Enum):
2933
"""Overall system health status."""
@@ -79,25 +83,39 @@ def unregister(self, name: str) -> None:
7983
def probe_names(self) -> List[str]:
8084
return list(self._probes.keys())
8185

82-
def check(self) -> Dict[str, Any]:
83-
"""Run all probes and return structured health status."""
86+
def check(self, timeout: float = _PROBE_TIMEOUT) -> Dict[str, Any]:
87+
"""Run all probes and return structured health status.
88+
89+
Each probe is run with a timeout guard to prevent a hung probe
90+
from stalling the entire health check.
91+
"""
8492
results: Dict[str, Dict[str, Any]] = {}
8593
failed = 0
8694
total = len(self._probes)
8795

8896
for name, probe_fn in self._probes.items():
8997
start = time.monotonic()
9098
try:
91-
probe = probe_fn()
99+
with concurrent.futures.ThreadPoolExecutor(max_workers=1) as pool:
100+
future = pool.submit(probe_fn)
101+
probe = future.result(timeout=timeout)
92102
probe.latency_ms = (time.monotonic() - start) * 1000
93103
results[name] = probe.to_dict()
94104
if not probe.ok:
95105
failed += 1
96-
except Exception as exc:
106+
except concurrent.futures.TimeoutError:
107+
elapsed = (time.monotonic() - start) * 1000
108+
results[name] = HealthProbe(
109+
ok=False,
110+
detail="probe timeout",
111+
latency_ms=elapsed,
112+
).to_dict()
113+
failed += 1
114+
except Exception:
97115
elapsed = (time.monotonic() - start) * 1000
98116
results[name] = HealthProbe(
99117
ok=False,
100-
detail=f"probe error: {type(exc).__name__}",
118+
detail="probe error",
101119
latency_ms=elapsed,
102120
).to_dict()
103121
failed += 1

openspace/observability/tracing.py

Lines changed: 19 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,8 @@ def duration_ms(self) -> Optional[float]:
5656
return (self.end_time - self.start_time) * 1000
5757

5858
def finish(self, status: str = "ok") -> None:
59+
if self.end_time is not None:
60+
return # Already finished — idempotent
5961
self.end_time = time.monotonic()
6062
self.status = status
6163

@@ -125,7 +127,15 @@ def __init__(self, max_traces: int = _MAX_TRACES) -> None:
125127
self._lock = threading.Lock()
126128

127129
def start_trace(self, name: str = "root", **attrs: Any) -> Trace:
128-
"""Begin a new trace with a root span."""
130+
"""Begin a new trace with a root span.
131+
132+
If a trace is already active, it is finished and stored before
133+
the new one starts (prevents orphaned traces).
134+
"""
135+
existing = _current_trace.get()
136+
if existing is not None:
137+
self.finish_trace()
138+
129139
trace = Trace()
130140
root = Span(
131141
name=name,
@@ -196,9 +206,15 @@ def __enter__(self) -> Span:
196206
return self._span
197207

198208
self._parent = _current_span.get()
199-
# Guard against unbounded span growth
209+
# Guard against unbounded span growth — return a no-op sentinel
200210
if len(trace.spans) >= _MAX_SPANS_PER_TRACE:
201-
return self._parent or trace.spans[0] # return existing span, don't add
211+
self._span = Span(
212+
name=self._name,
213+
trace_id=trace.trace_id,
214+
parent_id=self._parent.span_id if self._parent else None,
215+
)
216+
# NOT appended to trace.spans — mutations are silently discarded
217+
return self._span
202218
self._span = Span(
203219
name=self._name,
204220
trace_id=trace.trace_id,

tests/test_observability.py

Lines changed: 21 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -314,7 +314,7 @@ def bad_probe():
314314
result = agg.check()
315315
assert result["status"] == "unhealthy"
316316
assert result["checks"]["flaky"]["ok"] is False
317-
assert "ConnectionError" in result["checks"]["flaky"]["detail"]
317+
assert "ConnectionError" in result["checks"]["flaky"]["detail"] or "probe error" in result["checks"]["flaky"]["detail"]
318318

319319
def test_uptime_is_positive(self):
320320
agg = HealthAggregator()
@@ -587,12 +587,31 @@ def test_probe_exception_counted_as_failure(self):
587587
result = h.check()
588588
assert result["failed_probes"] == 1
589589
assert result["checks"]["explode"]["ok"] is False
590-
assert "RuntimeError" in result["checks"]["explode"]["detail"]
590+
assert "error" in result["checks"]["explode"]["detail"]
591591

592592
def test_unregister_nonexistent_probe_is_noop(self):
593593
h = HealthAggregator()
594594
h.unregister("does_not_exist") # should not raise
595595

596+
def test_probe_timeout_returns_failure(self):
597+
"""A probe that hangs beyond timeout should fail, not block."""
598+
import threading
599+
600+
h = HealthAggregator()
601+
hang_event = threading.Event()
602+
603+
def _hanging_probe():
604+
hang_event.wait(10) # blocks for up to 10s
605+
return HealthProbe(ok=True)
606+
607+
h.register("hangs", _hanging_probe)
608+
result = h.check(timeout=0.1) # 100ms timeout
609+
hang_event.set() # unblock the thread
610+
611+
assert result["failed_probes"] == 1
612+
assert result["checks"]["hangs"]["ok"] is False
613+
assert "timeout" in result["checks"]["hangs"]["detail"]
614+
596615
def test_finish_trace_with_no_active_trace_returns_none(self):
597616
t = ExecutionTracer()
598617
result = t.finish_trace()

0 commit comments

Comments
 (0)