Add structured compiler diagnostics

tests/test_adapter_contract.py

@@ -47,6 +47,7 @@ from docforge.models import (
     RenderConfig,
     RenderView,
 )
+from docforge.telemetry import request
 from docforge.viewer_manager import ViewerManagerClient
 from docforge.visualization import VisualizationIndexSnapshot
 
@@ -497,6 +498,53 @@ class AdapterContractTests(unittest.TestCase):
                 captured.exception.details["changed"],
             )
 
+    def test_warm_incremental_adapter_load_remains_visible_to_diagnostics(self) -> None:
+        with tempfile.TemporaryDirectory() as directory:
+            root = Path(directory).resolve()
+            loader = IncrementalLoader(root)
+            project = AdapterProject(loader, cache_root=root / ".cache" / "incremental")
+            with request("test", enabled=True) as cold_collector:
+                project.load()
+            assert cold_collector is not None
+            cold_counters = cold_collector.as_dict(outcome="ok")["counters"]
+            self.assertEqual(1, cold_counters["project_loads"])
+            self.assertEqual(0, cold_counters["adapter_projection_loads"])
+            self.assertEqual(2, cold_counters["adapter_source_extractions"])
+            loader.extract_calls.clear()
+
+            with request("test", enabled=True) as warm_collector:
+                project.load()
+
+            assert warm_collector is not None
+            counters = warm_collector.as_dict(outcome="ok")["counters"]
+            self.assertEqual(1, counters["project_loads"])
+            self.assertEqual(0, counters["adapter_projection_loads"])
+            self.assertEqual(0, counters["adapter_source_extractions"])
+            self.assertEqual([], loader.extract_calls)
+
+            index = ProjectIndex(project)
+            index.build()
+            with request("test", enabled=True) as read_collector:
+                index.get_node("guide.workflow")
+            assert read_collector is not None
+            read_counters = read_collector.as_dict(outcome="ok")["counters"]
+            self.assertEqual(0, read_counters["project_loads"])
+            self.assertEqual(0, read_counters["adapter_projection_loads"])
+            self.assertEqual(0, read_counters["adapter_source_extractions"])
+            self.assertEqual(0, read_counters["index_builds"])
+
+            legacy = AdapterProject(
+                Loader(self.projection(root)),
+                cache_root=root / ".cache" / "legacy",
+            )
+            with request("test", enabled=True) as legacy_collector:
+                legacy.load()
+            assert legacy_collector is not None
+            legacy_counters = legacy_collector.as_dict(outcome="ok")["counters"]
+            self.assertEqual(1, legacy_counters["project_loads"])
+            self.assertEqual(1, legacy_counters["adapter_projection_loads"])
+            self.assertEqual(0, legacy_counters["adapter_source_extractions"])
+
     def test_incremental_adapter_reuses_sources_and_invalidates_reverse_dependencies(self) -> None:
         with tempfile.TemporaryDirectory() as directory:
             root = Path(directory).resolve()

tests/test_mcp_server.py

@@ -92,6 +92,24 @@ class DocForgeMcpTests(unittest.IsolatedAsyncioTestCase):
                 )
             )
 
+    async def test_factory_diagnostics_are_additive_through_real_mcp(self) -> None:
+        with tempfile.TemporaryDirectory() as directory:
+            root = self.copy_fixture("alpha", Path(directory))
+            ProjectIndex(Project.open(root)).build()
+            async with create_connected_server_and_client_session(
+                create_server(root, diagnostics=True),
+                raise_exceptions=True,
+            ) as session:
+                result = await session.call_tool(
+                    "docforge_get_node",
+                    {"node_id": "guide.workflow"},
+                )
+
+            diagnostics = result.structuredContent["diagnostics"]
+            self.assertEqual("mcp.get_node", diagnostics["operation"])
+            self.assertEqual(0, diagnostics["counters"]["project_loads"])
+            self.assertEqual(0, diagnostics["counters"]["source_files_parsed"])
+
     async def test_no_ast_binding_preserves_adapter_and_blocks_logic(self) -> None:
         with tempfile.TemporaryDirectory() as directory:
             root = self.copy_fixture("alpha", Path(directory))
@@ -263,6 +281,7 @@ class DocForgeMcpTests(unittest.IsolatedAsyncioTestCase):
                     root,
                     "alpha-editor",
                     canonical_applier_id="alpha-editor",
+                    diagnostics=True,
                 ),
                 raise_exceptions=True,
             ) as session:
@@ -477,6 +496,7 @@ class DocForgeMcpTests(unittest.IsolatedAsyncioTestCase):
                 self.assertEqual("ok", payload["status"])
                 self.assertTrue(payload["mutation_committed"])
                 self.assertEqual("receipt", payload["result_mode"])
+                self.assertNotIn("diagnostics", payload)
                 self.assertLessEqual(
                     len(json.dumps(payload, sort_keys=True, separators=(",", ":"))),
                     1600,
@@ -513,7 +533,7 @@ class DocForgeMcpTests(unittest.IsolatedAsyncioTestCase):
             ProjectIndex(Project.open(root)).build()
             changeset_id = "must-not-exist-" + ("x" * 100)
             async with create_connected_server_and_client_session(
-                create_server(root, "alpha-editor"),
+                create_server(root, "alpha-editor", diagnostics=True),
                 raise_exceptions=True,
             ) as session:
                 result = await session.call_tool(
@@ -526,6 +546,7 @@ class DocForgeMcpTests(unittest.IsolatedAsyncioTestCase):
             self.assertEqual("result_too_large", payload["error"]["code"])
             self.assertEqual("preflight", payload["error"]["details"]["stage"])
             self.assertFalse(payload["error"]["details"]["mutation_committed"])
+            self.assertNotIn("diagnostics", payload)
             self.assertFalse((root / f".docforge/changesets/{changeset_id}.json").exists())
 
     async def test_proposal_tools_use_fixed_writer_and_never_change_canonical_content(self) -> None:

tests/test_observability.py

@@ -0,0 +1,370 @@
+from __future__ import annotations
+
+import asyncio
+import io
+import json
+import shutil
+import tempfile
+import threading
+import unittest
+from concurrent.futures import ThreadPoolExecutor
+from dataclasses import replace
+from pathlib import Path
+from unittest import mock
+
+import jsonschema
+
+from docforge.cli import main as cli_main
+from docforge.context import compile_context
+from docforge.errors import DocForgeError
+from docforge.index import ProjectIndex
+from docforge.mcp_server import DocForgeService
+from docforge.project import Project
+from docforge.rendering import RenderService
+from docforge.telemetry import (
+    COUNTER_NAMES,
+    OPERATION_NAMES,
+    STAGE_NAMES,
+    increment,
+    request,
+    stage,
+)
+from docforge.viewer_manager import ViewerManagerClient
+
+ROOT = Path(__file__).resolve().parents[1]
+FIXTURES = ROOT / "tests" / "fixtures"
+RESULT_SCHEMA = json.loads((ROOT / "schemas" / "result.schema.json").read_text())
+ZERO_WORK_COUNTERS = (
+    "project_loads",
+    "source_files_parsed",
+    "source_bytes_parsed",
+    "adapter_projection_loads",
+    "adapter_source_extractions",
+    "index_synchronizations",
+    "index_builds",
+    "render_prepare_calls",
+    "render_output_bytes_built",
+    "render_output_bytes_hashed",
+)
+
+
+class TelemetryContractTests(unittest.TestCase):
+    def copy_fixture(self, destination: Path) -> Path:
+        root = destination / "alpha"
+        shutil.copytree(FIXTURES / "alpha", root)
+        return root
+
+    def test_disabled_collection_reads_no_clock_and_emits_nothing(self) -> None:
+        with (
+            mock.patch(
+                "docforge.telemetry.time.perf_counter_ns",
+                side_effect=AssertionError("disabled telemetry read the clock"),
+            ),
+            request("test", enabled=False) as collector,
+        ):
+            increment("project_loads")
+            with stage("source.parse"):
+                pass
+        self.assertIsNone(collector)
+
+    def test_fixed_names_aggregation_and_exception_cleanup(self) -> None:
+        with (
+            self.assertRaisesRegex(ValueError, "operation"),
+            request(
+                "unknown",
+                enabled=True,
+            ),
+        ):
+            pass
+        with self.assertRaisesRegex(ValueError, "counter"):
+            increment("unknown")
+        with self.assertRaisesRegex(ValueError, "stage"), stage("unknown"):
+            pass
+
+        with request("test", enabled=True) as collector:
+            increment("source_files_parsed", 2)
+            with stage("source.parse"):
+                pass
+            with stage("source.parse"):
+                pass
+        assert collector is not None
+        diagnostics = collector.as_dict(outcome="ok")
+        self.assertEqual(2, diagnostics["counters"]["source_files_parsed"])
+        self.assertEqual(2, diagnostics["stages"]["source.parse"]["calls"])
+
+        with (
+            self.assertRaisesRegex(RuntimeError, "failed"),
+            request(
+                "test",
+                enabled=True,
+            ),
+            stage("index.read"),
+        ):
+            raise RuntimeError("failed")
+        with request("test", enabled=True) as next_collector:
+            increment("project_loads")
+        assert next_collector is not None
+        self.assertEqual(1, next_collector.as_dict(outcome="ok")["counters"]["project_loads"])
+
+        with request("test", enabled=True) as outer_collector:
+            increment("project_loads")
+            with request("test", enabled=True) as inner_collector:
+                increment("project_loads", 5)
+            increment("project_loads")
+        assert outer_collector is not None
+        assert inner_collector is not None
+        self.assertEqual(2, outer_collector.as_dict(outcome="ok")["counters"]["project_loads"])
+        self.assertEqual(5, inner_collector.as_dict(outcome="ok")["counters"]["project_loads"])
+
+    def test_schema_fixed_names_match_the_implementation(self) -> None:
+        properties = RESULT_SCHEMA["$defs"]["diagnostics"]["properties"]
+        self.assertEqual(
+            set(OPERATION_NAMES),
+            set(properties["operation"]["enum"]),
+        )
+        self.assertEqual(
+            set(STAGE_NAMES),
+            set(properties["stages"]["propertyNames"]["enum"]),
+        )
+        self.assertEqual(
+            set(COUNTER_NAMES),
+            set(properties["counters"]["required"]),
+        )
+        self.assertEqual(
+            set(COUNTER_NAMES),
+            set(properties["counters"]["properties"]),
+        )
+
+    def test_thread_and_async_request_contexts_are_isolated(self) -> None:
+        barrier = threading.Barrier(2)
+
+        def thread_worker(amount: int) -> int:
+            with request("test", enabled=True) as collector:
+                increment("project_loads", amount)
+                barrier.wait()
+                barrier.wait()
+            assert collector is not None
+            return int(collector.as_dict(outcome="ok")["counters"]["project_loads"])
+
+        with ThreadPoolExecutor(max_workers=2) as executor:
+            futures = [executor.submit(thread_worker, amount) for amount in (1, 3)]
+            self.assertEqual([1, 3], [future.result() for future in futures])
+
+        async def verify_async_isolation() -> list[int]:
+            ready = [asyncio.Event(), asyncio.Event()]
+            proceed = asyncio.Event()
+
+            async def async_worker(position: int, amount: int) -> int:
+                with request("test", enabled=True) as collector:
+                    increment("project_loads", amount)
+                    ready[position].set()
+                    await proceed.wait()
+                assert collector is not None
+                return int(collector.as_dict(outcome="ok")["counters"]["project_loads"])
+
+            tasks = [
+                asyncio.create_task(async_worker(position, amount))
+                for position, amount in enumerate((2, 5))
+            ]
+            await asyncio.gather(*(event.wait() for event in ready))
+            proceed.set()
+            return list(await asyncio.gather(*tasks))
+
+        self.assertEqual([2, 5], asyncio.run(verify_async_isolation()))
+
+    def test_generic_positive_controls_and_warm_zero_work_invariants(self) -> None:
+        with tempfile.TemporaryDirectory() as directory:
+            root = self.copy_fixture(Path(directory))
+            project = Project.open(root)
+            with request("test", enabled=True) as load_collector:
+                project.load()
+            assert load_collector is not None
+            load_counters = load_collector.as_dict(outcome="ok")["counters"]
+            self.assertEqual(1, load_counters["project_loads"])
+            self.assertGreater(load_counters["source_files_parsed"], 0)
+            self.assertGreater(load_counters["source_bytes_parsed"], 0)
+
+            index = ProjectIndex(project)
+            with request("test", enabled=True) as build_collector:
+                index.build()
+            assert build_collector is not None
+            build_counters = build_collector.as_dict(outcome="ok")["counters"]
+            self.assertEqual(1, build_counters["index_builds"])
+            self.assertGreater(build_counters["project_loads"], 0)
+
+            renderer = RenderService(project)
+            with request("test", enabled=True) as render_collector:
+                renderer.render("manual")
+            assert render_collector is not None
+            render_counters = render_collector.as_dict(outcome="ok")["counters"]
+            self.assertGreater(render_counters["render_prepare_calls"], 0)
+            self.assertGreater(render_counters["render_output_bytes_built"], 0)
+
+            with request("test", enabled=True) as deep_collector:
+                renderer.deep_status("manual")
+            assert deep_collector is not None
+            deep_counters = deep_collector.as_dict(outcome="ok")["counters"]
+            self.assertGreater(deep_counters["render_output_bytes_hashed"], 0)
+
+            service = DocForgeService(project, diagnostics=True)
+
+            warm_operations = {
+                "sync": service.synchronize,
+                "node": lambda: service.invoke(
+                    lambda: service.index.get_node("guide.workflow"),
+                    operation_name="mcp.get_node",
+                ),
+                "search": lambda: service.invoke(
+                    lambda: service.index.search("workflow", limit=5),
+                    operation_name="mcp.search",
+                ),
+                "filter": lambda: service.invoke(
+                    lambda: service.index.filter_nodes(family="guide", limit=5),
+                    operation_name="mcp.filter",
+                ),
+                "backlinks": lambda: service.invoke(
+                    lambda: service.index.backlinks("guide.foundation", limit=5),
+                    operation_name="mcp.backlinks",
+                ),
+                "dependencies": lambda: service.invoke(
+                    lambda: service.index.dependencies("guide.workflow", depth=2, limit=5),
+                    operation_name="mcp.dependencies",
+                ),
+                "impact": lambda: service.invoke(
+                    lambda: service.index.impact("guide.foundation", depth=2, limit=5),
+                    operation_name="mcp.impact",
+                ),
+                "context": lambda: service.invoke(
+                    lambda: compile_context(service.index, "active"),
+                    operation_name="mcp.context",
+                ),
+            }
+            warm_results: dict[str, dict[str, object]] = {}
+            for name, operation in warm_operations.items():
+                with self.subTest(operation=name):
+                    result = operation()
+                    warm_results[name] = result
+                    diagnostics = result["diagnostics"]
+                    for counter in ZERO_WORK_COUNTERS:
+                        expected = (
+                            1 if name == "sync" and counter == "index_synchronizations" else 0
+                        )
+                        self.assertEqual(
+                            expected,
+                            diagnostics["counters"][counter],
+                            counter,
+                        )
+                    self.assertGreater(diagnostics["counters"]["source_generation_checks"], 0)
+
+            node_result = warm_results["node"]
+            node_diagnostics = node_result["diagnostics"]
+            self.assertGreater(node_diagnostics["counters"]["index_checks"], 0)
+
+            missing_result = service.invoke(
+                lambda: service.index.get_node("missing.node"),
+                operation_name="mcp.get_node",
+            )
+            self.assertEqual("error", missing_result["status"])
+            for counter in ZERO_WORK_COUNTERS:
+                self.assertEqual(
+                    0,
+                    missing_result["diagnostics"]["counters"][counter],
+                    counter,
+                )
+
+            render_result = service.render_status("manual")
+            render_diagnostics = render_result["diagnostics"]
+            for counter in ZERO_WORK_COUNTERS:
+                self.assertEqual(0, render_diagnostics["counters"][counter], counter)
+            self.assertEqual(1, render_diagnostics["stages"]["render.status"]["calls"])
+            jsonschema.validate(node_result, RESULT_SCHEMA)
+            jsonschema.validate(render_result, RESULT_SCHEMA)
+
+    def test_structured_errors_include_diagnostics_and_schema_validation(self) -> None:
+        with tempfile.TemporaryDirectory() as directory:
+            project = Project.open(self.copy_fixture(Path(directory)))
+            service = DocForgeService(project, diagnostics=True)
+
+            def fail() -> dict[str, object]:
+                raise DocForgeError("intentional", "Intentional telemetry error")
+
+            result = service.invoke(
+                fail,
+                synchronize=False,
+                load_error_identity=False,
+                operation_name="mcp.invoke",
+            )
+            self.assertEqual("error", result["status"])
+            self.assertEqual("error", result["diagnostics"]["outcome"])
+            jsonschema.validate(result, RESULT_SCHEMA)
+
+    def test_visualization_status_error_has_one_request_and_no_hidden_work(self) -> None:
+        with tempfile.TemporaryDirectory() as directory:
+            root = self.copy_fixture(Path(directory))
+            project = Project.open(root)
+            service = DocForgeService(project, diagnostics=True)
+            service.visualization = ViewerManagerClient(
+                service.index,
+                state_path=root / ".docforge" / "missing-viewer-manager.json",
+            )
+
+            result = service.visualization_status()
+
+            self.assertEqual("error", result["status"])
+            counters = result["diagnostics"]["counters"]
+            for counter in ZERO_WORK_COUNTERS:
+                self.assertEqual(0, counters[counter], counter)
+            self.assertEqual(1, counters["viewer_manager_requests"])
+            self.assertEqual(
+                1,
+                result["diagnostics"]["stages"]["visualization.status"]["calls"],
+            )
+            self.assertEqual(
+                1,
+                result["diagnostics"]["stages"]["viewer.manager"]["calls"],
+            )
+
+    def test_diagnostics_are_dropped_before_the_primary_result(self) -> None:
+        with tempfile.TemporaryDirectory() as directory:
+            original = Project.open(self.copy_fixture(Path(directory)))
+            limits = replace(original.descriptor.limits, max_tool_output_chars=600)
+            project = Project(replace(original.descriptor, limits=limits))
+            service = DocForgeService(project, diagnostics=True)
+            result = service.invoke(
+                lambda: {
+                    "status": "ok",
+                    "project_id": project.descriptor.project_id,
+                    "revision": "unversioned",
+                    "source_hash": "0" * 64,
+                },
+                synchronize=False,
+                operation_name="mcp.invoke",
+            )
+            self.assertEqual("ok", result["status"])
+            self.assertNotIn("diagnostics", result)
+
+    def test_cli_diagnostics_flag_is_additive_and_defaults_off(self) -> None:
+        base_arguments = ["--project-root", "/unused", "info"]
+        with mock.patch("docforge.cli._run", return_value={"status": "ok"}):
+            with mock.patch("sys.stdout", new_callable=io.StringIO) as output:
+                self.assertEqual(0, cli_main(base_arguments))
+            self.assertNotIn("diagnostics", json.loads(output.getvalue()))
+
+            with mock.patch("sys.stdout", new_callable=io.StringIO) as output:
+                self.assertEqual(
+                    0,
+                    cli_main(
+                        [
+                            "--project-root",
+                            "/unused",
+                            "--diagnostics",
+                            "info",
+                        ]
+                    ),
+                )
+            result = json.loads(output.getvalue())
+            self.assertEqual("cli.info", result["diagnostics"]["operation"])
+
+
+if __name__ == "__main__":
+    unittest.main()