scout_apm_python icon indicating copy to clipboard operation
scout_apm_python copied to clipboard

Celery integration blocks running django commands

Open ktowen opened this issue 1 year ago • 4 comments

When I try to run any django command it gets stuck and if I interrupt it this is the traceback I get. I enabled debug logs in case it's useful

DEBUG:scout_apm.core.config:Configuration Loaded:
DEBUG:scout_apm.core.config:Defaults : app_server =
DEBUG:scout_apm.core.config:Defaults : application_root = /app
DEBUG:scout_apm.core.config:Defaults : collect_remote_ip = True
DEBUG:scout_apm.core.config:Null     : core_agent_config_file = None
DEBUG:scout_apm.core.config:Defaults : core_agent_dir = /tmp/scout_apm_core
DEBUG:scout_apm.core.config:Defaults : core_agent_download = True
DEBUG:scout_apm.core.config:Defaults : core_agent_launch = True
DEBUG:scout_apm.core.config:Null     : core_agent_log_file = None
DEBUG:scout_apm.core.config:Defaults : core_agent_log_level = info
DEBUG:scout_apm.core.config:Defaults : core_agent_permissions = 700
DEBUG:scout_apm.core.config:Defaults : core_agent_socket_path = tcp://127.0.0.1:6590
DEBUG:scout_apm.core.config:Defaults : core_agent_version = v1.4.0
DEBUG:scout_apm.core.config:Defaults : disabled_instruments = []
DEBUG:scout_apm.core.config:Defaults : download_url = https://s3-us-west-1.amazonaws.com/scout-public-downloads/apm_core_agent/release
DEBUG:scout_apm.core.config:Defaults : framework =
DEBUG:scout_apm.core.config:Defaults : framework_version =
DEBUG:scout_apm.core.config:Defaults : hostname = None
DEBUG:scout_apm.core.config:Null     : ignore = None
DEBUG:scout_apm.core.config:Null     : log_level = None
DEBUG:scout_apm.core.config:Defaults : log_payload_content = False
DEBUG:scout_apm.core.config:Python   : monitor = True
DEBUG:scout_apm.core.config:Python   : name = testtest
DEBUG:scout_apm.core.config:Python   : revision_sha = 7c7c4ecc708cf45338d150b59ac654245d546877
DEBUG:scout_apm.core.config:Python   : scm_subdirectory = /core
DEBUG:scout_apm.core.config:Defaults : shutdown_message_enabled = True
DEBUG:scout_apm.core.config:Defaults : shutdown_timeout_seconds = 2.0
DEBUG:scout_apm.instruments.elasticsearch:Instrumenting elasticsearch.
DEBUG:scout_apm.instruments.elasticsearch:Couldn't import elasticsearch.Elasticsearch - probably not installed.
DEBUG:scout_apm.instruments.elasticsearch:Couldn't import elasticsearch.Transport or elastic_transport.Transport - probably not installed.
DEBUG:scout_apm.instruments.jinja2:Instrumenting Jinja2.
DEBUG:scout_apm.instruments.pymongo:Instrumenting pymongo.
DEBUG:scout_apm.instruments.pymongo:Couldn't import pymongo.Collection - probably not installed.
DEBUG:scout_apm.instruments.redis:Instrumenting redis.
DEBUG:scout_apm.instruments.urllib3:Instrumenting urllib3.
DEBUG:scout_apm.core:APM Launching on PID: 598
DEBUG:scout_apm.core.agent.manager:Core Agent manifest json: {'version': '1.4.0', 'core_agent_version': '1.4.0', 'core_agent_binary': 'core-agent', 'core_agent_binary_sha256': '1a24b1ab8a0ca7ffc831ca83614e0d4c2b4b801f4a4eec0c3cfa0a363caf6ff8'}
^CDEBUG:scout_apm.core.agent.socket:CoreAgentSocketThread attempt 1, connecting to tcp://127.0.0.1:6590, PID: 598, Thread: <CoreAgentSocketThread(Thread-1, stopped daemon 140094993512000)>
DEBUG:scout_apm.core.agent.socket:CoreAgentSocketThread connected
INFO:scout_apm.core.agent.commands:Registering with app=testtest key_prefix=XQb key_format_validated=True host=None
Traceback (most recent call last):
  File "/app/manage.py", line 22, in <module>
    execute_from_command_line(sys.argv)
  File "/usr/local/lib/python3.10/dist-packages/django/core/management/__init__.py", line 419, in execute_from_command_line
    utility.execute()
  File "/usr/local/lib/python3.10/dist-packages/django/core/management/__init__.py", line 395, in execute
    django.setup()
  File "/usr/local/lib/python3.10/dist-packages/django/__init__.py", line 19, in setup
    configure_logging(settings.LOGGING_CONFIG, settings.LOGGING)
  File "/usr/local/lib/python3.10/dist-packages/django/utils/log.py", line 75, in configure_logging
    logging_config_func(logging_settings)
  File "/usr/lib/python3.10/logging/config.py", line 810, in dictConfig
    dictConfigClass(config).configure()
  File "/usr/lib/python3.10/logging/config.py", line 544, in configure
    formatters[name] = self.configure_formatter(
  File "/usr/lib/python3.10/logging/config.py", line 676, in configure_formatter
    c = _resolve(cname)
  File "/usr/lib/python3.10/logging/config.py", line 90, in _resolve
    found = __import__(used)
  File "/app/common/__init__.py", line 1, in <module>
    from common import tasks  # noqa
  File "/app/common/tasks/__init__.py", line 1, in <module>
    from .maintenance import *  # noqa
  File "/app/common/tasks/maintenance.py", line 6, in <module>
    from common.celery import app
  File "/app/common/celery.py", line 26, in <module>
    scout_celery.install(app)
  File "/usr/local/lib/python3.10/dist-packages/scout_apm/celery.py", line 133, in install
    installed = scout_apm.core.install()
  File "/usr/local/lib/python3.10/dist-packages/scout_apm/compat.py", line 141, in wrapper
    return func(*args, **kwargs)
  File "/usr/local/lib/python3.10/dist-packages/scout_apm/core/__init__.py", line 50, in install
    CoreAgentSocketThread.ensure_stopped()
  File "/usr/local/lib/python3.10/dist-packages/scout_apm/core/threading.py", line 44, in ensure_stopped
    cls._instance.join()DEBUG:scout_apm.core.tracked_request:Starting request: req-f0c17d8b-7f2b-47c0-b74c-3a81ab67f01f

  File "/usr/lib/python3.10/threading.py", line 1096, in join
DEBUG:urllib3.connectionpool:Starting new HTTPS connection (1): sentry.*****.****:443
    self._wait_for_tstate_lock()
  File "/usr/lib/python3.10/threading.py", line 1116, in _wait_for_tstate_lock
    if lock.acquire(block, timeout):
KeyboardInterrupt
DEBUG:urllib3.connectionpool:https://sentry.*****.****:443 "POST /api/2/store/ HTTP/1.1" 200 41
DEBUG:scout_apm.core.tracked_request:Stopping request: req-f0c17d8b-7f2b-47c0-b74c-3a81ab67f01f
DEBUG:scout_apm.core.tracked_request:Request req-f0c17d8b-7f2b-47c0-b74c-3a81ab67f01f start_time=2023-06-01 17:17:25.078999 end_time=2023-06-01 17:17:25.162968 duration=0.083969 active_spans=0 complete_spans=1 tags=0 hit_max=False is_real_request=False sent=False

ktowen avatar Jun 01 '23 17:06 ktowen

Thanks, and sorry for the trouble. We'll have to take a look into this.

lancetarn avatar Jun 09 '23 18:06 lancetarn

Any workaround for this?

ktowen avatar Oct 24 '23 10:10 ktowen

My apologies for the extended delay here. I spent some time setting up a simple Celery+Django test application, but have yet been unable to recreate this issue. My test application is using python 3.10, Django 4.2, and Celery 5.3 with a local Redis server. I'm running everything in a containerized environment via docker-compose.

Could you please provide more info about your specific environment/setup? You mentioned this is happening when you run "any" django command, so i'm assuming this extends to even python manage.py runserver?

I'm also curious how you are instrumenting Celery. In my test app I created the Celery instance in a separate celery.py module and then had to import that into the __init__.py of the Django app.

Again, sorry about the delay here, and appreciate your patience on this issue. Please provide some more context and let's get this figured out!

quinnmil avatar Nov 10 '23 19:11 quinnmil

Hello. Thanks for your response. I will work on creating a simple test application where I can replicate the problem.

ktowen avatar Nov 10 '23 21:11 ktowen