fix(instrumentation): demote per-call and setup logs to debug

.cursor/BUGBOT.md

@@ -4,6 +4,22 @@
 
 - When adding a new instrumentation, the README must be updated to document the new instrumentation.
 
+## Logging Levels
+
+The SDK's default log level is `info` (see `drift/core/logger.py`). Customers initializing with `TuskDrift.initialize(env=...)` and no logger overrides will see every `logger.info(...)` line in their application output.
+
+**Rules:**
+
+1. **Per-call / per-request / per-query log lines MUST use `logger.debug(...)`, never `logger.info(...)`.** This includes anything inside a patched function body that runs on every invocation (e.g. `patched_connect`, middleware `__call__`, request hooks, cursor wrappers). One INFO line per DB connect or HTTP request floods customer logs and looks like a bug to them.
+
+2. **"X instrumented" startup lines MUST be `logger.debug(...)`.** The convention (see `drift/instrumentation/redis/instrumentation.py` and the sync paths in `drift/instrumentation/psycopg/instrumentation.py`) is debug. Even though these fire once per process, they appear in every customer's startup logs and read as internal SDK noise. Do not include the patched function's repr (`module.connect is now: ...`) at any level — it leaks implementation detail and confuses customers.
+
+3. **`logger.info(...)` is reserved for events the customer genuinely benefits from seeing once:** "App marked as ready", circuit-breaker state transitions, Rust-core enable/disable at startup, mode-change events. If the line can fire more than ~once per process lifetime in normal operation, it must be `debug`.
+
+4. **When adding a sibling instrumentation (e.g. psycopg2 alongside psycopg3), match the existing level conventions across both.** The psycopg2/psycopg3 split caused exactly this bug — psycopg3 used `debug` for "RECORD mode: Connected", psycopg2 used `info`, and customers saw 4 noise lines per connect.
+
+5. **Do not log raw header dicts, query args, or connection arguments at INFO** even once — these can be high-cardinality and contain sensitive values. Use `debug` and prefer logging only the keys, not values.
+
 ## REPLAY Mode: Context Ordering and OUTPUT_VALUE on Inbound Spans
 
 When implementing or modifying a REPLAY mode handler (e.g., `_handle_replay_request`) in any framework instrumentation (Django, FastAPI, Flask, WSGI, etc.):

drift/instrumentation/aiohttp/instrumentation.py

@@ -203,7 +203,7 @@ async def original_call():
 
         # Apply patch
         module.ClientSession._request = patched_request
-        logger.info("aiohttp.ClientSession._request instrumented")
+        logger.debug("aiohttp.ClientSession._request instrumented")
 
     async def _handle_replay_request(
         self,

drift/instrumentation/django/middleware.py

@@ -97,10 +97,10 @@ def _handle_replay_request(self, request: HttpRequest, sdk) -> HttpResponse:
         # Extract trace ID from headers (case-insensitive lookup)
         # Django stores headers in request.META
         headers_lower = {k.lower(): v for k, v in request.META.items() if k.startswith("HTTP_")}
-        logger.info(f"[DJANGO_MIDDLEWARE] REPLAY mode, headers: {list(headers_lower.keys())}")
+        logger.debug(f"[DJANGO_MIDDLEWARE] REPLAY mode, headers: {list(headers_lower.keys())}")
         # Convert HTTP_X_TD_TRACE_ID -> x-td-trace-id
         replay_trace_id = headers_lower.get("http_x_td_trace_id")
-        logger.info(f"[DJANGO_MIDDLEWARE] replay_trace_id from header: {replay_trace_id}")
+        logger.debug(f"[DJANGO_MIDDLEWARE] replay_trace_id from header: {replay_trace_id}")
 
         if not replay_trace_id:
             # No trace context in REPLAY mode; proceed without span

drift/instrumentation/grpc/instrumentation.py

@@ -94,7 +94,7 @@ def patch(self, module: Any) -> None:
         # to return instrumented channels
         self._patch_channel_factories(module)
 
-        logger.info("grpc module instrumented")
+        logger.debug("grpc module instrumented")
 
     def _patch_channel_factories(self, module: Any) -> None:
         """Patch channel factory functions to instrument created channels."""

drift/instrumentation/httpx/instrumentation.py

@@ -325,7 +325,7 @@ def original_call():
 
         # Apply patch
         module.Client.send = patched_send
-        logger.info("httpx.Client.send instrumented")
+        logger.debug("httpx.Client.send instrumented")
 
     def _handle_replay_send_sync(
         self,
@@ -518,7 +518,7 @@ async def original_call():
 
         # Apply patch
         module.AsyncClient.send = patched_send
-        logger.info("httpx.AsyncClient.send instrumented")
+        logger.debug("httpx.AsyncClient.send instrumented")
 
     async def _handle_replay_send_async(
         self,

drift/instrumentation/psycopg/instrumentation.py

@@ -90,10 +90,10 @@ def patched_connect(*args, **kwargs):
                     # Set server cursor factory on the connection for named cursors
                     if server_cursor_factory:
                         connection.server_cursor_factory = server_cursor_factory
-                    logger.info("[PATCHED_CONNECT] REPLAY mode: Successfully connected to database (psycopg3)")
+                    logger.debug("[PATCHED_CONNECT] REPLAY mode: Successfully connected to database (psycopg3)")
                     return connection
                 except Exception as e:
-                    logger.info(
+                    logger.debug(
                         f"[PATCHED_CONNECT] REPLAY mode: Database connection failed ({e}), using mock connection (psycopg3)"
                     )
                     # Return mock connection that doesn't require a real database
@@ -220,12 +220,12 @@ async def patched_async_connect(conninfo="", **kwargs):
                     if user_row_factory is not None:
                         kwargs["row_factory"] = user_row_factory
                     connection = await original_async_connect(conninfo, **kwargs)
-                    logger.info(
+                    logger.debug(
                         "[PATCHED_ASYNC_CONNECT] REPLAY mode: Successfully connected to database (psycopg3 async)"
                     )
                     return connection
                 except Exception as e:
-                    logger.info(
+                    logger.debug(
                         f"[PATCHED_ASYNC_CONNECT] REPLAY mode: Database connection failed ({e}), using mock async connection"
                     )
                     # Import mock async connection
@@ -245,7 +245,7 @@ async def patched_async_connect(conninfo="", **kwargs):
         AsyncConnection.connect = classmethod(
             lambda cls, conninfo="", **kwargs: patched_async_connect(conninfo, **kwargs)
         )
-        logger.info("psycopg.AsyncConnection.connect instrumented")
+        logger.debug("psycopg.AsyncConnection.connect instrumented")
 
         # Also patch AsyncConnectionPool to inject cursor_factory
         self._patch_async_connection_pool(module)
@@ -283,7 +283,7 @@ def patched_init(pool_self, conninfo="", **kwargs):
             return original_init(pool_self, conninfo, **kwargs)
 
         AsyncConnectionPool.__init__ = patched_init
-        logger.info("psycopg_pool.AsyncConnectionPool.__init__ instrumented")
+        logger.debug("psycopg_pool.AsyncConnectionPool.__init__ instrumented")
 
     def _create_async_cursor_factory(self, sdk: TuskDrift, base_factory=None):
         """Create an async cursor factory that wraps async cursors with instrumentation.

drift/instrumentation/psycopg2/instrumentation.py

@@ -390,7 +390,7 @@ def _unwrap_connection(conn_or_curs: Any) -> Any:
                     psycopg2.extras.register_default_jsonb = lambda *args, **kwargs: None
                 if original_register_uuid:
                     psycopg2.extras.register_uuid = lambda *args, **kwargs: None
-                logger.info("[PSYCOPG2_REPLAY] Patched psycopg2.extras register functions to be no-ops")
+                logger.debug("[PSYCOPG2_REPLAY] Patched psycopg2.extras register functions to be no-ops")
             else:
                 # In RECORD mode, unwrap InstrumentedConnection before calling original
                 if original_register_default_json:
@@ -422,16 +422,16 @@ def patched_register_uuid(oids: Any = None, conn_or_curs: Any = None) -> Any:
 
                     psycopg2.extras.register_uuid = patched_register_uuid
 
-                logger.info("[PSYCOPG2] Patched psycopg2.extras register functions to unwrap InstrumentedConnection")
+                logger.debug("[PSYCOPG2] Patched psycopg2.extras register functions to unwrap InstrumentedConnection")
         except Exception as e:
             logger.warning(f"[PSYCOPG2] Failed to patch psycopg2.extras: {e}")
 
         def patched_connect(*args, **kwargs):
             """Patched psycopg2.connect method."""
             sdk = TuskDrift.get_instance()
-            logger.info("[PATCHED_CONNECT] psycopg2.connect() called")
-            logger.info(f"[PATCHED_CONNECT]   mode: {sdk.mode}")
-            logger.info(f"[PATCHED_CONNECT]   app_ready: {sdk.app_ready}")
+            logger.debug("[PATCHED_CONNECT] psycopg2.connect() called")
+            logger.debug(f"[PATCHED_CONNECT]   mode: {sdk.mode}")
+            logger.debug(f"[PATCHED_CONNECT]   app_ready: {sdk.app_ready}")
             logger.debug(f"[PATCHED_CONNECT]   args: {args[:2] if args else 'none'}")
 
             # Pass through if SDK is disabled or original connect is missing
@@ -446,11 +446,11 @@ def patched_connect(*args, **kwargs):
                 try:
                     logger.debug("[PATCHED_CONNECT] REPLAY mode: Attempting real DB connection...")
                     connection = original_connect(*args, **kwargs)
-                    logger.info("[PATCHED_CONNECT] REPLAY mode: Successfully connected to real database")
+                    logger.debug("[PATCHED_CONNECT] REPLAY mode: Successfully connected to real database")
                     # Wrap connection to intercept cursor() calls
                     return InstrumentedConnection(connection, instrumentation, sdk)
                 except Exception as e:
-                    logger.info(
+                    logger.debug(
                         f"[PATCHED_CONNECT] REPLAY mode: Database connection failed ({e}), using mock connection"
                     )
                     # Return mock connection that doesn't require a real database
@@ -460,19 +460,19 @@ def patched_connect(*args, **kwargs):
             # In RECORD mode, always require real connection
             logger.debug("[PATCHED_CONNECT] RECORD mode: Connecting to database...")
             connection = original_connect(*args, **kwargs)
-            logger.info("[PATCHED_CONNECT] RECORD mode: Connected to database successfully")
+            logger.debug("[PATCHED_CONNECT] RECORD mode: Connected to database successfully")
             # Wrap connection to intercept cursor() calls
             return InstrumentedConnection(connection, instrumentation, sdk)
 
         # Apply patch
         module.connect = patched_connect  # type: ignore[attr-defined]
-        logger.info(f"psycopg2.connect instrumented. module.connect is now: {getattr(module, 'connect', None)}")
+        logger.debug("psycopg2.connect instrumented")
 
         # Also verify it's actually patched
         import psycopg2
 
         if psycopg2.connect == patched_connect:
-            logger.info("[VERIFY] psycopg2.connect successfully patched!")
+            logger.debug("[VERIFY] psycopg2.connect successfully patched!")
         else:
             logger.error(
                 f"[VERIFY] psycopg2.connect NOT patched! psycopg2.connect={psycopg2.connect}, patched_connect={patched_connect}"

drift/instrumentation/requests/instrumentation.py

@@ -154,7 +154,7 @@ def original_call():
 
         # Apply patch
         module.Session.send = patched_send
-        logger.info("requests.Session.send instrumented")
+        logger.debug("requests.Session.send instrumented")
 
     def _get_default_response(self, url: str) -> Any:
         """Return default response for background requests in REPLAY mode.

drift/instrumentation/urllib/instrumentation.py

@@ -378,7 +378,7 @@ def original_call():
 
         # Apply patch
         module.OpenerDirector.open = patched_open
-        logger.info("urllib.request.OpenerDirector.open instrumented")
+        logger.debug("urllib.request.OpenerDirector.open instrumented")
 
     def _extract_request_info(self, fullurl: Any, data: bytes | None) -> dict[str, Any]:
         """Extract request information from urlopen arguments.

drift/instrumentation/urllib3/instrumentation.py

@@ -218,7 +218,7 @@ def original_call():
                 calling_library_context.reset(context_token)
 
         module.PoolManager.urlopen = patched_urlopen
-        logger.info("urllib3.PoolManager.urlopen instrumented")
+        logger.debug("urllib3.PoolManager.urlopen instrumented")
 
     def _patch_connection_pool(self, module: Any) -> None:
         """Patch urllib3.HTTPConnectionPool.urlopen for direct pool usage."""
@@ -363,7 +363,7 @@ def original_call():
                 calling_library_context.reset(context_token)
 
         module.HTTPConnectionPool.urlopen = patched_urlopen
-        logger.info("urllib3.HTTPConnectionPool.urlopen instrumented")
+        logger.debug("urllib3.HTTPConnectionPool.urlopen instrumented")
 
     def _get_default_response(self, urllib3_module: Any, url: str) -> Any:
         """Return default response for background requests in REPLAY mode.