Skip to content

Exceptions not logged on sentry.io when using concurrent.futures.ThreadPoolExecutor  #1234

@patunhedged

Description

@patunhedged

Environment

How do you use Sentry?
Sentry SaaS (sentry.io)

Which SDK and version?
macOS 11.5.2 (big sur)
CPython 3.9.6
sentry_sdk 1.4.2

Steps to Reproduce

I ran the following block of code

from concurrent.futures import ThreadPoolExecutor
import sentry_sdk
from sentry_sdk.integrations.threading import ThreadingIntegration

dsn = "<your sentry dsn>"
sentry_sdk.init(
    dsn=dsn,
    shutdown_timeout=10,
    debug=True,
    integrations=[ThreadingIntegration(propagate_hub=True)],
)
sentry_sdk.set_tag("mydata", 42)

def task(name, item):
    # task that is performed in parallel
    print("task {} {} started".format(name, item))
    sentry_sdk.capture_message("going to crash with a 30/0")
    40/0            # I expect this to log an exception but does NOT log an exception on sentry.io
    print("task {} {} finished".format(name, item))  # we never get here because of the crash

def task_manager():
    THREAD_MAX_WORKERS = 100
    thread_executor = ThreadPoolExecutor(max_workers=THREAD_MAX_WORKERS)
    for item in range(5):
        thread_executor.submit(task, "test", item)  # create a new job
    thread_executor.shutdown()  # we will be blocked here until all threads complete
    print("jobs finished")

if __name__ == "__main__":
    task_manager()
    41/0    # this WILL log an exception on sentry.io

Expected Result

As task_manager() would create 5x separate task() jobs, I expected:

  • 5x capture_messages going to crash with a 30/0 to be logged on sentry.io (line 17)
  • 5x exceptions to be logged with 40/0 ZeroDivisionError exception (line 18)
  • 1x exception to be logged with 41/0 ZeroDivisionError exception (line 31)

Actual Result

I experienced:

  • 5x capture_messages going to crash with a 30/0 were SUCCESSFULLY logged on sentry.io (line 17)
  • 5x exceptions with 40/0 ZeroDivisionError exception (line 18) was NOT SUCCESSFULLY logged on sentry.io
  • 1x exception with 41/0 ZeroDivisionError exception (line 31) was SUCCESSFULLY logged on sentry.io
python test_thread_mvp.py
 [sentry] DEBUG: Setting up integrations (with default = True)
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.django.DjangoIntegration: Django not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.flask.FlaskIntegration: Flask is not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.bottle.BottleIntegration: Bottle not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.falcon.FalconIntegration: Falcon not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.sanic.SanicIntegration: Sanic not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.celery.CeleryIntegration: Celery not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.rq.RqIntegration: RQ not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.aiohttp.AioHttpIntegration: AIOHTTP not installed
 [sentry] DEBUG: Did not import default integration sentry_sdk.integrations.tornado.TornadoIntegration: Tornado not installed
 [sentry] DEBUG: Setting up previously not enabled integration threading
 [sentry] DEBUG: Setting up previously not enabled integration logging
 [sentry] DEBUG: Setting up previously not enabled integration stdlib
 [sentry] DEBUG: Setting up previously not enabled integration excepthook
 [sentry] DEBUG: Setting up previously not enabled integration dedupe
 [sentry] DEBUG: Setting up previously not enabled integration atexit
 [sentry] DEBUG: Setting up previously not enabled integration modules
 [sentry] DEBUG: Setting up previously not enabled integration argv
 [sentry] DEBUG: Setting up previously not enabled integration sqlalchemy
 [sentry] DEBUG: Setting up previously not enabled integration boto3
 [sentry] DEBUG: Enabling integration threading
 [sentry] DEBUG: Enabling integration logging
 [sentry] DEBUG: Enabling integration stdlib
 [sentry] DEBUG: Enabling integration excepthook
 [sentry] DEBUG: Enabling integration dedupe
 [sentry] DEBUG: Enabling integration atexit
 [sentry] DEBUG: Enabling integration modules
 [sentry] DEBUG: Enabling integration argv
 [sentry] DEBUG: Enabling integration sqlalchemy
 [sentry] DEBUG: Enabling integration boto3
task test 0 started
task test 1 started
task test 2 started
task test 3 started
task test 4 started
jobs finished
 [sentry] DEBUG: Sending event, type:null level:info event_id:3d30670b8f134560bf7288091d72ada4 project:7463834 host:o3847193.ingest.sentry.io
Traceback (most recent call last):
  File "/Users/z/test_thread_mvp.py", line 31, in <module>
    41/0    # this WILL log an exception on sentry.io
ZeroDivisionError: division by zero
 [sentry] DEBUG: atexit: got shutdown signal
 [sentry] DEBUG: atexit: shutting down client
 [sentry] DEBUG: Flushing HTTP transport
 [sentry] DEBUG: background worker got flush request
 [sentry] DEBUG: 7 event(s) pending on flush
Sentry is attempting to send 7 pending error messages
Waiting up to 10 seconds
Press Ctrl-C to quit
 [sentry] DEBUG: [Tracing] Adding `sentry-trace` header 573c7981bb724747a7b6a1c57ac1e9b4-8c262e380834b2b3- to outgoing request to https://o3847193.ingest.sentry.io/api/7463834/store/.
 [sentry] DEBUG: Sending event, type:null level:info event_id:97fe1e03626c46e185372dbb78f30cc7 project:7463834 host:o3847193.ingest.sentry.io
 [sentry] DEBUG: [Tracing] Adding `sentry-trace` header 93b26a8d501c4837921f9dc45b12269a-917a82ad3ee8be4c- to outgoing request to https://o3847193.ingest.sentry.io/api/7463834/store/.
 [sentry] DEBUG: Sending event, type:null level:info event_id:02b389a7eee749d4ad50f873369b06fa project:7463834 host:o3847193.ingest.sentry.io
 [sentry] DEBUG: [Tracing] Adding `sentry-trace` header 0ebc6b346b7341088d9d8a3948913e5a-8d4701f59abbd49d- to outgoing request to https://o3847193.ingest.sentry.io/api/7463834/store/.
 [sentry] DEBUG: Sending event, type:null level:info event_id:aa39d467ed5b4261a5507402660c8682 project:7463834 host:o3847193.ingest.sentry.io
 [sentry] DEBUG: [Tracing] Adding `sentry-trace` header dcdfdc9b20e14ae399b149e9c083a63b-8f0dcbf5cc377c87- to outgoing request to https://o3847193.ingest.sentry.io/api/7463834/store/.
 [sentry] DEBUG: Sending event, type:null level:info event_id:fd9c63e42864441c92e301a0147efbcb project:7463834 host:o3847193.ingest.sentry.io
 [sentry] DEBUG: [Tracing] Adding `sentry-trace` header a3f4e86d18e54a49b9c3dc7e0d5a2533-b89dd26b2502bec7- to outgoing request to https://o3847193.ingest.sentry.io/api/7463834/store/.
 [sentry] DEBUG: Sending event, type:null level:error event_id:436508a757c6410688c28a975e1fd6c5 project:7463834 host:o3847193.ingest.sentry.io
 [sentry] DEBUG: [Tracing] Adding `sentry-trace` header 8c2203cb91fd480fb7abae703f271d81-a0dcba3c252e9470- to outgoing request to https://o3847193.ingest.sentry.io/api/7463834/store/.
 [sentry] DEBUG: background worker flushed
 [sentry] DEBUG: Killing HTTP transport
 [sentry] DEBUG: background worker got kill request

Note that:

  • removing ThreadingIntegration didn't seem to affect the result
  • initialising sentry_dsk.init inside task doesn't seem to affect the result

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels
    No fields configured for issues without a type.

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions