fix: reduce excessive log volume by demoting per-request noise to DEBUG (#613)

Demote high-frequency per-request/per-item logs from INFO to DEBUG:
- 🔇 Client routing decisions (async_client.py) — logged every MCP tool call
- 🔇 DB migration checks (db.py) — logged every ASGI client creation
- 🔇 Vector table ensure/ready (sqlite + postgres search repos) — logged every search
- 🔇 Per-entity search index start/complete (search_service.py) — logged every file sync
- 🔇 Incremental scan details + per-file permalink updates (sync_service.py)
- 🔇 MCP search tool params and no-results (search.py)
- 📉 Log retention: "10 days" → 5 files (~50MB cap)

API v2 request/response logs remain at INFO for observability.

Closes #613

Co-Authored-By: Claude Opus 4.6 <noreply@anthropic.com>
Signed-off-by: phernandez <paul@basicmachines.co>

Author: phernandez

src/basic_memory/api/v2/routers/knowledge_router.py

@@ -130,7 +130,7 @@ async def resolve_identifier(
         resolution_method=resolution_method,
     )
 
-    logger.info(
+    logger.debug(
         f"API v2 response: resolved '{data.identifier}' to external_id={result.external_id} via {resolution_method}"
     )
 

src/basic_memory/db.py

@@ -475,7 +475,7 @@ async def run_migrations(
     Note: Alembic tracks which migrations have been applied via the alembic_version table,
     so it's safe to call this multiple times - it will only run pending migrations.
     """
-    logger.info("Running database migrations...")
+    logger.debug("Running database migrations...")
     temp_engine: AsyncEngine | None = None
     try:
         revisions_before_upgrade: set[str] = set()
@@ -514,7 +514,7 @@ async def run_migrations(
         config.set_main_option("sqlalchemy.url", db_url)
 
         command.upgrade(config, "head")
-        logger.info("Migrations completed successfully")
+        logger.debug("Migrations completed successfully")
 
         # Get session maker - ensure we don't trigger recursive migration calls
         if _session_maker is None:

src/basic_memory/mcp/async_client.py

@@ -154,13 +154,13 @@ async def get_client(
     # Outcome: route strictly based on explicit flag.
     if _explicit_routing():
         if _force_local_mode():
-            logger.info("Explicit local routing enabled - using ASGI client")
+            logger.debug("Explicit local routing enabled - using ASGI client")
             async with _asgi_client(timeout) as client:
                 yield client
             return
 
         if _force_cloud_mode():
-            logger.info("Explicit cloud routing enabled - using cloud proxy client")
+            logger.debug("Explicit cloud routing enabled - using cloud proxy client")
             async with _cloud_client(config, timeout, workspace=workspace) as client:
                 yield client
             return
@@ -172,7 +172,7 @@ async def get_client(
     if project_name is not None and not _explicit_routing():
         project_mode = config.get_project_mode(project_name)
         if project_mode == ProjectMode.CLOUD:
-            logger.info(f"Project '{project_name}' is cloud mode - using cloud proxy client")
+            logger.debug(f"Project '{project_name}' is cloud mode - using cloud proxy client")
             try:
                 async with _cloud_client(config, timeout, workspace=workspace) as client:
                     yield client
@@ -183,13 +183,13 @@ async def get_client(
                 ) from exc
             return
 
-        logger.info(f"Project '{project_name}' is local mode - using ASGI client")
+        logger.debug(f"Project '{project_name}' is local mode - using ASGI client")
         async with _asgi_client(timeout) as client:
             yield client
         return
 
     # --- Default fallback ---
-    logger.info("Default routing - using ASGI client for local Basic Memory API")
+    logger.debug("Default routing - using ASGI client for local Basic Memory API")
     async with _asgi_client(timeout) as client:
         yield client
 

src/basic_memory/mcp/tools/search.py

@@ -513,7 +513,7 @@ async def search_notes(
                     "`tags`, `status`, `note_types`, `entity_types`, or `after_date`."
                 )
 
-            logger.info(f"Searching for {search_query} in project {active_project.name}")
+            logger.debug(f"Searching for {search_query} in project {active_project.name}")
             # Import here to avoid circular import (tools → clients → utils → tools)
             from basic_memory.mcp.clients import SearchClient
 
@@ -527,7 +527,7 @@ async def search_notes(
 
             # Check if we got no results and provide helpful guidance
             if not result.results:
-                logger.info(
+                logger.debug(
                     f"Search returned no results for query: {query} in project {active_project.name}"
                 )
                 # Don't treat this as an error, but the user might want guidance

src/basic_memory/repository/postgres_search_repository.py

@@ -267,7 +267,7 @@ async def _ensure_vector_tables(self) -> None:
         if self._vector_tables_initialized:
             return
 
-        logger.info("Ensuring Postgres vector tables exist for semantic search")
+        logger.debug("Ensuring Postgres vector tables exist for semantic search")
 
         async with self._vector_tables_lock:
             if self._vector_tables_initialized:
@@ -358,7 +358,7 @@ async def _ensure_vector_tables(self) -> None:
                 )
                 await session.commit()
 
-            logger.info(f"Postgres vector tables ready (dimensions={self._vector_dimensions})")
+            logger.debug(f"Postgres vector tables ready (dimensions={self._vector_dimensions})")
             self._vector_tables_initialized = True
 
     async def _get_existing_embedding_dims(self, session: AsyncSession) -> int | None:

src/basic_memory/repository/sqlite_search_repository.py

@@ -79,7 +79,7 @@ async def init_search_index(self):
         across server restarts. Also creates vector tables when semantic search
         is enabled so missing dependencies are caught at startup, not first query.
         """
-        logger.info("Initializing SQLite FTS5 search index")
+        logger.debug("Initializing SQLite FTS5 search index")
         try:
             async with db.scoped_session(self.session_maker) as session:
                 # Create FTS5 virtual table if it doesn't exist
@@ -378,7 +378,7 @@ async def _ensure_vector_tables(self) -> None:
         if self._vector_tables_initialized:
             return
 
-        logger.info("Ensuring SQLite vector tables exist for semantic search")
+        logger.debug("Ensuring SQLite vector tables exist for semantic search")
 
         async with db.scoped_session(self.session_maker) as session:
             await self._ensure_sqlite_vec_loaded(session)
@@ -431,7 +431,7 @@ async def _ensure_vector_tables(self) -> None:
             await session.execute(create_sqlite_search_vector_embeddings(self._vector_dimensions))
             await session.commit()
 
-        logger.info(f"SQLite vector tables ready (dimensions={self._vector_dimensions})")
+        logger.debug(f"SQLite vector tables ready (dimensions={self._vector_dimensions})")
         self._vector_tables_initialized = True
 
     async def _prepare_vector_session(self, session: AsyncSession) -> None:

src/basic_memory/services/search_service.py

@@ -347,7 +347,7 @@ async def index_entity_data(
         entity: Entity,
         content: str | None = None,
     ) -> None:
-        logger.info(
+        logger.debug(
             f"[BackgroundTask] Starting search index for entity_id={entity.id} "
             f"permalink={entity.permalink} project_id={entity.project_id}"
         )
@@ -360,7 +360,7 @@ async def index_entity_data(
                 entity, content
             ) if entity.is_markdown else await self.index_entity_file(entity)
 
-            logger.info(
+            logger.debug(
                 f"[BackgroundTask] Completed search index for entity_id={entity.id} "
                 f"permalink={entity.permalink}"
             )

src/basic_memory/sync/sync_service.py

@@ -437,13 +437,13 @@ async def scan(self, directory, force_full: bool = False):
         elif project.last_scan_timestamp is not None:
             # Incremental scan: only files modified since last scan
             scan_type = "incremental"
-            logger.info(
+            logger.debug(
                 f"Running incremental scan for files modified since {project.last_scan_timestamp}"
             )
             file_paths_to_scan = await self._scan_directory_modified_since(
                 directory, project.last_scan_timestamp
             )
-            logger.info(
+            logger.debug(
                 f"Incremental scan found {len(file_paths_to_scan)} potentially changed files"
             )
 
@@ -705,7 +705,7 @@ async def sync_markdown_file(self, path: str, new: bool = True) -> Tuple[Optiona
 
             # If permalink changed, update the file
             if permalink != entity_markdown.frontmatter.permalink:
-                logger.info(
+                logger.debug(
                     f"Updating permalink for path: {path}, old_permalink: {entity_markdown.frontmatter.permalink}, new_permalink: {permalink}"
                 )
 

src/basic_memory/utils.py

@@ -281,7 +281,7 @@ def setup_logging(
             str(log_path),
             level=log_level,
             rotation="10 MB",
-            retention="10 days",
+            retention=5,
             backtrace=True,
             diagnose=True,
             enqueue=False,