diff --git a/graphify/__main__.py b/graphify/__main__.py index efd5619..ba3ceb6 100644 --- a/graphify/__main__.py +++ b/graphify/__main__.py @@ -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 \"\" [--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 "" diff --git a/graphify/querylog.py b/graphify/querylog.py new file mode 100644 index 0000000..1bee5b2 --- /dev/null +++ b/graphify/querylog.py @@ -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 diff --git a/graphify/serve.py b/graphify/serve.py index 6e5d4a1..2314820 100644 --- a/graphify/serve.py +++ b/graphify/serve.py @@ -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() diff --git a/tests/test_querylog.py b/tests/test_querylog.py new file mode 100644 index 0000000..2ebe851 --- /dev/null +++ b/tests/test_querylog.py @@ -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"