search

newrelic / newrelic-python-agent

New Relic Python Agent
https://docs.newrelic.com/docs/agents/python-agent
Apache License 2.0
176 stars 100 forks source link

New Relic ASGI wrapper stop working #1152

Closed jefer94 closed 1 month ago

jefer94 commented 4 months ago

Versions

pipenv=2023.12.1
django=5.0.5
python=3.12.3

Worker

uvicorn.workers.UvicornWorker

Cloud

Heroku

Env

WEB_WORKER_CONNECTION=160
WEB_WORKER_CLASS=uvicorn.workers.UvicornWorker
CELERY_POOL=prefork
WEB_WORKERS=2
WEB_MAX_REQUESTS=100
WEB_MAX_REQUESTS_JITTER=50
WEB_PRELOAD=0
NOWRAP_APP=0

Script

#!/bin/env bash

WEB_WORKER_CONNECTION=${WEB_WORKER_CONNECTION:-200}
WEB_WORKER_CLASS=${WEB_WORKER_CLASS:-uvicorn.workers.UvicornWorker}
CELERY_POOL=${CELERY_POOL:-prefork}
WEB_WORKERS=${WEB_WORKERS:-2}
WEB_TIMEOUT=${WEB_TIMEOUT:-29}
WEB_MAX_REQUESTS=${WEB_MAX_REQUESTS:-6000}
WEB_MAX_REQUESTS_JITTER=${WEB_MAX_REQUESTS_JITTER:-3000}
WEB_PRELOAD=${WEB_PRELOAD:-1}
SSR=${SSR:-0}

export NEW_RELIC_METADATA_COMMIT=$HEROKU_SLUG_COMMIT;
export CORALOGIX_SUBSYSTEM=web;
export CELERY_POOL=$CELERY_POOL;

if [ "$WEB_PRELOAD" = "1" ]; then
    GUNICORN_PARAMS="--preload"
else
    GUNICORN_PARAMS=""
fi

if [ "$WEB_WORKER_CLASS" = "uvicorn.workers.UvicornWorker" ]; then
    export SERVER_TYPE=asgi;
else
    export SERVER_TYPE=wsgi;
fi

newrelic-admin run-program bin/start-pgbouncer-stunnel \
    gunicorn breathecode.$SERVER_TYPE --timeout $WEB_TIMEOUT --workers $WEB_WORKERS \
        --worker-connections $WEB_WORKER_CONNECTION --worker-class $WEB_WORKER_CLASS \
        --max-requests $WEB_MAX_REQUESTS --max-requests-jitter $WEB_MAX_REQUESTS_JITTER \
        $GUNICORN_PARAMS &

pid1=$!

if [ "$SSR" = "1" ]; then
    curl -fsSL https://bun.sh/install | bash
    export BUN_INSTALL="$HOME/.bun"
    export PATH=$BUN_INSTALL/bin:$PATH

    newrelic-admin run-program bun ssr.ts &
    pid2=$!
    wait $pid2
fi

wait $pid1

asgi.py

"""
WSGI config for breathecode project.

It exposes the WSGI callable as a module-level variable named ``application``.

For more information on this file, see
https://docs.djangoproject.com/en/3.0/howto/deployment/wsgi/
"""

# keeps this above
import newrelic.agent

newrelic.agent.initialize()

# the rest of your ASGI file contents go here
import os

from django.core.asgi import get_asgi_application

os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'breathecode.settings')

application = get_asgi_application()
if os.getenv('NOWRAP_APP') != '1':
    application = newrelic.agent.ASGIApplicationWrapper(application)

Log

2024-05-28T20:06:58.493920+00:00 heroku[router]: at=info method=GET path="/" host=breathecode-test.herokuapp.com request_id=bbcdf32f-d6b6-4df7-baed-f80afc42fd4e fwd="190.240.161.182" dyno=web.1 connect=0ms service=4ms status=500 bytes=212 protocol=https
2024-05-28T20:06:58.492684+00:00 app[web.1]: [2024-05-28 20:06:58 +0000] [29] [ERROR] Exception in ASGI application
2024-05-28T20:06:58.492750+00:00 app[web.1]: Traceback (most recent call last):
2024-05-28T20:06:58.492766+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 407, in run_asgi
2024-05-28T20:06:58.492767+00:00 app[web.1]:     result = await app(  # type: ignore[func-returns-value]
2024-05-28T20:06:58.492767+00:00 app[web.1]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.492768+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 69, in __call__
2024-05-28T20:06:58.492768+00:00 app[web.1]:     return await self.app(scope, receive, send)
2024-05-28T20:06:58.492768+00:00 app[web.1]:                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.492768+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 258, in nr_asgi_wrapper
2024-05-28T20:06:58.492769+00:00 app[web.1]:     return wrapped(*args, **kwargs)
2024-05-28T20:06:58.492769+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.492771+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/wsgi_application.py", line 669, in _nr_wsgi_application_wrapper_
2024-05-28T20:06:58.492771+00:00 app[web.1]:     result = wrapped(environ, _start_response)
2024-05-28T20:06:58.492771+00:00 app[web.1]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.492772+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 363, in nr_asgi_wrapper
2024-05-28T20:06:58.492772+00:00 app[web.1]:     return nr_async_asgi(*_bind_receive_send(*args, **kwargs))
2024-05-28T20:06:58.492773+00:00 app[web.1]:                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.492773+00:00 app[web.1]: TypeError: _bind_receive_send() missing 1 required positional argument: 'send'
2024-05-28T20:06:58.493146+00:00 app[web.1]: 190.240.161.182:0 - "GET / HTTP/1.1" 500
2024-05-28T20:06:58.837909+00:00 heroku[router]: at=info method=GET path="/favicon.ico" host=breathecode-test.herokuapp.com request_id=d7d55ec6-d5b9-4955-85b9-70734617f2d2 fwd="190.240.161.182" dyno=web.1 connect=1ms service=15ms status=500 bytes=212 protocol=https
2024-05-28T20:06:58.836773+00:00 app[web.1]: [2024-05-28 20:06:58 +0000] [28] [ERROR] Exception in ASGI application
2024-05-28T20:06:58.836839+00:00 app[web.1]: Traceback (most recent call last):
2024-05-28T20:06:58.836857+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 407, in run_asgi
2024-05-28T20:06:58.836858+00:00 app[web.1]:     result = await app(  # type: ignore[func-returns-value]
2024-05-28T20:06:58.836858+00:00 app[web.1]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.836858+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 69, in __call__
2024-05-28T20:06:58.836858+00:00 app[web.1]:     return await self.app(scope, receive, send)
2024-05-28T20:06:58.836859+00:00 app[web.1]:                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.836859+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 258, in nr_asgi_wrapper
2024-05-28T20:06:58.836859+00:00 app[web.1]:     return wrapped(*args, **kwargs)
2024-05-28T20:06:58.836859+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.836861+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/wsgi_application.py", line 669, in _nr_wsgi_application_wrapper_
2024-05-28T20:06:58.836861+00:00 app[web.1]:     result = wrapped(environ, _start_response)
2024-05-28T20:06:58.836861+00:00 app[web.1]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.836861+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 363, in nr_asgi_wrapper
2024-05-28T20:06:58.836861+00:00 app[web.1]:     return nr_async_asgi(*_bind_receive_send(*args, **kwargs))
2024-05-28T20:06:58.836861+00:00 app[web.1]:                           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-05-28T20:06:58.836862+00:00 app[web.1]: TypeError: _bind_receive_send() missing 1 required positional argument: 'send'
2024-05-28T20:06:58.836931+00:00 app[web.1]: 190.240.161.182:0 - "GET /favicon.ico HTTP/1.1" 500
workato-integration[bot] commented 4 months ago

https://new-relic.atlassian.net/browse/NR-274379

hmstepanek commented 3 months ago

What version of the agent are you using?

hmstepanek commented 3 months ago

I'm not really sure how, but it looks like you have some double instrumentation going on here. In particular these lines of the stack trace look rather problematic:

packages/newrelic/api/asgi_application.py", line 258, in nr_asgi_wrapper
packages/newrelic/api/wsgi_application.py", line 669, in _nr_wsgi_application_wrapper_

For some reason it is wrapping wsgi in asgi. I notice you are manually applying our instrumentation which you should not need to do. Can you try removing the manual instrumentation and just let it automatically instrument instead?

import os

from django.core.asgi import get_asgi_application

os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'breathecode.settings')

application = get_asgi_application()
jefer94 commented 3 months ago

I'm using 9.10.0

I don't get you, I'm setting DJANGO_SETTINGS_MODULE and NewRelic can't know that value, right? with instrumentation what should I remove?

https://github.com/breatheco-de/apiv2/blob/development/Pipfile.lock

jefer94 commented 3 months ago

I'm not really sure how, but it looks like you have some double instrumentation going on here. In particular these lines of the stack trace look rather problematic:

packages/newrelic/api/asgi_application.py", line 258, in nr_asgi_wrapper
packages/newrelic/api/wsgi_application.py", line 669, in _nr_wsgi_application_wrapper_

For some reason it is wrapping wsgi in asgi. I notice you are manually applying our instrumentation which you should not need to do. Can you try removing the manual instrumentation and just let it automatically instrument instead?

import os

from django.core.asgi import get_asgi_application

os.environ.setdefault('DJANGO_SETTINGS_MODULE', 'breathecode.settings')

application = get_asgi_application()

Mmm I tried 

application = newrelic.agent.ASGIApplicationWrapper()

And this didn't work

  File "/usr/lib/python3.12/importlib/__init__.py", line 90, in import_module
    return _bootstrap._gcd_import(name[level:], package, level)
           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "<frozen importlib._bootstrap>", line 1387, in _gcd_import
  File "<frozen importlib._bootstrap>", line 1360, in _find_and_load
  File "<frozen importlib._bootstrap>", line 1331, in _find_and_load_unlocked
  File "<frozen importlib._bootstrap>", line 935, in _load_unlocked
  File "<frozen importlib._bootstrap_external>", line 995, in exec_module
  File "<frozen importlib._bootstrap>", line 488, in _call_with_frames_removed
  File "/home/jefer/dev/work/apiv2/breathecode/asgi.py", line 25, in <module>
    application = newrelic.agent.ASGIApplicationWrapper()
                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
TypeError: ASGIApplicationWrapper() missing 1 required positional argument: 'wrapped'

I don't know what you mean with instrumentation

hmstepanek commented 3 months ago

I'm suggesting that you use the newrelic-admin as your entry point instead of calling the newrelic api directly. For example: newrelic-admin gunicorn --bind :8000 --workers 3 breathecode.wsgi:application and similarly newrelic-admin uvicorn --bind :8000 --workers 3 breathecode.asgi:application . Then in your code you can remove the calls to newrelic.agent.initialize() and application = newrelic.agent.ASGIApplicationWrapper(application). Also, as an aside, if you want to disable the instrumentation you can use the following environment variable (instead of an if statement like you have above): NEW_RELIC_MONITOR_MODE=false.

When running with newrelic-admin it will automatically apply the instrumentation correctly based on whether you are using ASGI or WSGI. Based on what you posted above it looks like you are manually wrapping your application object in a newrelic api wrapper called, ASGIApplicationWrapper. This is unnecessary and could be causing it to wrap our asgi application wrapper around our wsgi application wrapper which is what that stack trace is indicating. The stack trace makes me think you are applying our newrelic api incorrectly and it is causing a crash. This can be understandably tricky to do, which is why we provide the newrelic-admin script as it just takes care of all that stuff for you. Our instrumentation automatically detects various web application frameworks (including Django) and automatically applies the appropriate wsgi and asgi application wrappers so there's no need to call our api directly and apply instrumentation yourself.

jefer94 commented 3 months ago

It fixed my issue, but this behavior is really weird

workato-integration[bot] commented 1 month ago

Work has been completed on this issue.