add query logging to ~/.cache/graphify-queries.log (#1128)

Co-Authored-By: Claude Sonnet 4.6 <noreply@anthropic.com>
This commit is contained in:
Safi
2026-06-03 21:04:01 +01:00
co-authored by Claude Sonnet 4.6
parent 25df580061
commit 3a90ac2784
4 changed files with 299 additions and 10 deletions
+36 -9
View File
@@ -2486,6 +2486,7 @@ def main() -> None:
from graphify.serve import _query_graph_text
from graphify.security import sanitize_label
from networkx.readwrite import json_graph
from graphify import querylog
question = sys.argv[2]
use_dfs = "--dfs" in sys.argv
@@ -2542,16 +2543,28 @@ def main() -> None:
except Exception as exc:
print(f"error: could not load graph: {exc}", file=sys.stderr)
sys.exit(1)
print(
_query_graph_text(
G,
question,
mode="dfs" if use_dfs else "bfs",
depth=2,
token_budget=budget,
context_filters=context_filters,
)
import time as _time
_t0 = _time.perf_counter()
_mode = "dfs" if use_dfs else "bfs"
_result = _query_graph_text(
G,
question,
mode=_mode,
depth=2,
token_budget=budget,
context_filters=context_filters,
)
querylog.log_query(
kind="query",
question=question,
corpus=str(gp),
result=_result,
mode=_mode,
depth=2,
token_budget=budget,
duration_ms=(_time.perf_counter() - _t0) * 1000,
)
print(_result)
elif cmd == "affected":
if len(sys.argv) < 3:
print("Usage: graphify affected \"<node-or-label>\" [--relation R] [--depth N] [--graph path]", file=sys.stderr)
@@ -2720,6 +2733,13 @@ def main() -> None:
else:
segments.append(f"<--{rel}{conf_str}-- {G.nodes[v].get('label', v)}")
print(f"Shortest path ({hops} hops):\n " + " ".join(segments))
from graphify import querylog
querylog.log_query(
kind="path",
question=f"{sys.argv[2]} -> {sys.argv[3]}",
corpus=str(gp),
nodes_returned=hops,
)
elif cmd == "explain":
if len(sys.argv) < 3:
@@ -2778,6 +2798,13 @@ def main() -> None:
print(f" {arrow} {G.nodes[nb].get('label', nb)} [{rel}] [{conf}]")
if len(connections) > 20:
print(f" ... and {len(connections) - 20} more")
from graphify import querylog
querylog.log_query(
kind="explain",
question=sys.argv[2],
corpus=str(gp),
nodes_returned=len(connections),
)
elif cmd == "diagnose":
subcmd = sys.argv[2] if len(sys.argv) > 2 else ""
+70
View File
@@ -0,0 +1,70 @@
"""Query logging for graphify — append-only JSONL, fail-silent."""
from __future__ import annotations
import json
import os
import re
import time
from datetime import datetime, timezone
from pathlib import Path
from typing import Any
_NODES_RE = re.compile(r"(\d+)\s+nodes?\s+found")
def _log_path() -> Path | None:
if os.environ.get("GRAPHIFY_QUERY_LOG_DISABLE", "").lower() in ("1", "true", "yes"):
return None
override = os.environ.get("GRAPHIFY_QUERY_LOG", "").strip()
if override:
return Path(override).expanduser()
return Path.home() / ".cache" / "graphify-queries.log"
def _log_responses() -> bool:
return os.environ.get("GRAPHIFY_QUERY_LOG_RESPONSES", "").lower() in ("1", "true", "yes")
def nodes_from_result(result: str) -> int | None:
m = _NODES_RE.search(result or "")
return int(m.group(1)) if m else None
def log_query(
*,
kind: str,
question: str,
corpus: str,
result: str | None = None,
nodes_returned: int | None = None,
duration_ms: float | None = None,
**extra: Any,
) -> None:
"""Append one JSONL record to the query log. Never raises."""
try:
path = _log_path()
if path is None:
return
if nodes_returned is None and result is not None:
nodes_returned = nodes_from_result(result)
rec: dict[str, Any] = {
"ts": datetime.now(timezone.utc).isoformat(),
"kind": kind,
"question": question,
"corpus": corpus,
"nodes_returned": nodes_returned,
}
if result is not None:
rec["result_chars"] = len(result)
if duration_ms is not None:
rec["duration_ms"] = round(duration_ms, 3)
for k, v in extra.items():
if v is not None:
rec[k] = v
if result is not None and _log_responses():
rec["response"] = result
path.parent.mkdir(parents=True, exist_ok=True)
with path.open("a", encoding="utf-8") as fh:
fh.write(json.dumps(rec, ensure_ascii=False) + "\n")
except Exception:
pass
+15 -1
View File
@@ -649,12 +649,15 @@ def serve(graph_path: str = "graphify-out/graph.json") -> None:
]
def _tool_query_graph(arguments: dict) -> str:
import time as _time
from graphify import querylog
question = arguments["question"]
mode = arguments.get("mode", "bfs")
depth = min(int(arguments.get("depth", 3)), 6)
budget = int(arguments.get("token_budget", 2000))
context_filter = arguments.get("context_filter")
return _query_graph_text(
_t0 = _time.perf_counter()
result = _query_graph_text(
G,
question,
mode=mode,
@@ -662,6 +665,17 @@ def serve(graph_path: str = "graphify-out/graph.json") -> None:
token_budget=budget,
context_filters=context_filter,
)
querylog.log_query(
kind="mcp_query",
question=question,
corpus=str(graph_path),
result=result,
mode=mode,
depth=depth,
token_budget=budget,
duration_ms=(_time.perf_counter() - _t0) * 1000,
)
return result
def _tool_get_node(arguments: dict) -> str:
label = arguments["label"].lower()
+178
View File
@@ -0,0 +1,178 @@
"""Tests for graphify.querylog."""
import json
import os
import pytest
from pathlib import Path
from graphify.querylog import log_query, nodes_from_result
# ---------------------------------------------------------------------------
# nodes_from_result
# ---------------------------------------------------------------------------
def test_nodes_from_result_parses_header():
result = "Traversal: BFS depth=2 | Start: ['foo'] | 7 nodes found\n\nNODE foo"
assert nodes_from_result(result) == 7
def test_nodes_from_result_singular():
assert nodes_from_result("1 node found") == 1
def test_nodes_from_result_missing():
assert nodes_from_result("no match here") is None
def test_nodes_from_result_empty():
assert nodes_from_result("") is None
# ---------------------------------------------------------------------------
# log_query — basic write
# ---------------------------------------------------------------------------
def test_log_query_writes_jsonl(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="query", question="what is X", corpus="/some/graph.json",
result="3 nodes found\nNODE a", duration_ms=12.5, mode="bfs", depth=2)
lines = log_file.read_text().splitlines()
assert len(lines) == 1
rec = json.loads(lines[0])
assert rec["kind"] == "query"
assert rec["question"] == "what is X"
assert rec["corpus"] == "/some/graph.json"
assert rec["nodes_returned"] == 3
assert rec["result_chars"] > 0
assert rec["duration_ms"] == pytest.approx(12.5, abs=0.01)
assert rec["mode"] == "bfs"
assert "ts" in rec
def test_log_query_appends(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="query", question="q1", corpus="/g.json")
log_query(kind="query", question="q2", corpus="/g.json")
lines = log_file.read_text().splitlines()
assert len(lines) == 2
assert json.loads(lines[0])["question"] == "q1"
assert json.loads(lines[1])["question"] == "q2"
# ---------------------------------------------------------------------------
# opt-out / opt-in
# ---------------------------------------------------------------------------
def test_disable_env(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.setenv("GRAPHIFY_QUERY_LOG_DISABLE", "1")
log_query(kind="query", question="q", corpus="/g.json")
assert not log_file.exists()
def test_disable_env_true(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.setenv("GRAPHIFY_QUERY_LOG_DISABLE", "true")
log_query(kind="query", question="q", corpus="/g.json")
assert not log_file.exists()
def test_responses_not_logged_by_default(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_RESPONSES", raising=False)
log_query(kind="query", question="q", corpus="/g.json", result="NODE foo")
rec = json.loads(log_file.read_text())
assert "response" not in rec
def test_responses_optin(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.setenv("GRAPHIFY_QUERY_LOG_RESPONSES", "1")
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="query", question="q", corpus="/g.json", result="NODE foo bar")
rec = json.loads(log_file.read_text())
assert rec["response"] == "NODE foo bar"
# ---------------------------------------------------------------------------
# robustness — never raises
# ---------------------------------------------------------------------------
def test_log_never_raises(tmp_path, monkeypatch):
# Point at a directory — open() for append will fail
bad_path = tmp_path / "is_a_dir"
bad_path.mkdir()
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(bad_path))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
# Must not raise
log_query(kind="query", question="q", corpus="/g.json")
def test_log_creates_parent_dirs(tmp_path, monkeypatch):
log_file = tmp_path / "deep" / "nested" / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="query", question="q", corpus="/g.json")
assert log_file.exists()
# ---------------------------------------------------------------------------
# field coverage
# ---------------------------------------------------------------------------
def test_nodes_returned_inferred_from_result(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="query", question="q", corpus="/g.json",
result="5 nodes found\nNODE a\nNODE b")
rec = json.loads(log_file.read_text())
assert rec["nodes_returned"] == 5
def test_explicit_nodes_returned_takes_precedence(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="path", question="A -> B", corpus="/g.json", nodes_returned=3)
rec = json.loads(log_file.read_text())
assert rec["nodes_returned"] == 3
def test_kind_mcp_query(tmp_path, monkeypatch):
log_file = tmp_path / "q.log"
monkeypatch.setenv("GRAPHIFY_QUERY_LOG", str(log_file))
monkeypatch.delenv("GRAPHIFY_QUERY_LOG_DISABLE", raising=False)
log_query(kind="mcp_query", question="q", corpus="/g.json")
rec = json.loads(log_file.read_text())
assert rec["kind"] == "mcp_query"