diff --git a/CHANGELOG.md b/CHANGELOG.md index 8d73e1bdd0..8dd7763121 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -122,7 +122,7 @@ sentry_sdk.init( dsn="...", _experiments={ - "enable_sentry_logs": True + "enable_logs": True } integrations=[ LoggingIntegration(sentry_logs_level=logging.ERROR), diff --git a/sentry_sdk/integrations/logging.py b/sentry_sdk/integrations/logging.py index dddcc17334..756a35a900 100644 --- a/sentry_sdk/integrations/logging.py +++ b/sentry_sdk/integrations/logging.py @@ -5,6 +5,7 @@ import sentry_sdk from sentry_sdk.client import BaseClient +from sentry_sdk.logger import _log_level_to_otel from sentry_sdk.utils import ( safe_repr, to_string, @@ -14,7 +15,7 @@ ) from sentry_sdk.integrations import Integration -from typing import TYPE_CHECKING, Tuple +from typing import TYPE_CHECKING if TYPE_CHECKING: from collections.abc import MutableMapping @@ -36,6 +37,16 @@ logging.CRITICAL: "fatal", # CRITICAL is same as FATAL } +# Map logging level numbers to corresponding OTel level numbers +SEVERITY_TO_OTEL_SEVERITY = { + logging.CRITICAL: 21, # fatal + logging.ERROR: 17, # error + logging.WARNING: 13, # warn + logging.INFO: 9, # info + logging.DEBUG: 5, # debug +} + + # Capturing events from those loggers causes recursion errors. We cannot allow # the user to unconditionally create events from those loggers under any # circumstances. @@ -312,21 +323,6 @@ def _breadcrumb_from_record(self, record): } -def _python_level_to_otel(record_level): - # type: (int) -> Tuple[int, str] - for py_level, otel_severity_number, otel_severity_text in [ - (50, 21, "fatal"), - (40, 17, "error"), - (30, 13, "warn"), - (20, 9, "info"), - (10, 5, "debug"), - (5, 1, "trace"), - ]: - if record_level >= py_level: - return otel_severity_number, otel_severity_text - return 0, "default" - - class SentryLogsHandler(_BaseHandler): """ A logging handler that records Sentry logs for each Python log record. @@ -352,7 +348,9 @@ def emit(self, record): def _capture_log_from_record(self, client, record): # type: (BaseClient, LogRecord) -> None - otel_severity_number, otel_severity_text = _python_level_to_otel(record.levelno) + otel_severity_number, otel_severity_text = _log_level_to_otel( + record.levelno, SEVERITY_TO_OTEL_SEVERITY + ) project_root = client.options["project_root"] attrs = self._extra_from_record(record) # type: Any attrs["sentry.origin"] = "auto.logger.log" @@ -363,10 +361,7 @@ def _capture_log_from_record(self, client, record): for i, arg in enumerate(record.args): attrs[f"sentry.message.parameter.{i}"] = ( arg - if isinstance(arg, str) - or isinstance(arg, float) - or isinstance(arg, int) - or isinstance(arg, bool) + if isinstance(arg, (str, float, int, bool)) else safe_repr(arg) ) if record.lineno: diff --git a/sentry_sdk/integrations/loguru.py b/sentry_sdk/integrations/loguru.py index a71c4ac87f..df3ecf161a 100644 --- a/sentry_sdk/integrations/loguru.py +++ b/sentry_sdk/integrations/loguru.py @@ -1,22 +1,27 @@ import enum +import sentry_sdk from sentry_sdk.integrations import Integration, DidNotEnable from sentry_sdk.integrations.logging import ( BreadcrumbHandler, EventHandler, _BaseHandler, ) +from sentry_sdk.logger import _log_level_to_otel from typing import TYPE_CHECKING if TYPE_CHECKING: from logging import LogRecord - from typing import Optional, Any + from typing import Any, Optional try: import loguru from loguru import logger from loguru._defaults import LOGURU_FORMAT as DEFAULT_FORMAT + + if TYPE_CHECKING: + from loguru import Message except ImportError: raise DidNotEnable("LOGURU is not installed") @@ -31,6 +36,10 @@ class LoggingLevels(enum.IntEnum): CRITICAL = 50 +DEFAULT_LEVEL = LoggingLevels.INFO.value +DEFAULT_EVENT_LEVEL = LoggingLevels.ERROR.value + + SENTRY_LEVEL_FROM_LOGURU_LEVEL = { "TRACE": "DEBUG", "DEBUG": "DEBUG", @@ -41,8 +50,16 @@ class LoggingLevels(enum.IntEnum): "CRITICAL": "CRITICAL", } -DEFAULT_LEVEL = LoggingLevels.INFO.value -DEFAULT_EVENT_LEVEL = LoggingLevels.ERROR.value +# Map Loguru level numbers to corresponding OTel level numbers +SEVERITY_TO_OTEL_SEVERITY = { + LoggingLevels.CRITICAL: 21, # fatal + LoggingLevels.ERROR: 17, # error + LoggingLevels.WARNING: 13, # warn + LoggingLevels.SUCCESS: 11, # info + LoggingLevels.INFO: 9, # info + LoggingLevels.DEBUG: 5, # debug + LoggingLevels.TRACE: 1, # trace +} class LoguruIntegration(Integration): @@ -52,6 +69,7 @@ class LoguruIntegration(Integration): event_level = DEFAULT_EVENT_LEVEL # type: Optional[int] breadcrumb_format = DEFAULT_FORMAT event_format = DEFAULT_FORMAT + sentry_logs_level = DEFAULT_LEVEL # type: Optional[int] def __init__( self, @@ -59,12 +77,14 @@ def __init__( event_level=DEFAULT_EVENT_LEVEL, breadcrumb_format=DEFAULT_FORMAT, event_format=DEFAULT_FORMAT, + sentry_logs_level=DEFAULT_LEVEL, ): - # type: (Optional[int], Optional[int], str | loguru.FormatFunction, str | loguru.FormatFunction) -> None + # type: (Optional[int], Optional[int], str | loguru.FormatFunction, str | loguru.FormatFunction, Optional[int]) -> None LoguruIntegration.level = level LoguruIntegration.event_level = event_level LoguruIntegration.breadcrumb_format = breadcrumb_format LoguruIntegration.event_format = event_format + LoguruIntegration.sentry_logs_level = sentry_logs_level @staticmethod def setup_once(): @@ -83,8 +103,23 @@ def setup_once(): format=LoguruIntegration.event_format, ) + if LoguruIntegration.sentry_logs_level is not None: + logger.add( + loguru_sentry_logs_handler, + level=LoguruIntegration.sentry_logs_level, + ) + class _LoguruBaseHandler(_BaseHandler): + def __init__(self, *args, **kwargs): + # type: (*Any, **Any) -> None + if kwargs.get("level"): + kwargs["level"] = SENTRY_LEVEL_FROM_LOGURU_LEVEL.get( + kwargs.get("level", ""), DEFAULT_LEVEL + ) + + super().__init__(*args, **kwargs) + def _logging_to_event_level(self, record): # type: (LogRecord) -> str try: @@ -98,24 +133,72 @@ def _logging_to_event_level(self, record): class LoguruEventHandler(_LoguruBaseHandler, EventHandler): """Modified version of :class:`sentry_sdk.integrations.logging.EventHandler` to use loguru's level names.""" - def __init__(self, *args, **kwargs): - # type: (*Any, **Any) -> None - if kwargs.get("level"): - kwargs["level"] = SENTRY_LEVEL_FROM_LOGURU_LEVEL.get( - kwargs.get("level", ""), DEFAULT_LEVEL - ) - - super().__init__(*args, **kwargs) + pass class LoguruBreadcrumbHandler(_LoguruBaseHandler, BreadcrumbHandler): """Modified version of :class:`sentry_sdk.integrations.logging.BreadcrumbHandler` to use loguru's level names.""" - def __init__(self, *args, **kwargs): - # type: (*Any, **Any) -> None - if kwargs.get("level"): - kwargs["level"] = SENTRY_LEVEL_FROM_LOGURU_LEVEL.get( - kwargs.get("level", ""), DEFAULT_LEVEL - ) + pass - super().__init__(*args, **kwargs) + +def loguru_sentry_logs_handler(message): + # type: (Message) -> None + # This is intentionally a callable sink instead of a standard logging handler + # since otherwise we wouldn't get direct access to message.record + client = sentry_sdk.get_client() + + if not client.is_active(): + return + + if not client.options["_experiments"].get("enable_logs", False): + return + + record = message.record + + if ( + LoguruIntegration.sentry_logs_level is None + or record["level"].no < LoguruIntegration.sentry_logs_level + ): + return + + otel_severity_number, otel_severity_text = _log_level_to_otel( + record["level"].no, SEVERITY_TO_OTEL_SEVERITY + ) + + attrs = {"sentry.origin": "auto.logger.loguru"} # type: dict[str, Any] + + project_root = client.options["project_root"] + if record.get("file"): + if project_root is not None and record["file"].path.startswith(project_root): + attrs["code.file.path"] = record["file"].path[len(project_root) + 1 :] + else: + attrs["code.file.path"] = record["file"].path + + if record.get("line") is not None: + attrs["code.line.number"] = record["line"] + + if record.get("function"): + attrs["code.function.name"] = record["function"] + + if record.get("thread"): + attrs["thread.name"] = record["thread"].name + attrs["thread.id"] = record["thread"].id + + if record.get("process"): + attrs["process.pid"] = record["process"].id + attrs["process.executable.name"] = record["process"].name + + if record.get("name"): + attrs["logger.name"] = record["name"] + + client._capture_experimental_log( + { + "severity_text": otel_severity_text, + "severity_number": otel_severity_number, + "body": record["message"], + "attributes": attrs, + "time_unix_nano": int(record["time"].timestamp() * 1e9), + "trace_id": None, + } + ) diff --git a/sentry_sdk/logger.py b/sentry_sdk/logger.py index 2f5e859533..c18cf91ff2 100644 --- a/sentry_sdk/logger.py +++ b/sentry_sdk/logger.py @@ -6,6 +6,17 @@ from sentry_sdk import get_client from sentry_sdk.utils import safe_repr +OTEL_RANGES = [ + # ((severity level range), severity text) + # https://opentelemetry.io/docs/specs/otel/logs/data-model + ((1, 4), "trace"), + ((5, 8), "debug"), + ((9, 12), "info"), + ((13, 16), "warn"), + ((17, 20), "error"), + ((21, 24), "fatal"), +] + def _capture_log(severity_text, severity_number, template, **kwargs): # type: (str, int, str, **Any) -> None @@ -52,3 +63,21 @@ def _capture_log(severity_text, severity_number, template, **kwargs): warning = functools.partial(_capture_log, "warn", 13) error = functools.partial(_capture_log, "error", 17) fatal = functools.partial(_capture_log, "fatal", 21) + + +def _otel_severity_text(otel_severity_number): + # type: (int) -> str + for (lower, upper), severity in OTEL_RANGES: + if lower <= otel_severity_number <= upper: + return severity + + return "default" + + +def _log_level_to_otel(level, mapping): + # type: (int, dict[Any, int]) -> tuple[int, str] + for py_level, otel_severity_number in sorted(mapping.items(), reverse=True): + if level >= py_level: + return otel_severity_number, _otel_severity_text(otel_severity_number) + + return 0, "default" diff --git a/tests/integrations/logging/test_logging.py b/tests/integrations/logging/test_logging.py index c08e960c00..656ac38963 100644 --- a/tests/integrations/logging/test_logging.py +++ b/tests/integrations/logging/test_logging.py @@ -3,7 +3,10 @@ import pytest +from sentry_sdk import get_client +from sentry_sdk.consts import VERSION from sentry_sdk.integrations.logging import LoggingIntegration, ignore_logger +from tests.test_logs import envelopes_to_logs other_logger = logging.getLogger("testfoo") logger = logging.getLogger(__name__) @@ -283,3 +286,197 @@ def test_logging_dictionary_args(sentry_init, capture_events): == "the value of foo is bar, and the value of bar is baz" ) assert event["logentry"]["params"] == {"foo": "bar", "bar": "baz"} + + +def test_sentry_logs_warning(sentry_init, capture_envelopes): + """ + The python logger module should create 'warn' sentry logs if the flag is on. + """ + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + python_logger = logging.Logger("test-logger") + python_logger.warning("this is %s a template %s", "1", "2") + + get_client().flush() + logs = envelopes_to_logs(envelopes) + attrs = logs[0]["attributes"] + assert attrs["sentry.message.template"] == "this is %s a template %s" + assert "code.file.path" in attrs + assert "code.line.number" in attrs + assert attrs["logger.name"] == "test-logger" + assert attrs["sentry.environment"] == "production" + assert attrs["sentry.message.parameter.0"] == "1" + assert attrs["sentry.message.parameter.1"] == "2" + assert attrs["sentry.origin"] == "auto.logger.log" + assert logs[0]["severity_number"] == 13 + assert logs[0]["severity_text"] == "warn" + + +def test_sentry_logs_debug(sentry_init, capture_envelopes): + """ + The python logger module should not create 'debug' sentry logs if the flag is on by default + """ + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + python_logger = logging.Logger("test-logger") + python_logger.debug("this is %s a template %s", "1", "2") + get_client().flush() + + assert len(envelopes) == 0 + + +def test_no_log_infinite_loop(sentry_init, capture_envelopes): + """ + If 'debug' mode is true, and you set a low log level in the logging integration, there should be no infinite loops. + """ + sentry_init( + _experiments={"enable_logs": True}, + integrations=[LoggingIntegration(sentry_logs_level=logging.DEBUG)], + debug=True, + ) + envelopes = capture_envelopes() + + python_logger = logging.Logger("test-logger") + python_logger.debug("this is %s a template %s", "1", "2") + get_client().flush() + + assert len(envelopes) == 1 + + +def test_logging_errors(sentry_init, capture_envelopes): + """ + The python logger module should be able to log errors without erroring + """ + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + python_logger = logging.Logger("test-logger") + python_logger.error(Exception("test exc 1")) + python_logger.error("error is %s", Exception("test exc 2")) + get_client().flush() + + error_event_1 = envelopes[0].items[0].payload.json + assert error_event_1["level"] == "error" + error_event_2 = envelopes[1].items[0].payload.json + assert error_event_2["level"] == "error" + + logs = envelopes_to_logs(envelopes) + assert logs[0]["severity_text"] == "error" + assert "sentry.message.template" not in logs[0]["attributes"] + assert "sentry.message.parameter.0" not in logs[0]["attributes"] + assert "code.line.number" in logs[0]["attributes"] + + assert logs[1]["severity_text"] == "error" + assert logs[1]["attributes"]["sentry.message.template"] == "error is %s" + assert logs[1]["attributes"]["sentry.message.parameter.0"] in ( + "Exception('test exc 2')", + "Exception('test exc 2',)", # py3.6 + ) + assert "code.line.number" in logs[1]["attributes"] + + assert len(logs) == 2 + + +def test_log_strips_project_root(sentry_init, capture_envelopes): + """ + The python logger should strip project roots from the log record path + """ + sentry_init( + _experiments={"enable_logs": True}, + project_root="/custom/test", + ) + envelopes = capture_envelopes() + + python_logger = logging.Logger("test-logger") + python_logger.handle( + logging.LogRecord( + name="test-logger", + level=logging.WARN, + pathname="/custom/test/blah/path.py", + lineno=123, + msg="This is a test log with a custom pathname", + args=(), + exc_info=None, + ) + ) + get_client().flush() + + logs = envelopes_to_logs(envelopes) + assert len(logs) == 1 + attrs = logs[0]["attributes"] + assert attrs["code.file.path"] == "blah/path.py" + + +def test_logger_with_all_attributes(sentry_init, capture_envelopes): + """ + The python logger should be able to log all attributes, including extra data. + """ + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + python_logger = logging.Logger("test-logger") + python_logger.warning( + "log #%d", + 1, + extra={"foo": "bar", "numeric": 42, "more_complex": {"nested": "data"}}, + ) + get_client().flush() + + logs = envelopes_to_logs(envelopes) + + attributes = logs[0]["attributes"] + + assert "process.pid" in attributes + assert isinstance(attributes["process.pid"], int) + del attributes["process.pid"] + + assert "sentry.release" in attributes + assert isinstance(attributes["sentry.release"], str) + del attributes["sentry.release"] + + assert "server.address" in attributes + assert isinstance(attributes["server.address"], str) + del attributes["server.address"] + + assert "thread.id" in attributes + assert isinstance(attributes["thread.id"], int) + del attributes["thread.id"] + + assert "code.file.path" in attributes + assert isinstance(attributes["code.file.path"], str) + del attributes["code.file.path"] + + assert "code.function.name" in attributes + assert isinstance(attributes["code.function.name"], str) + del attributes["code.function.name"] + + assert "code.line.number" in attributes + assert isinstance(attributes["code.line.number"], int) + del attributes["code.line.number"] + + assert "process.executable.name" in attributes + assert isinstance(attributes["process.executable.name"], str) + del attributes["process.executable.name"] + + assert "thread.name" in attributes + assert isinstance(attributes["thread.name"], str) + del attributes["thread.name"] + + assert attributes.pop("sentry.sdk.name").startswith("sentry.python") + + # Assert on the remaining non-dynamic attributes. + assert attributes == { + "foo": "bar", + "numeric": 42, + "more_complex": "{'nested': 'data'}", + "logger.name": "test-logger", + "sentry.origin": "auto.logger.log", + "sentry.message.template": "log #%d", + "sentry.message.parameter.0": 1, + "sentry.environment": "production", + "sentry.sdk.version": VERSION, + "sentry.severity_number": 13, + "sentry.severity_text": "warn", + } diff --git a/tests/integrations/loguru/test_loguru.py b/tests/integrations/loguru/test_loguru.py index 6be09b86dc..20d3230b49 100644 --- a/tests/integrations/loguru/test_loguru.py +++ b/tests/integrations/loguru/test_loguru.py @@ -1,8 +1,13 @@ +from unittest.mock import MagicMock, patch + import pytest from loguru import logger +from loguru._recattrs import RecordFile, RecordLevel import sentry_sdk +from sentry_sdk.consts import VERSION from sentry_sdk.integrations.loguru import LoguruIntegration, LoggingLevels +from tests.test_logs import envelopes_to_logs logger.remove(0) # don't print to console @@ -54,7 +59,7 @@ def test_just_log( formatted_message = ( " | " + "{:9}".format(level.name.upper()) - + "| tests.integrations.loguru.test_loguru:test_just_log:52 - test" + + "| tests.integrations.loguru.test_loguru:test_just_log:57 - test" ) if not created_event: @@ -127,3 +132,337 @@ def test_event_format(sentry_init, capture_events, uninstall_integration, reques (event,) = events assert event["logentry"]["message"] == formatted_message + + +def test_sentry_logs_warning( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + logger.warning("this is {} a {}", "just", "template") + + sentry_sdk.get_client().flush() + logs = envelopes_to_logs(envelopes) + + attrs = logs[0]["attributes"] + assert "code.file.path" in attrs + assert "code.line.number" in attrs + assert attrs["logger.name"] == "tests.integrations.loguru.test_loguru" + assert attrs["sentry.environment"] == "production" + assert attrs["sentry.origin"] == "auto.logger.loguru" + assert logs[0]["severity_number"] == 13 + assert logs[0]["severity_text"] == "warn" + + +def test_sentry_logs_debug( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + logger.debug("this is %s a template %s", "1", "2") + sentry_sdk.get_client().flush() + + assert len(envelopes) == 0 + + +def test_sentry_log_levels( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init( + integrations=[LoguruIntegration(sentry_logs_level=LoggingLevels.SUCCESS)], + _experiments={"enable_logs": True}, + ) + envelopes = capture_envelopes() + + logger.trace("this is a log") + logger.debug("this is a log") + logger.info("this is a log") + logger.success("this is a log") + logger.warning("this is a log") + logger.error("this is a log") + logger.critical("this is a log") + + sentry_sdk.get_client().flush() + logs = envelopes_to_logs(envelopes) + assert len(logs) == 4 + + assert logs[0]["severity_number"] == 11 + assert logs[0]["severity_text"] == "info" + assert logs[1]["severity_number"] == 13 + assert logs[1]["severity_text"] == "warn" + assert logs[2]["severity_number"] == 17 + assert logs[2]["severity_text"] == "error" + assert logs[3]["severity_number"] == 21 + assert logs[3]["severity_text"] == "fatal" + + +def test_disable_loguru_logs( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init( + integrations=[LoguruIntegration(sentry_logs_level=None)], + _experiments={"enable_logs": True}, + ) + envelopes = capture_envelopes() + + logger.trace("this is a log") + logger.debug("this is a log") + logger.info("this is a log") + logger.success("this is a log") + logger.warning("this is a log") + logger.error("this is a log") + logger.critical("this is a log") + + sentry_sdk.get_client().flush() + logs = envelopes_to_logs(envelopes) + assert len(logs) == 0 + + +def test_disable_sentry_logs( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init( + _experiments={"enable_logs": False}, + ) + envelopes = capture_envelopes() + + logger.trace("this is a log") + logger.debug("this is a log") + logger.info("this is a log") + logger.success("this is a log") + logger.warning("this is a log") + logger.error("this is a log") + logger.critical("this is a log") + + sentry_sdk.get_client().flush() + logs = envelopes_to_logs(envelopes) + assert len(logs) == 0 + + +def test_no_log_infinite_loop( + sentry_init, capture_envelopes, uninstall_integration, request +): + """ + In debug mode, there should be no infinite loops even when a low log level is set. + """ + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init( + _experiments={"enable_logs": True}, + integrations=[LoguruIntegration(sentry_logs_level=LoggingLevels.DEBUG)], + debug=True, + ) + envelopes = capture_envelopes() + + logger.debug("this is %s a template %s", "1", "2") + sentry_sdk.get_client().flush() + + assert len(envelopes) == 1 + + +def test_logging_errors(sentry_init, capture_envelopes, uninstall_integration, request): + """We're able to log errors without erroring.""" + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + logger.error(Exception("test exc 1")) + logger.error("error is %s", Exception("test exc 2")) + sentry_sdk.get_client().flush() + + error_event_1 = envelopes[0].items[0].payload.json + assert error_event_1["level"] == "error" + error_event_2 = envelopes[1].items[0].payload.json + assert error_event_2["level"] == "error" + + logs = envelopes_to_logs(envelopes) + assert logs[0]["severity_text"] == "error" + assert "code.line.number" in logs[0]["attributes"] + + assert logs[1]["severity_text"] == "error" + assert "code.line.number" in logs[1]["attributes"] + + assert len(logs) == 2 + + +def test_log_strips_project_root( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init( + _experiments={"enable_logs": True}, + project_root="/custom/test", + ) + envelopes = capture_envelopes() + + class FakeMessage: + def __init__(self, *args, **kwargs): + pass + + @property + def record(self): + return { + "elapsed": MagicMock(), + "exception": None, + "file": RecordFile(name="app.py", path="/custom/test/blah/path.py"), + "function": "", + "level": RecordLevel(name="ERROR", no=20, icon=""), + "line": 35, + "message": "some message", + "module": "app", + "name": "__main__", + "process": MagicMock(), + "thread": MagicMock(), + "time": MagicMock(), + "extra": MagicMock(), + } + + @record.setter + def record(self, val): + pass + + with patch("loguru._handler.Message", FakeMessage): + logger.error("some message") + + sentry_sdk.get_client().flush() + + logs = envelopes_to_logs(envelopes) + assert len(logs) == 1 + attrs = logs[0]["attributes"] + assert attrs["code.file.path"] == "blah/path.py" + + +def test_log_keeps_full_path_if_not_in_project_root( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init( + _experiments={"enable_logs": True}, + project_root="/custom/test", + ) + envelopes = capture_envelopes() + + class FakeMessage: + def __init__(self, *args, **kwargs): + pass + + @property + def record(self): + return { + "elapsed": MagicMock(), + "exception": None, + "file": RecordFile(name="app.py", path="/blah/path.py"), + "function": "", + "level": RecordLevel(name="ERROR", no=20, icon=""), + "line": 35, + "message": "some message", + "module": "app", + "name": "__main__", + "process": MagicMock(), + "thread": MagicMock(), + "time": MagicMock(), + "extra": MagicMock(), + } + + @record.setter + def record(self, val): + pass + + with patch("loguru._handler.Message", FakeMessage): + logger.error("some message") + + sentry_sdk.get_client().flush() + + logs = envelopes_to_logs(envelopes) + assert len(logs) == 1 + attrs = logs[0]["attributes"] + assert attrs["code.file.path"] == "/blah/path.py" + + +def test_logger_with_all_attributes( + sentry_init, capture_envelopes, uninstall_integration, request +): + uninstall_integration("loguru") + request.addfinalizer(logger.remove) + + sentry_init(_experiments={"enable_logs": True}) + envelopes = capture_envelopes() + + logger.warning("log #{}", 1) + sentry_sdk.get_client().flush() + + logs = envelopes_to_logs(envelopes) + + attributes = logs[0]["attributes"] + + assert "process.pid" in attributes + assert isinstance(attributes["process.pid"], int) + del attributes["process.pid"] + + assert "sentry.release" in attributes + assert isinstance(attributes["sentry.release"], str) + del attributes["sentry.release"] + + assert "server.address" in attributes + assert isinstance(attributes["server.address"], str) + del attributes["server.address"] + + assert "thread.id" in attributes + assert isinstance(attributes["thread.id"], int) + del attributes["thread.id"] + + assert "code.file.path" in attributes + assert isinstance(attributes["code.file.path"], str) + del attributes["code.file.path"] + + assert "code.function.name" in attributes + assert isinstance(attributes["code.function.name"], str) + del attributes["code.function.name"] + + assert "code.line.number" in attributes + assert isinstance(attributes["code.line.number"], int) + del attributes["code.line.number"] + + assert "process.executable.name" in attributes + assert isinstance(attributes["process.executable.name"], str) + del attributes["process.executable.name"] + + assert "thread.name" in attributes + assert isinstance(attributes["thread.name"], str) + del attributes["thread.name"] + + assert attributes.pop("sentry.sdk.name").startswith("sentry.python") + + # Assert on the remaining non-dynamic attributes. + assert attributes == { + "logger.name": "tests.integrations.loguru.test_loguru", + "sentry.origin": "auto.logger.loguru", + "sentry.environment": "production", + "sentry.sdk.version": VERSION, + "sentry.severity_number": 13, + "sentry.severity_text": "warn", + } diff --git a/tests/test_logs.py b/tests/test_logs.py index 94c0f4ce6f..e480923d70 100644 --- a/tests/test_logs.py +++ b/tests/test_logs.py @@ -9,7 +9,6 @@ import sentry_sdk.logger from sentry_sdk import get_client from sentry_sdk.envelope import Envelope -from sentry_sdk.integrations.logging import LoggingIntegration from sentry_sdk.types import Log from sentry_sdk.consts import SPANDATA, VERSION @@ -268,203 +267,6 @@ def test_logs_tied_to_spans(sentry_init, capture_envelopes): assert logs[0]["attributes"]["sentry.trace.parent_span_id"] == span.span_id -@minimum_python_37 -def test_logger_integration_warning(sentry_init, capture_envelopes): - """ - The python logger module should create 'warn' sentry logs if the flag is on. - """ - sentry_init(_experiments={"enable_logs": True}) - envelopes = capture_envelopes() - - python_logger = logging.Logger("test-logger") - python_logger.warning("this is %s a template %s", "1", "2") - - get_client().flush() - logs = envelopes_to_logs(envelopes) - attrs = logs[0]["attributes"] - assert attrs["sentry.message.template"] == "this is %s a template %s" - assert "code.file.path" in attrs - assert "code.line.number" in attrs - assert attrs["logger.name"] == "test-logger" - assert attrs["sentry.environment"] == "production" - assert attrs["sentry.message.parameter.0"] == "1" - assert attrs["sentry.message.parameter.1"] == "2" - assert attrs["sentry.origin"] == "auto.logger.log" - assert logs[0]["severity_number"] == 13 - assert logs[0]["severity_text"] == "warn" - - -@minimum_python_37 -def test_logger_integration_debug(sentry_init, capture_envelopes): - """ - The python logger module should not create 'debug' sentry logs if the flag is on by default - """ - sentry_init(_experiments={"enable_logs": True}) - envelopes = capture_envelopes() - - python_logger = logging.Logger("test-logger") - python_logger.debug("this is %s a template %s", "1", "2") - get_client().flush() - - assert len(envelopes) == 0 - - -@minimum_python_37 -def test_no_log_infinite_loop(sentry_init, capture_envelopes): - """ - If 'debug' mode is true, and you set a low log level in the logging integration, there should be no infinite loops. - """ - sentry_init( - _experiments={"enable_logs": True}, - integrations=[LoggingIntegration(sentry_logs_level=logging.DEBUG)], - debug=True, - ) - envelopes = capture_envelopes() - - python_logger = logging.Logger("test-logger") - python_logger.debug("this is %s a template %s", "1", "2") - get_client().flush() - - assert len(envelopes) == 1 - - -@minimum_python_37 -def test_logging_errors(sentry_init, capture_envelopes): - """ - The python logger module should be able to log errors without erroring - """ - sentry_init(_experiments={"enable_logs": True}) - envelopes = capture_envelopes() - - python_logger = logging.Logger("test-logger") - python_logger.error(Exception("test exc 1")) - python_logger.error("error is %s", Exception("test exc 2")) - get_client().flush() - - error_event_1 = envelopes[0].items[0].payload.json - assert error_event_1["level"] == "error" - error_event_2 = envelopes[1].items[0].payload.json - assert error_event_2["level"] == "error" - - logs = envelopes_to_logs(envelopes) - assert logs[0]["severity_text"] == "error" - assert "sentry.message.template" not in logs[0]["attributes"] - assert "sentry.message.parameter.0" not in logs[0]["attributes"] - assert "code.line.number" in logs[0]["attributes"] - - assert logs[1]["severity_text"] == "error" - assert logs[1]["attributes"]["sentry.message.template"] == "error is %s" - assert ( - logs[1]["attributes"]["sentry.message.parameter.0"] == "Exception('test exc 2')" - ) - assert "code.line.number" in logs[1]["attributes"] - - assert len(logs) == 2 - - -def test_log_strips_project_root(sentry_init, capture_envelopes): - """ - The python logger should strip project roots from the log record path - """ - sentry_init( - _experiments={"enable_logs": True}, - project_root="/custom/test", - ) - envelopes = capture_envelopes() - - python_logger = logging.Logger("test-logger") - python_logger.handle( - logging.LogRecord( - name="test-logger", - level=logging.WARN, - pathname="/custom/test/blah/path.py", - lineno=123, - msg="This is a test log with a custom pathname", - args=(), - exc_info=None, - ) - ) - get_client().flush() - - logs = envelopes_to_logs(envelopes) - assert len(logs) == 1 - attrs = logs[0]["attributes"] - assert attrs["code.file.path"] == "blah/path.py" - - -def test_logger_with_all_attributes(sentry_init, capture_envelopes): - """ - The python logger should be able to log all attributes, including extra data. - """ - sentry_init(_experiments={"enable_logs": True}) - envelopes = capture_envelopes() - - python_logger = logging.Logger("test-logger") - python_logger.warning( - "log #%d", - 1, - extra={"foo": "bar", "numeric": 42, "more_complex": {"nested": "data"}}, - ) - get_client().flush() - - logs = envelopes_to_logs(envelopes) - - attributes = logs[0]["attributes"] - - assert "process.pid" in attributes - assert isinstance(attributes["process.pid"], int) - del attributes["process.pid"] - - assert "sentry.release" in attributes - assert isinstance(attributes["sentry.release"], str) - del attributes["sentry.release"] - - assert "server.address" in attributes - assert isinstance(attributes["server.address"], str) - del attributes["server.address"] - - assert "thread.id" in attributes - assert isinstance(attributes["thread.id"], int) - del attributes["thread.id"] - - assert "code.file.path" in attributes - assert isinstance(attributes["code.file.path"], str) - del attributes["code.file.path"] - - assert "code.function.name" in attributes - assert isinstance(attributes["code.function.name"], str) - del attributes["code.function.name"] - - assert "code.line.number" in attributes - assert isinstance(attributes["code.line.number"], int) - del attributes["code.line.number"] - - assert "process.executable.name" in attributes - assert isinstance(attributes["process.executable.name"], str) - del attributes["process.executable.name"] - - assert "thread.name" in attributes - assert isinstance(attributes["thread.name"], str) - del attributes["thread.name"] - - assert attributes.pop("sentry.sdk.name").startswith("sentry.python") - - # Assert on the remaining non-dynamic attributes. - assert attributes == { - "foo": "bar", - "numeric": 42, - "more_complex": "{'nested': 'data'}", - "logger.name": "test-logger", - "sentry.origin": "auto.logger.log", - "sentry.message.template": "log #%d", - "sentry.message.parameter.0": 1, - "sentry.environment": "production", - "sentry.sdk.version": VERSION, - "sentry.severity_number": 13, - "sentry.severity_text": "warn", - } - - def test_auto_flush_logs_after_100(sentry_init, capture_envelopes): """ If you log >100 logs, it should automatically trigger a flush.