fix(lsp): log at INFO when a request is skipped because its root is marked broken

After one timeout `_mark_broken_for_file` disables the whole (server, root)
pair for the life of the process, and every later request returned [] with no
log line at all — at default levels a skipped file and a clean file
(`log_clean` is DEBUG) looked identical, so a workspace that silently lost
TypeScript feedback was indistinguishable from a healthy one (#116446, ask 3).

`LSPService.enabled_for` — the gate every production path (snapshot,
get_diagnostics_sync, file_operations_lint) runs through — now emits
`eventlog.log_skipped_broken`: INFO once per (server, root), DEBUG on repeats,
same dedup bucket pattern as the other announce-once events.
This commit is contained in:
teknium1
2026-09-19 23:06:43 -07:00
committed by Teknium
parent b4f0553f8e
commit d15b17adf5
3 changed files with 41 additions and 3 deletions

View File

@@ -26,7 +26,8 @@ _ANNOUNCE_CAP = 512
_announced_active: set = set() # keys: (server_id, workspace_root)
_announced_unavailable: set = set() # keys: (server_id, binary_path_or_name)
_announced_no_root: set = set() # keys: (server_id, file_path)
_ALL_BUCKETS = (_announced_active, _announced_unavailable, _announced_no_root)
_announced_skipped: set = set() # keys: (server_id, workspace_root)
_ALL_BUCKETS = (_announced_active, _announced_unavailable, _announced_no_root, _announced_skipped)
def _short_path(file_path: str) -> str:
@@ -111,6 +112,15 @@ def log_spawn_failed(server_id: str, workspace_root: str, exc: BaseException) ->
_emit(server_id, logging.WARNING, f"spawn/initialize failed for {workspace_root}: {type(exc).__name__}: {exc}")
def log_skipped_broken(server_id: str, workspace_root: str, file_path: str) -> None:
"""A request was skipped because ``(server_id, root)`` is marked broken. INFO once per root, then DEBUG:
at default log levels a skipped file and a clean file otherwise look identical (``log_clean`` is DEBUG)."""
_emit_once(_announced_skipped, (server_id, workspace_root), server_id, logging.INFO,
f"skipping {_short_path(file_path)}: {workspace_root} marked broken after an earlier failure "
"(no diagnostics for this root until restart)",
f"skipping {_short_path(file_path)}: {workspace_root} marked broken")
def log_reaped(keys: List[Tuple[str, str]], idle_timeout: float) -> None:
"""Idle clients were reaped. INFO, one line per sweep.
@@ -141,7 +151,7 @@ def reset_announce_caches() -> None:
__all__ = [
"event_log", "log_clean", "log_disabled", "log_active", "log_diagnostics", "log_no_project_root",
"log_server_unavailable", "log_timeout", "log_server_error", "log_spawn_failed", "log_reaped",
"log_server_unavailable", "log_timeout", "log_server_error", "log_spawn_failed", "log_skipped_broken", "log_reaped",
"reset_announce_caches",
]

View File

@@ -207,7 +207,12 @@ class LSPService:
if srv is None or srv.server_id in self._disabled_servers:
return False
key = self._broken_key(srv, file_path)
return key is not None and key not in self._broken
if key is None:
return False
if key in self._broken:
eventlog.log_skipped_broken(srv.server_id, key[1], file_path)
return False
return True
def snapshot_baseline(self, file_path: str) -> None:
"""Snapshot current diagnostics for ``file_path`` as the delta baseline (call BEFORE a write).

View File

@@ -124,3 +124,26 @@ def test_snapshot_failure_marks_broken_via_outer_timeout(tmp_path, monkeypatch):
assert svc.enabled_for(str(src)) is False
finally:
svc.shutdown()
def test_skipped_request_on_broken_root_is_logged_at_info(tmp_path, monkeypatch, caplog):
"""A request skipped because its root is broken must leave a visible trace (#116446): at default
levels ``log_clean`` is DEBUG, so a silently skipped file was indistinguishable from a clean one."""
from agent.lsp import eventlog
repo = _make_git_workspace(tmp_path)
src = repo / "x.py"
src.write_text("")
monkeypatch.chdir(str(repo))
eventlog.reset_announce_caches()
svc = LSPService(enabled=True, wait_mode="document", wait_timeout=2.0, install_strategy="manual")
try:
svc._mark_broken_for_file(str(src), RuntimeError("simulated"))
with caplog.at_level("INFO", logger=eventlog.event_log.name):
assert svc.get_diagnostics_sync(str(src)) == []
assert svc.get_diagnostics_sync(str(src)) == []
finally:
svc.shutdown()
skipped = [r for r in caplog.records if "marked broken" in r.getMessage()]
assert [r.levelname for r in skipped] == ["INFO"] # once per root; the repeat is DEBUG
assert str(repo) in skipped[0].getMessage() and "x.py" in skipped[0].getMessage()