feat: add failure-focused telemetry details

Signed-off-by: phernandez <paul@basicmachines.co>

Author: phernandez

docs/logfire-instrumentation-strategy.md

@@ -348,7 +348,7 @@ Avoid full automatic SQL span firehose by default.
 - [x] Phase 1: Bootstrap and config gating
 - [x] Phase 2: Root spans for entrypoints and primary operations
 - [x] Phase 3: Child spans for sync, search, and routing
-- [ ] Phase 4: Failure-focused detail and final verification
+- [x] Phase 4: Failure-focused detail and final verification
 
 ## Recommended Rollout Phases
 

src/basic_memory/mcp/async_client.py

@@ -5,6 +5,7 @@
 from httpx import ASGITransport, AsyncClient, Timeout
 from loguru import logger
 
+from basic_memory import telemetry
 from basic_memory.api.app import app as fastapi_app
 from basic_memory.config import ConfigManager, ProjectMode
 
@@ -43,21 +44,26 @@ def _asgi_client(timeout: Timeout) -> AsyncClient:
 
 async def _resolve_cloud_token(config) -> str:
     """Resolve cloud token with API key preferred, OAuth fallback."""
-    token = config.cloud_api_key
-    if token:
-        return token
-
-    from basic_memory.cli.auth import CLIAuth
-
-    auth = CLIAuth(client_id=config.cloud_client_id, authkit_domain=config.cloud_domain)
-    token = await auth.get_valid_token()
-    if token:
-        return token
-
-    raise RuntimeError(
-        "Cloud routing requested but no credentials found. "
-        "Run 'bm cloud api-key save <key>' or 'bm cloud login' first."
-    )
+    with telemetry.span(
+        "routing.resolve_cloud_credentials",
+        has_api_key=bool(config.cloud_api_key),
+    ):
+        token = config.cloud_api_key
+        if token:
+            return token
+
+        from basic_memory.cli.auth import CLIAuth
+
+        auth = CLIAuth(client_id=config.cloud_client_id, authkit_domain=config.cloud_domain)
+        token = await auth.get_valid_token()
+        if token:
+            return token
+
+        logger.error("Cloud routing requested but no credentials were available")
+        raise RuntimeError(
+            "Cloud routing requested but no credentials found. "
+            "Run 'bm cloud api-key save <key>' or 'bm cloud login' first."
+        )
 
 
 @asynccontextmanager

src/basic_memory/mcp/project_context.py

@@ -64,6 +64,27 @@ async def _resolve_default_project_from_api() -> Optional[str]:
     return None
 
 
+def _canonicalize_project_name(
+    project_name: Optional[str],
+    config: BasicMemoryConfig,
+) -> Optional[str]:
+    """Return the configured project name when the identifier matches by permalink.
+
+    Project routing happens before API validation, so we normalize explicit inputs
+    here to keep local/cloud routing aligned with the database's case-insensitive
+    project resolver.
+    """
+    if project_name is None:
+        return None
+
+    requested_permalink = generate_permalink(project_name)
+    for configured_name in config.projects:
+        if generate_permalink(configured_name) == requested_permalink:
+            return configured_name
+
+    return project_name
+
+
 async def resolve_project_parameter(
     project: Optional[str] = None,
     allow_discovery: bool = False,
@@ -95,11 +116,12 @@ async def resolve_project_parameter(
         requested_project=project,
         allow_discovery=allow_discovery,
     ):
+        config = ConfigManager().config
+
         # Load config for any values not explicitly provided.
         # ConfigManager reads from the local config file, which doesn't exist in cloud mode.
         # When it returns None, fall back to querying the projects API for the is_default flag.
         if default_project is None:
-            config = ConfigManager().config
             default_project = config.default_project
 
         if default_project is None:
@@ -110,7 +132,7 @@ async def resolve_project_parameter(
             default_project=default_project,
         )
         result = resolver.resolve(project=project, allow_discovery=allow_discovery)
-        return result.project
+        return _canonicalize_project_name(result.project, config)
 
 
 async def get_project_names(client: AsyncClient, headers: HeaderTypes | None = None) -> List[str]:

src/basic_memory/mcp/tools/write_note.py

@@ -250,7 +250,9 @@ async def write_note(
                                 title, entity.permalink, active_project.name
                             )
 
-                        logger.debug(f"Entity exists, updating instead permalink={entity.permalink}")
+                        logger.debug(
+                            f"Entity exists, updating instead permalink={entity.permalink}"
+                        )
                         try:
                             if not entity.permalink:
                                 raise ValueError(

src/basic_memory/sync/sync_service.py

@@ -37,6 +37,7 @@
 
 # Circuit breaker configuration
 MAX_CONSECUTIVE_FAILURES = 3
+SLOW_FILE_SYNC_WARNING_MS = 500
 
 
 @dataclass
@@ -650,12 +651,14 @@ async def sync_file(
             logger.warning(f"Skipping file due to repeated failures: {path}")
             return None, None
 
+        start_time = time.time()
+        is_markdown = self.file_service.is_markdown(path)
+        file_kind = "markdown" if is_markdown else "regular"
+
         try:
-            logger.debug(
-                f"Syncing file path={path} is_new={new} is_markdown={self.file_service.is_markdown(path)}"
-            )
+            logger.debug(f"Syncing file path={path} is_new={new} is_markdown={is_markdown}")
 
-            if self.file_service.is_markdown(path):
+            if is_markdown:
                 entity, checksum = await self.sync_markdown_file(path, new)
             else:
                 entity, checksum = await self.sync_regular_file(path, new)
@@ -680,33 +683,63 @@ async def sync_file(
                 logger.debug(
                     f"File sync completed, path={path}, entity_id={entity.id}, checksum={checksum[:8]}"
                 )
+            duration_ms = int((time.time() - start_time) * 1000)
+            if duration_ms >= SLOW_FILE_SYNC_WARNING_MS:
+                logger.warning(
+                    f"Slow file sync detected: path={path}, file_kind={file_kind}, duration_ms={duration_ms}"
+                )
             return entity, checksum
 
         except FileNotFoundError:
             # File exists in database but not on filesystem
             # This indicates a database/filesystem inconsistency - treat as deletion
-            logger.warning(
-                f"File not found during sync, treating as deletion: path={path}. "
-                "This may indicate a race condition or manual file deletion."
-            )
-            await self.handle_delete(path)
+            with telemetry.span(
+                "sync.file.failure",
+                failure_type="file_not_found",
+                path=path,
+                file_kind=file_kind,
+                is_new=new,
+                is_fatal=False,
+            ):
+                logger.warning(
+                    f"File not found during sync, treating as deletion: path={path}. "
+                    "This may indicate a race condition or manual file deletion."
+                )
+                await self.handle_delete(path)
             return None, None
 
         except Exception as e:
+            failure_type = type(e).__name__
             # Check if this is a fatal error (or caused by one)
             # Fatal errors like project deletion should terminate sync immediately
             if isinstance(e, SyncFatalError) or isinstance(
                 e.__cause__, SyncFatalError
             ):  # pragma: no cover
-                logger.error(f"Fatal sync error encountered, terminating sync: path={path}")
+                with telemetry.span(
+                    "sync.file.failure",
+                    failure_type=failure_type,
+                    path=path,
+                    file_kind=file_kind,
+                    is_new=new,
+                    is_fatal=True,
+                ):
+                    logger.error(f"Fatal sync error encountered, terminating sync: path={path}")
                 raise
 
             # Otherwise treat as recoverable file-level error
             error_msg = str(e)
-            logger.error(f"Failed to sync file: path={path}, error={error_msg}")
+            with telemetry.span(
+                "sync.file.failure",
+                failure_type=failure_type,
+                path=path,
+                file_kind=file_kind,
+                is_new=new,
+                is_fatal=False,
+            ):
+                logger.error(f"Failed to sync file: path={path}, error={error_msg}")
 
-            # Record failure for circuit breaker
-            await self._record_failure(path, error_msg)
+                # Record failure for circuit breaker
+                await self._record_failure(path, error_msg)
 
             return None, None
 
@@ -1100,24 +1133,36 @@ async def resolve_relations(self, entity_id: int | None = None):
                     # update search index only on successful resolution
                     await self.search_service.index_entity(resolved_entity)
                 except IntegrityError:
-                    # IntegrityError means a relation with this (from_id, to_id, relation_type)
-                    # already exists. The UPDATE was rolled back, so our unresolved relation
-                    # (to_id=NULL) still exists in the database. We delete it because:
-                    # 1. It's redundant - a resolved relation already captures this relationship
-                    # 2. If we don't delete it, future syncs will try to resolve it again
-                    #    and get the same IntegrityError
-                    logger.debug(
-                        "Deleting duplicate unresolved relation "
-                        f"relation_id={relation.id} "
-                        f"from_id={relation.from_id} "
-                        f"to_name={relation.to_name} "
-                        f"resolved_to_id={resolved_entity.id}"
-                    )
-                    try:
-                        await self.relation_repository.delete(relation.id)
-                    except Exception as e:
-                        # Log but don't fail - the relation may have been deleted already
-                        logger.debug(f"Could not delete duplicate relation {relation.id}: {e}")
+                    with telemetry.span(
+                        "sync.relation.resolve_conflict",
+                        relation_id=relation.id,
+                        relation_type=relation.relation_type,
+                    ):
+                        # IntegrityError means a relation with this (from_id, to_id, relation_type)
+                        # already exists. The UPDATE was rolled back, so our unresolved relation
+                        # (to_id=NULL) still exists in the database. We delete it because:
+                        # 1. It's redundant - a resolved version already captures this relationship
+                        # 2. If we don't delete it, future syncs will try to resolve it again
+                        #    and get the same IntegrityError
+                        logger.debug(
+                            "Deleting duplicate unresolved relation "
+                            f"relation_id={relation.id} "
+                            f"from_id={relation.from_id} "
+                            f"to_name={relation.to_name} "
+                            f"resolved_to_id={resolved_entity.id}"
+                        )
+                        try:
+                            await self.relation_repository.delete(relation.id)
+                        except Exception as e:
+                            with telemetry.span(
+                                "sync.relation.cleanup_failure",
+                                relation_id=relation.id,
+                                relation_type=relation.relation_type,
+                            ):
+                                # Log but don't fail - the relation may have been deleted already
+                                logger.debug(
+                                    f"Could not delete duplicate relation {relation.id}: {e}"
+                                )
 
     async def _quick_count_files(self, directory: Path) -> int:
         """Fast file count using find command.

tests/mcp/test_async_client_telemetry.py

@@ -0,0 +1,46 @@
+"""Telemetry coverage for async client auth failures."""
+
+from __future__ import annotations
+
+import importlib
+from contextlib import contextmanager
+from types import SimpleNamespace
+
+import pytest
+
+async_client_module = importlib.import_module("basic_memory.mcp.async_client")
+
+
+@pytest.mark.asyncio
+async def test_resolve_cloud_token_emits_failure_span(monkeypatch) -> None:
+    spans: list[tuple[str, dict]] = []
+    error_messages: list[str] = []
+
+    class FakeAuth:
+        def __init__(self, client_id: str, authkit_domain: str) -> None:
+            self.client_id = client_id
+            self.authkit_domain = authkit_domain
+
+        async def get_valid_token(self):
+            return None
+
+    @contextmanager
+    def fake_span(name: str, **attrs):
+        spans.append((name, attrs))
+        yield
+
+    monkeypatch.setattr(async_client_module.telemetry, "span", fake_span)
+    monkeypatch.setattr("basic_memory.cli.auth.CLIAuth", FakeAuth)
+    monkeypatch.setattr(async_client_module.logger, "error", error_messages.append)
+
+    config = SimpleNamespace(
+        cloud_api_key=None,
+        cloud_client_id="client-123",
+        cloud_domain="auth.example.com",
+    )
+
+    with pytest.raises(RuntimeError, match="no credentials found"):
+        await async_client_module._resolve_cloud_token(config)
+
+    assert spans == [("routing.resolve_cloud_credentials", {"has_api_key": False})]
+    assert error_messages == ["Cloud routing requested but no credentials were available"]

tests/mcp/test_project_context.py

@@ -94,6 +94,26 @@ async def test_uses_explicit_project_when_no_env(config_manager, monkeypatch):
     assert await resolve_project_parameter(project="explicit-project") == "explicit-project"
 
 
+@pytest.mark.asyncio
+async def test_canonicalizes_case_insensitive_project_reference(
+    config_manager, config_home, monkeypatch
+):
+    from basic_memory.config import ProjectEntry
+    from basic_memory.mcp.project_context import resolve_project_parameter
+
+    cfg = config_manager.load_config()
+    project_name = "Personal-Project"
+    project_path = config_home / "personal-project"
+    project_path.mkdir(parents=True, exist_ok=True)
+    cfg.projects[project_name] = ProjectEntry(path=str(project_path))
+    config_manager.save_config(cfg)
+
+    monkeypatch.delenv("BASIC_MEMORY_MCP_PROJECT", raising=False)
+
+    assert await resolve_project_parameter(project="personal-project") == project_name
+    assert await resolve_project_parameter(project="PERSONAL-PROJECT") == project_name
+
+
 @pytest.mark.asyncio
 async def test_uses_default_project(config_manager, config_home, monkeypatch):
     from basic_memory.mcp.project_context import resolve_project_parameter

tests/mcp/test_tool_telemetry.py

@@ -60,6 +60,10 @@ async def test_write_note_emits_root_operation_and_project_context(
         )
     ]
     assert contexts[0] == {
+        "route_mode": "local_asgi",
+        "workspace_id": None,
+    }
+    assert contexts[1] == {
         "project_name": test_project.name,
         "workspace_id": None,
         "tool_name": "write_note",
@@ -104,6 +108,10 @@ async def test_read_note_emits_root_operation_and_project_context(
         )
     ]
     assert contexts[0] == {
+        "route_mode": "local_asgi",
+        "workspace_id": None,
+    }
+    assert contexts[1] == {
         "project_name": test_project.name,
         "workspace_id": None,
         "tool_name": "read_note",
@@ -155,6 +163,10 @@ async def test_search_notes_emits_root_operation_and_project_context(
     )
     assert ("api.request.search",) == (operations[1][0],)
     assert contexts[0] == {
+        "route_mode": "local_asgi",
+        "workspace_id": None,
+    }
+    assert contexts[1] == {
         "project_name": test_project.name,
         "workspace_id": None,
         "tool_name": "search_notes",