More lenient handling of loguru message mismatch and better warnings (#338)

Author: alexmojaki

logfire/_internal/config.py

@@ -76,7 +76,7 @@
 from .integrations.executors import instrument_executors
 from .metrics import ProxyMeterProvider, configure_metrics
 from .scrubbing import NOOP_SCRUBBER, BaseScrubber, Scrubber, ScrubbingOptions, ScrubCallback
-from .stack_info import get_user_frame_and_stacklevel
+from .stack_info import warn_at_user_stacklevel
 from .tracer import PendingSpanProcessor, ProxyTracerProvider
 from .utils import UnexpectedResponse, ensure_data_dir_exists, get_version, read_toml_file, suppress_instrumentation
 
@@ -801,12 +801,10 @@ def get_meter_provider(self) -> ProxyMeterProvider:
 
     def warn_if_not_initialized(self, message: str):
         if not self._initialized and not self.ignore_no_config:
-            _frame, stacklevel = get_user_frame_and_stacklevel()
-            warnings.warn(
+            warn_at_user_stacklevel(
                 f'{message} until `logfire.configure()` has been called. '
                 f'Set the environment variable LOGFIRE_IGNORE_NO_CONFIG=1 or add ignore_no_config=true in pyproject.toml to suppress this warning.',
                 category=LogfireNotConfiguredWarning,
-                stacklevel=stacklevel,
             )
 
     @cached_property

logfire/_internal/formatter.py

@@ -14,10 +14,10 @@
 from typing_extensions import NotRequired, TypedDict
 
 import logfire
-from logfire._internal.stack_info import get_user_frame_and_stacklevel
 
 from .constants import ATTRIBUTES_SCRUBBED_KEY, MESSAGE_FORMATTED_VALUE_LENGTH_LIMIT
 from .scrubbing import NOOP_SCRUBBER, BaseScrubber, ScrubbedNote
+from .stack_info import warn_at_user_stacklevel
 from .utils import log_internal_error, truncate_string
 
 
@@ -466,14 +466,12 @@ class FormattingFailedWarning(UserWarning):
 
 
 def warn_formatting(msg: str):
-    _frame, stacklevel = get_user_frame_and_stacklevel()
-    warnings.warn(
+    warn_at_user_stacklevel(
         f'\n'
         f'    Ensure you are either:\n'
         '      (1) passing an f-string directly, with inspect_arguments enabled and working, or\n'
         '      (2) passing a literal `str.format`-style template, not a preformatted string.\n'
         '    See https://docs.pydantic.dev/logfire/guides/onboarding_checklist/add_manual_tracing/#messages-and-span-names.\n'
         f'    The problem was: {msg}',
-        stacklevel=stacklevel,
         category=FormattingFailedWarning,
     )

logfire/_internal/stack_info.py

@@ -2,6 +2,7 @@
 
 import inspect
 import sys
+import warnings
 from functools import lru_cache
 from pathlib import Path
 from types import CodeType, FrameType
@@ -97,3 +98,8 @@ def is_user_code(code: CodeType) -> bool:
         str(Path(code.co_filename).absolute()).startswith(PREFIXES)
         or code.co_name in ('<listcomp>', '<dictcomp>', '<setcomp>')
     )
+
+
+def warn_at_user_stacklevel(msg: str, category: type[Warning]):
+    _frame, stacklevel = get_user_frame_and_stacklevel()
+    warnings.warn(msg, stacklevel=stacklevel, category=category)

logfire/integrations/loguru.py

@@ -3,15 +3,25 @@
 from __future__ import annotations
 
 import inspect
-import warnings
 from logging import LogRecord
+from pathlib import Path
 from typing import Any
 
-from loguru import logger
+import loguru
 
 from .._internal.constants import ATTRIBUTES_LOGGING_ARGS_KEY, ATTRIBUTES_MESSAGE_KEY, ATTRIBUTES_MESSAGE_TEMPLATE_KEY
+from .._internal.stack_info import warn_at_user_stacklevel
 from .logging import LogfireLoggingHandler
 
+LOGURU_PATH = Path(loguru.__file__).parent
+
+
+class LoguruInspectionFailed(RuntimeWarning):
+    """Warning raised when magic introspection of loguru stack frames fails.
+
+    This may happen if the loguru library changes in a way that breaks the introspection.
+    """
+
 
 class LogfireHandler(LogfireLoggingHandler):
     """A loguru handler that sends logs to **Logfire**."""
@@ -38,51 +48,49 @@ def fill_attributes(self, record: LogRecord) -> dict[str, Any]:
             while frame:  # pragma: no branch
                 if frame.f_code is _LOG_METHOD_CODE:
                     frame_locals = frame.f_locals
-                    if 'message' in frame_locals:
+                    if 'message' in frame_locals:  # pragma: no branch
                         attributes[ATTRIBUTES_MESSAGE_TEMPLATE_KEY] = frame_locals['message']
                     else:  # pragma: no cover
-                        _warn_inspection_failure()
+                        warn_at_user_stacklevel(
+                            'Failed to extract message template (span name) for loguru log.', LoguruInspectionFailed
+                        )
 
                     args = frame_locals.get('args')
-                    if isinstance(args, (tuple, list)):
+                    if isinstance(args, (tuple, list)):  # pragma: no branch
                         if args:
                             attributes[ATTRIBUTES_LOGGING_ARGS_KEY] = args
                     else:  # pragma: no cover
-                        _warn_inspection_failure()
-
-                    if record.exc_info:
-                        original_record = frame_locals.get('log_record')
-                        if isinstance(original_record, dict):
-                            message = original_record.get('message')  # type: ignore
-                            if isinstance(message, str) and record.msg.startswith(
-                                message + '\nTraceback (most recent call last):'
-                            ):
-                                # `record.msg` includes a traceback added by Loguru,
-                                # replace it with the original message.
-                                attributes[ATTRIBUTES_MESSAGE_KEY] = message
-                            else:  # pragma: no cover
-                                _warn_inspection_failure()
-                        else:  # pragma: no cover
-                            _warn_inspection_failure()
+                        warn_at_user_stacklevel('Failed to extract args for loguru log.', LoguruInspectionFailed)
+
+                    original_record: dict[str, Any] | None = frame_locals.get('log_record')
+                    if (
+                        isinstance(original_record, dict)
+                        and isinstance(message := original_record.get('message'), str)
+                        and message in record.msg
+                    ):  # pragma: no branch
+                        # `record.msg` may include a traceback added by Loguru,
+                        # replace it with the original message.
+                        attributes[ATTRIBUTES_MESSAGE_KEY] = message
+                    else:  # pragma: no cover
+                        warn_at_user_stacklevel(
+                            'Failed to extract original message for loguru log.', LoguruInspectionFailed
+                        )
 
                     break
 
                 frame = frame.f_back
+            else:  # pragma: no cover
+                warn_at_user_stacklevel(
+                    'Failed to find loguru log frame to extract detailed information', LoguruInspectionFailed
+                )
 
         return attributes
 
 
-def _warn_inspection_failure() -> None:  # pragma: no cover
-    warnings.warn(
-        'Failed to extract info from loguru logger. '
-        'This may affect span names and/or positional arguments. '
-        'Please report an issue to logfire.',
-        RuntimeWarning,
-    )
-
-
 try:
-    _LOG_METHOD_CODE = inspect.unwrap(type(logger)._log).__code__  # type: ignore
+    _LOG_METHOD_CODE = inspect.unwrap(type(loguru.logger)._log).__code__  # type: ignore
 except Exception:  # pragma: no cover
     _LOG_METHOD_CODE = None  # type: ignore
-    _warn_inspection_failure()
+    warn_at_user_stacklevel(
+        'Failed to find loguru log method code to extract detailed information', LoguruInspectionFailed
+    )