Monitoring and centralized logging integration strategy #344

rudyryk · 2020-10-06T07:32:20Z

I'm trying switching to Loguru for my newer projects and I'm wondering, what is recommended approach to perform integrations with services like Sentry, etc.?

For example, Sentry has built-in standard logging library hooks. But it won't work with the standard logging intercepted by Loguru.

Should we create custom sink? That could be tricky, and actually, could introduce extra bugs, so it needs to have solid design and bunch of tests. Application broken because of bugs monitoring a is kind of "fun but not fun".

rudyryk · 2020-10-06T09:57:05Z

For Sentry integration I came up to such code:

import sys
from loguru import logger
import logging
from sentry_sdk.integrations.logging import LoggingIntegration, EventHandler
SENTRY_DSN = '...'
logger.remove()
sentry_sdk.init(
    SENTRY_DSN,
    integrations=[LoggingIntegration(level=None, event_level=None)],
)
logger.add(sys.stderr, level='INFO')
logger.add(EventHandler(level=logging.WARNING))

# + InterceptHandler from README.md
# ...
logging.basicConfig(handlers=[InterceptHandler()], level=0)

Will test how it works out.

Delgan · 2020-10-06T20:28:50Z

Hi @rudyryk.

As you figured out, I think simply adding a Sentry EventHandler or BreadcrumbHandler to the Loguru logger should work fine.

Combining this with the InterceptHandler() ensure that logs emitted the standard logging library will be captured too.

Please, let me know if this does not work as expected.

rudyryk · 2020-10-08T18:51:57Z

@Delgan unfortunately, I faced weird issue, I got endless messages sent to the Sentry server:

...
2020-10-08 21:34:56.524 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:56.634 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:56.704 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:56.817 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:56.870 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:56.977 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.028 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.141 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.193 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.297 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.363 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.473 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.539 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.645 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
2020-10-08 21:34:57.706 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41
^C2020-10-08 21:34:57.803 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41

An example of message received:

2020-10-08 21:42:57.985 | DEBUG    | sentry_sdk.integrations.logging:sentry_patched_callhandlers:83 - https://sentry.mysite.org:443 "POST /api/9/store/ HTTP/1.1" 200 41

Seems like some cyclic logging behaviour.

Delgan · 2020-10-09T14:59:57Z

Sorry, I'm not a Sentry user and consequently I'm not able to reproduce your problem. :(

Would this be possible that events emitted by the EventHandler() would somehow be captured by Sentry which would generate new logs causing EventHandler() to emit new events and so on?
I have no clue about what could be causing the behavior you're experiencing. 😕

rudyryk · 2020-10-20T22:20:16Z

Would this be possible that events emitted by the EventHandler() would somehow be captured by Sentry which would generate new logs causing EventHandler() to emit new events and so on?

My guess is that's what happening exactly, but I didn't have chance to deep dive. Sentry is a major player in monitoring and crashes tracking in Python world, I think it's crucial to have solid workflow to make them play well with each other.

Delgan · 2020-10-21T18:14:56Z

Indeed, it is very important that loguru and sentry can work together. From what I've seen, several people use both of them without any problem, though.

If you have any idea how to create a minimum reproducible example of the issue you're facing, please let me know.

I have some doubts about the use of sentry_sdk.init() in your example. I'm not sure, but I'm thinking that it might be the one that causes conflicts with other handlers added manually.

rudyryk · 2020-10-23T15:19:57Z

@Delgan Yes, it's possible that some other hooks are also involved, I'll try to provide basic reproducible example.

Soures888 · 2021-01-14T20:58:24Z

@rudyryk Have you found a solution?

Delgan · 2021-03-15T21:57:05Z

Hi @Soures888. Did you encounter the same issue? Are you able to create a minimal reproducible example?

TheZavitaev · 2021-07-29T15:02:03Z

Hi guys! Just use this solution:
getsentry/sentry-python#653 (comment)

kbakk · 2022-01-16T15:48:09Z

Hi,

I'm seeing some issues with using Sentry and Loguru. Here's a reproducer:

t.py

import logging
import os
import sys
from loguru import logger
import sentry_sdk


class InterceptHandler(logging.Handler):
    def emit(self, record):
        # Get corresponding Loguru level if it exists
        try:
            level = logger.level(record.levelname).name
        except (ValueError, TypeError):
            level = record.levelno

        # Find caller from where originated the logged message
        frame, depth = logging.currentframe(), 2
        while frame.f_code.co_filename == logging.__file__:
            frame = frame.f_back
            depth += 1

        logger.opt(depth=depth, exception=record.exc_info).log(
            level, record.getMessage()
        )


logging.basicConfig(handlers=[InterceptHandler()], level=0)
level_per_module = {"": "DEBUG", "sentry_sdk": "INFO"}
logger.remove()
logger.add(
    sys.stderr,
    filter=level_per_module,
    diagnose=False,
    colorize=True,
    format="{level: <8} | {name}:{line} ({module}) | <level>{message}</level>",
    level="DEBUG",
)
sentry_sdk.init(
    os.getenv("SENTRY_SDK")
)

std_logger = logging.getLogger("std_logger")
std_logger.info("Test info msg")
std_logger.debug("Test debug msg - not shown")

logger.debug("Test msg")

$ python t.py
INFO     | sentry_sdk.integrations.logging:86 (logging) | Test info msg
DEBUG    | __main__:45 (t) | Test msg

If I comment out the sentry_sdk.init statement, I'll get the expected output:

$ python t.py
INFO     | __main__:42 (t) | Test info msg
DEBUG    | __main__:43 (t) | Test debug msg - not shown
DEBUG    | __main__:45 (t) | Test msg

It looks like the sentry_sdk overwrites some of the data.

kbakk · 2022-01-16T16:17:10Z

Playing around a bit, I tried changing

         # Find caller from where originated the logged message
         frame, depth = logging.currentframe(), 2
-        while frame.f_code.co_filename == logging.__file__:
+        while (
+            frame.f_code.co_filename == logging.__file__
+            or "sentry_sdk/integrations" in frame.f_code.co_filename
+        ):
             frame = frame.f_back
             depth += 1

It seems to have the desired effect:

$ python t.py
INFO     | __main__:46 (t) | Test info msg
DEBUG    | __main__:47 (t) | Test debug msg - not shown
DEBUG    | __main__:49 (t) | Test msg

This might introduce some other problems, so not sure I can recommend this.

kbakk · 2022-01-16T16:28:44Z

The above is similar to what @fratambot writes in #509

fratambot · 2022-01-17T13:35:33Z

The above is similar to what @fratambot writes in #509

Hey @kbakk, in the end I managed to integrate nicely loguru and sentry.
You can take a look at what I've done here: #554 (comment)
I hope it can help you ! :)

Delgan · 2022-01-19T12:56:21Z

Hey @kbakk. Thanks for the reproducible example. This seems definitely related to how logging is configured by sentry_sdk.init(). I do not know what's happening under the hood, but it somehow breaks the InterceptHandler expectations.

I figured out you could configure Sentry with default_integrations=False to generate the expected logs. This has probably some side effect I'm not aware of, documentation is mentioning two handlers you may need to install manually: Logging | Sentry Documentation.

Hope it might help.

Delgan · 2023-08-27T16:15:26Z

It seems Sentry now officially supports Loguru: Learn about using Sentry with Loguru.

Consequently, I'm closing this ticket. The integration should be quite straightforward.

Delgan added the question Further information is requested label Mar 15, 2021

kbakk mentioned this issue Jan 16, 2022

Add support of loguru logger. getsentry/sentry-python#653

Closed

Delgan closed this as completed Aug 27, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Monitoring and centralized logging integration strategy #344

Monitoring and centralized logging integration strategy #344

rudyryk commented Oct 6, 2020 •

edited

Loading

rudyryk commented Oct 6, 2020 •

edited

Loading

Delgan commented Oct 6, 2020 •

edited

Loading

rudyryk commented Oct 8, 2020 •

edited

Loading

Delgan commented Oct 9, 2020

rudyryk commented Oct 20, 2020

Delgan commented Oct 21, 2020 •

edited

Loading

rudyryk commented Oct 23, 2020

Soures888 commented Jan 14, 2021

Delgan commented Mar 15, 2021 •

edited

Loading

TheZavitaev commented Jul 29, 2021

kbakk commented Jan 16, 2022

kbakk commented Jan 16, 2022

kbakk commented Jan 16, 2022

fratambot commented Jan 17, 2022

Delgan commented Jan 19, 2022

Delgan commented Aug 27, 2023

Monitoring and centralized logging integration strategy #344

Monitoring and centralized logging integration strategy #344

Comments

rudyryk commented Oct 6, 2020 • edited Loading

rudyryk commented Oct 6, 2020 • edited Loading

Delgan commented Oct 6, 2020 • edited Loading

rudyryk commented Oct 8, 2020 • edited Loading

Delgan commented Oct 9, 2020

rudyryk commented Oct 20, 2020

Delgan commented Oct 21, 2020 • edited Loading

rudyryk commented Oct 23, 2020

Soures888 commented Jan 14, 2021

Delgan commented Mar 15, 2021 • edited Loading

TheZavitaev commented Jul 29, 2021

kbakk commented Jan 16, 2022

kbakk commented Jan 16, 2022

kbakk commented Jan 16, 2022

fratambot commented Jan 17, 2022

Delgan commented Jan 19, 2022

Delgan commented Aug 27, 2023

rudyryk commented Oct 6, 2020 •

edited

Loading

rudyryk commented Oct 6, 2020 •

edited

Loading

Delgan commented Oct 6, 2020 •

edited

Loading

rudyryk commented Oct 8, 2020 •

edited

Loading

Delgan commented Oct 21, 2020 •

edited

Loading

Delgan commented Mar 15, 2021 •

edited

Loading