Logging/breadcrumb integration with multiple threads

[mikepurvis]

I'm trying to use raven.handlers.logging.SentryHandler to capture errors and exceptions in my application , but I'm getting some strange behaviour around breadcrumbs that I'm hoping I can get a little help understanding. Potentially this is related to #806 (which @mitsuhiko was looking at), but seeing this behaviour without multiprocessing involved felt like it warranted a new ticket.

MWE:

import raven
import logging
from raven.handlers.logging import SentryHandler
from time import sleep
from threading import Thread

logger = logging.getLogger('foo')
logger.setLevel(logging.DEBUG)
other_logger = logging.getLogger('bar')
other_logger.setLevel(logging.DEBUG)

client = raven.Client()
sentryLogHandler = SentryHandler(client, level="ERROR")
logger.addHandler(sentryLogHandler)
other_logger.addHandler(sentryLogHandler)

sh = logging.StreamHandler()
logger.addHandler(sh)
other_logger.addHandler(sh)

logger.debug("1")
logger.info("2")
other_logger.info("3")

def foo():
    other_logger.info("4")
    logger.critical("5")
t = Thread(target=foo)
t.start()
sleep(0.1)

logger.critical("6")

Output in the console (via StreamHandler) is as expected:

1
2
3
4
5
6

However, in Sentry:

• The event for 6 is missing the breadcrumbs for 4 and 5 (from the other thread), and
• The event for 5 has no breadcrumbs at all, not even the 4 one from within the same thread.

Any idea what's going on here?

[mikepurvis]

Oh, it seems that the breadcrumb capture doesn't happen via raven.handlers.logging.SentryHandler at all— it's this monkey-patch of the logging module itself:

https://github.com/getsentry/raven-python/blob/c69abaa1506a426802e979c7f8c6a4ab0ef9c4d7/raven/breadcrumbs.py#L157-L186

---

However, it looks like this is an issue with breadcrumbs more than with the logging patch— even when I just do a straight up raven.breadcrumbs.record, it makes it in from the main thread, but not the other one.

---

Here it is— breadcrumbs are stored as part of the "context", which is thread-local:

https://github.com/getsentry/raven-python/blob/c69abaa1506a426802e979c7f8c6a4ab0ef9c4d7/raven/context.py#L22-L51

---

So, this feels like a giant hack, but I get the behaviour I would like if I manually alias the thread's context's BreadcrumbBuffer back to the global instance, like so:

logger.debug("1")
logger.info("2")
other_logger.info("3")
record('aaa')
global_breadcrumbs = client.context.breadcrumbs

def foo():
    client.context.activate()
    client.context.breadcrumbs = global_breadcrumbs
    record('bbb')
    other_logger.info("4")
    logger.critical("5")
t = Thread(target=foo)
t.start()
sleep(0.1)

logger.critical("6")

This will allow me to move forward, but it would be great to have any thoughts on whether there are better ways to solve this.