mirror of
https://github.com/usestrix/strix.git
synced 2026-08-16 09:26:39 +02:00
feat(logging): close audit gaps — SDK records, proxy tracebacks, CLI/docker/posthog
Five gaps from the post-implementation audit, closed:
1. **SDK logger captured.** The openai-agents SDK uses
``logging.getLogger("openai.agents")`` for its own lifecycle events
(Runner.run starts, tool dispatch, model retries, exceptions).
Previous setup only attached handlers to the ``strix`` root, so
SDK-internal events were dropped. Tracked-roots tuple now covers
both, with the same FileHandler/StreamHandler/Filter chain.
2. **Proxy tool exception tracebacks.** Every ``@function_tool`` in
``strix/tools/proxy/tools.py`` returns a JSON error to the LLM via
the ``_err(name, exc)`` helper. The tracebacks were silently
formatted away — the LLM saw the message, the human reading the
log saw nothing. ``_err`` now emits ``logger.exception(...)``
covering all five tools at once.
3. **CLI bootstrap.** ``strix/interface/main.py`` had its module
``logger`` removed by the previous commit and was emitting nothing.
Restored, plus log lines for env validation, docker check, LLM
warm-up, and image pull (debug for already-present, info for
pull, exception for failures).
4. **Docker client.** ``strix/runtime/docker_client.py`` had no
logger. Container creation now logs caps + exposed ports at DEBUG
and the resulting container id at INFO.
5. **PostHog telemetry.** ``strix/telemetry/posthog.py`` had no
logger. Now logs send success/failure at DEBUG, version-detection
failures at DEBUG, and disabled-skip at DEBUG (so the log shows
when telemetry is off, instead of being silent about it).
Co-Authored-By: Claude Opus 4.7 (1M context) <noreply@anthropic.com>
This commit is contained in:
co-authored by
Claude Opus 4.7
parent
46ff025209
commit
f8213452ea
+23
-2
@@ -42,14 +42,21 @@ from strix.telemetry.tracer import get_global_tracer
|
|||||||
HOST_GATEWAY_HOSTNAME = "host.docker.internal"
|
HOST_GATEWAY_HOSTNAME = "host.docker.internal"
|
||||||
|
|
||||||
|
|
||||||
|
import logging # noqa: E402
|
||||||
|
|
||||||
|
|
||||||
# Per-scan logging is set up by ``setup_scan_logging`` from inside
|
# Per-scan logging is set up by ``setup_scan_logging`` from inside
|
||||||
# ``orchestration.scan.run_strix_scan`` once the scan ``run_dir`` is
|
# ``orchestration.scan.run_strix_scan`` once the scan ``run_dir`` is
|
||||||
# known — that's where ``strix.*`` levels and handlers are owned. Pre-scan
|
# known — that's where ``strix.*`` levels and handlers are owned. Pre-scan
|
||||||
# work (``main()``, env validation, image pull) emits at WARNING+ to
|
# work (``main()``, env validation, image pull) emits via the module
|
||||||
# stderr via the SDK / stdlib defaults.
|
# logger; once setup_scan_logging runs, those records start landing in
|
||||||
|
# the file too.
|
||||||
|
|
||||||
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
def validate_environment() -> None:
|
def validate_environment() -> None:
|
||||||
|
logger.info("Validating environment")
|
||||||
console = Console()
|
console = Console()
|
||||||
missing_required_vars = []
|
missing_required_vars = []
|
||||||
missing_optional_vars = []
|
missing_optional_vars = []
|
||||||
@@ -162,14 +169,20 @@ def validate_environment() -> None:
|
|||||||
padding=(1, 2),
|
padding=(1, 2),
|
||||||
)
|
)
|
||||||
|
|
||||||
|
logger.error("Missing required env vars: %s", missing_required_vars)
|
||||||
console.print("\n")
|
console.print("\n")
|
||||||
console.print(panel)
|
console.print(panel)
|
||||||
console.print()
|
console.print()
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
|
logger.info(
|
||||||
|
"Environment OK (optional missing: %s)",
|
||||||
|
missing_optional_vars or "none",
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
def check_docker_installed() -> None:
|
def check_docker_installed() -> None:
|
||||||
if shutil.which("docker") is None:
|
if shutil.which("docker") is None:
|
||||||
|
logger.error("Docker CLI not found in PATH")
|
||||||
console = Console()
|
console = Console()
|
||||||
error_text = Text()
|
error_text = Text()
|
||||||
error_text.append("DOCKER NOT INSTALLED", style="bold red")
|
error_text.append("DOCKER NOT INSTALLED", style="bold red")
|
||||||
@@ -188,10 +201,12 @@ def check_docker_installed() -> None:
|
|||||||
)
|
)
|
||||||
console.print("\n", panel, "\n")
|
console.print("\n", panel, "\n")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
|
logger.debug("Docker CLI present")
|
||||||
|
|
||||||
|
|
||||||
async def warm_up_llm() -> None:
|
async def warm_up_llm() -> None:
|
||||||
console = Console()
|
console = Console()
|
||||||
|
logger.info("Warming up LLM connection")
|
||||||
|
|
||||||
try:
|
try:
|
||||||
llm = load_settings().llm
|
llm = load_settings().llm
|
||||||
@@ -214,8 +229,10 @@ async def warm_up_llm() -> None:
|
|||||||
response = litellm.completion(**completion_kwargs)
|
response = litellm.completion(**completion_kwargs)
|
||||||
|
|
||||||
validate_llm_response(response)
|
validate_llm_response(response)
|
||||||
|
logger.info("LLM warm-up succeeded for model %s", llm.model)
|
||||||
|
|
||||||
except Exception as e:
|
except Exception as e:
|
||||||
|
logger.exception("LLM warm-up failed")
|
||||||
error_text = Text()
|
error_text = Text()
|
||||||
error_text.append("LLM CONNECTION FAILED", style="bold red")
|
error_text.append("LLM CONNECTION FAILED", style="bold red")
|
||||||
error_text.append("\n\n", style="white")
|
error_text.append("\n\n", style="white")
|
||||||
@@ -473,8 +490,10 @@ def pull_docker_image() -> None:
|
|||||||
image = load_settings().runtime.image
|
image = load_settings().runtime.image
|
||||||
|
|
||||||
if image_exists(client, image):
|
if image_exists(client, image):
|
||||||
|
logger.debug("Docker image already present locally: %s", image)
|
||||||
return
|
return
|
||||||
|
|
||||||
|
logger.info("Pulling docker image: %s", image)
|
||||||
console.print()
|
console.print()
|
||||||
console.print(f"[dim]Pulling image[/] {image}")
|
console.print(f"[dim]Pulling image[/] {image}")
|
||||||
console.print("[dim yellow]This only happens on first run and may take a few minutes...[/]")
|
console.print("[dim yellow]This only happens on first run and may take a few minutes...[/]")
|
||||||
@@ -489,6 +508,7 @@ def pull_docker_image() -> None:
|
|||||||
last_update = process_pull_line(line, layers_info, status, last_update)
|
last_update = process_pull_line(line, layers_info, status, last_update)
|
||||||
|
|
||||||
except DockerException as e:
|
except DockerException as e:
|
||||||
|
logger.exception("Failed to pull docker image %s", image)
|
||||||
console.print()
|
console.print()
|
||||||
error_text = Text()
|
error_text = Text()
|
||||||
error_text.append("FAILED TO PULL IMAGE", style="bold red")
|
error_text.append("FAILED TO PULL IMAGE", style="bold red")
|
||||||
@@ -506,6 +526,7 @@ def pull_docker_image() -> None:
|
|||||||
console.print(panel, "\n")
|
console.print(panel, "\n")
|
||||||
sys.exit(1)
|
sys.exit(1)
|
||||||
|
|
||||||
|
logger.info("Docker image %s ready", image)
|
||||||
success_text = Text()
|
success_text = Text()
|
||||||
success_text.append("Docker image ready", style="#22c55e")
|
success_text.append("Docker image ready", style="#22c55e")
|
||||||
console.print(success_text)
|
console.print(success_text)
|
||||||
|
|||||||
@@ -17,6 +17,7 @@ re-merging the parent body. Track upstream for an injection hook.
|
|||||||
|
|
||||||
from __future__ import annotations
|
from __future__ import annotations
|
||||||
|
|
||||||
|
import logging
|
||||||
import uuid
|
import uuid
|
||||||
from typing import Any
|
from typing import Any
|
||||||
|
|
||||||
@@ -32,6 +33,9 @@ from docker.models.containers import Container # type: ignore[import-untyped, u
|
|||||||
from docker.utils import parse_repository_tag # type: ignore[import-untyped, unused-ignore]
|
from docker.utils import parse_repository_tag # type: ignore[import-untyped, unused-ignore]
|
||||||
|
|
||||||
|
|
||||||
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
class StrixDockerSandboxClient(DockerSandboxClient):
|
class StrixDockerSandboxClient(DockerSandboxClient):
|
||||||
"""``DockerSandboxClient`` subclass that injects Strix-required capabilities.
|
"""``DockerSandboxClient`` subclass that injects Strix-required capabilities.
|
||||||
|
|
||||||
@@ -100,4 +104,16 @@ class StrixDockerSandboxClient(DockerSandboxClient):
|
|||||||
extra_hosts = create_kwargs.setdefault("extra_hosts", {})
|
extra_hosts = create_kwargs.setdefault("extra_hosts", {})
|
||||||
extra_hosts["host.docker.internal"] = "host-gateway"
|
extra_hosts["host.docker.internal"] = "host-gateway"
|
||||||
|
|
||||||
return self.docker_client.containers.create(**create_kwargs)
|
logger.debug(
|
||||||
|
"Creating sandbox container: image=%s caps=%s exposed_ports=%s",
|
||||||
|
image,
|
||||||
|
cap_add,
|
||||||
|
list(exposed_ports),
|
||||||
|
)
|
||||||
|
container = self.docker_client.containers.create(**create_kwargs)
|
||||||
|
logger.info(
|
||||||
|
"Sandbox container created: id=%s image=%s",
|
||||||
|
container.short_id if hasattr(container, "short_id") else "?",
|
||||||
|
image,
|
||||||
|
)
|
||||||
|
return container
|
||||||
|
|||||||
+24
-13
@@ -72,6 +72,15 @@ _NOISY_LIBS: tuple[str, ...] = (
|
|||||||
_HANDLER_TAG = "_strix_scan_handler"
|
_HANDLER_TAG = "_strix_scan_handler"
|
||||||
|
|
||||||
|
|
||||||
|
# Logger roots that also receive our scan handlers. ``strix`` covers
|
||||||
|
# everything we own. ``openai.agents`` is the openai-agents SDK's
|
||||||
|
# canonical logger (verified: ``agents/logger.py``, ``agents/__init__.py``,
|
||||||
|
# ``agents/tracing/logger.py`` all use this namespace) — without
|
||||||
|
# attaching here, SDK-internal Runner / tool-dispatch / model-retry
|
||||||
|
# events would be invisible.
|
||||||
|
_TRACKED_ROOTS: tuple[str, ...] = ("strix", "openai.agents")
|
||||||
|
|
||||||
|
|
||||||
def setup_scan_logging(run_dir: Path, *, debug: bool | None = None) -> Callable[[], None]:
|
def setup_scan_logging(run_dir: Path, *, debug: bool | None = None) -> Callable[[], None]:
|
||||||
"""Attach scan-scoped handlers; return a teardown callable.
|
"""Attach scan-scoped handlers; return a teardown callable.
|
||||||
|
|
||||||
@@ -114,23 +123,25 @@ def setup_scan_logging(run_dir: Path, *, debug: bool | None = None) -> Callable[
|
|||||||
stream_handler.addFilter(context_filter)
|
stream_handler.addFilter(context_filter)
|
||||||
setattr(stream_handler, _HANDLER_TAG, True)
|
setattr(stream_handler, _HANDLER_TAG, True)
|
||||||
|
|
||||||
strix_root = logging.getLogger("strix")
|
tracked_loggers = [logging.getLogger(name) for name in _TRACKED_ROOTS]
|
||||||
strix_root.setLevel(logging.DEBUG)
|
for tracked in tracked_loggers:
|
||||||
strix_root.addHandler(file_handler)
|
tracked.setLevel(logging.DEBUG)
|
||||||
strix_root.addHandler(stream_handler)
|
tracked.addHandler(file_handler)
|
||||||
# Stop ``strix.*`` records from also bubbling to the python root
|
tracked.addHandler(stream_handler)
|
||||||
# logger's lastResort handler (which would double-print to stderr).
|
# Stop these records from also bubbling to the python root
|
||||||
strix_root.propagate = False
|
# logger's lastResort handler (would double-print to stderr).
|
||||||
|
tracked.propagate = False
|
||||||
|
|
||||||
for name in _NOISY_LIBS:
|
for name in _NOISY_LIBS:
|
||||||
logging.getLogger(name).setLevel(logging.WARNING)
|
logging.getLogger(name).setLevel(logging.WARNING)
|
||||||
|
|
||||||
def _teardown() -> None:
|
def _teardown() -> None:
|
||||||
for handler in list(strix_root.handlers):
|
for tracked in tracked_loggers:
|
||||||
if getattr(handler, _HANDLER_TAG, False):
|
for handler in list(tracked.handlers):
|
||||||
strix_root.removeHandler(handler)
|
if getattr(handler, _HANDLER_TAG, False):
|
||||||
with contextlib.suppress(Exception):
|
tracked.removeHandler(handler)
|
||||||
handler.flush()
|
with contextlib.suppress(Exception):
|
||||||
handler.close()
|
handler.flush()
|
||||||
|
handler.close()
|
||||||
|
|
||||||
return _teardown
|
return _teardown
|
||||||
|
|||||||
@@ -1,4 +1,5 @@
|
|||||||
import json
|
import json
|
||||||
|
import logging
|
||||||
import platform
|
import platform
|
||||||
import sys
|
import sys
|
||||||
import urllib.request
|
import urllib.request
|
||||||
@@ -12,6 +13,9 @@ from strix.config import load_settings
|
|||||||
if TYPE_CHECKING:
|
if TYPE_CHECKING:
|
||||||
from strix.telemetry.tracer import Tracer
|
from strix.telemetry.tracer import Tracer
|
||||||
|
|
||||||
|
|
||||||
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
_POSTHOG_PUBLIC_API_KEY = "phc_7rO3XRuNT5sgSKAl6HDIrWdSGh1COzxw0vxVIAR6vVZ"
|
_POSTHOG_PUBLIC_API_KEY = "phc_7rO3XRuNT5sgSKAl6HDIrWdSGh1COzxw0vxVIAR6vVZ"
|
||||||
_POSTHOG_HOST = "https://us.i.posthog.com"
|
_POSTHOG_HOST = "https://us.i.posthog.com"
|
||||||
|
|
||||||
@@ -41,11 +45,13 @@ def _get_version() -> str:
|
|||||||
|
|
||||||
return version("strix-agent")
|
return version("strix-agent")
|
||||||
except Exception: # noqa: BLE001
|
except Exception: # noqa: BLE001
|
||||||
|
logger.debug("strix-agent version lookup failed", exc_info=True)
|
||||||
return "unknown"
|
return "unknown"
|
||||||
|
|
||||||
|
|
||||||
def _send(event: str, properties: dict[str, Any]) -> None:
|
def _send(event: str, properties: dict[str, Any]) -> None:
|
||||||
if not _is_enabled():
|
if not _is_enabled():
|
||||||
|
logger.debug("posthog disabled; skipping event %s", event)
|
||||||
return
|
return
|
||||||
try:
|
try:
|
||||||
payload = {
|
payload = {
|
||||||
@@ -61,8 +67,11 @@ def _send(event: str, properties: dict[str, Any]) -> None:
|
|||||||
)
|
)
|
||||||
with urllib.request.urlopen(req, timeout=10): # noqa: S310 # nosec B310
|
with urllib.request.urlopen(req, timeout=10): # noqa: S310 # nosec B310
|
||||||
pass
|
pass
|
||||||
except Exception: # noqa: BLE001, S110
|
except Exception: # noqa: BLE001
|
||||||
pass # nosec B110
|
# Telemetry must never disrupt a scan; log + swallow.
|
||||||
|
logger.debug("posthog send failed for event %s", event, exc_info=True)
|
||||||
|
else:
|
||||||
|
logger.debug("posthog event sent: %s", event)
|
||||||
|
|
||||||
|
|
||||||
def _base_props() -> dict[str, Any]:
|
def _base_props() -> dict[str, Any]:
|
||||||
|
|||||||
@@ -14,6 +14,7 @@ from __future__ import annotations
|
|||||||
|
|
||||||
import dataclasses
|
import dataclasses
|
||||||
import json
|
import json
|
||||||
|
import logging
|
||||||
import re
|
import re
|
||||||
from dataclasses import is_dataclass
|
from dataclasses import is_dataclass
|
||||||
from datetime import datetime
|
from datetime import datetime
|
||||||
@@ -24,6 +25,9 @@ from agents import RunContextWrapper, function_tool
|
|||||||
from strix.tools.proxy import _calls
|
from strix.tools.proxy import _calls
|
||||||
|
|
||||||
|
|
||||||
|
logger = logging.getLogger(__name__)
|
||||||
|
|
||||||
|
|
||||||
if TYPE_CHECKING:
|
if TYPE_CHECKING:
|
||||||
from caido_sdk_client import Client
|
from caido_sdk_client import Client
|
||||||
|
|
||||||
@@ -79,6 +83,7 @@ def _no_client() -> str:
|
|||||||
|
|
||||||
|
|
||||||
def _err(name: str, exc: Exception) -> str:
|
def _err(name: str, exc: Exception) -> str:
|
||||||
|
logger.exception("%s failed", name)
|
||||||
return json.dumps(
|
return json.dumps(
|
||||||
{"success": False, "error": f"{name} failed: {exc}"},
|
{"success": False, "error": f"{name} failed: {exc}"},
|
||||||
ensure_ascii=False,
|
ensure_ascii=False,
|
||||||
|
|||||||
Reference in New Issue
Block a user