New issue related to the new package uvicorn_worker.UvicornWorker (the last one was deprecated)

[jefer94]

That solved my issue breatheco-de/apiv2@1d2d47c...edffa12

2024-09-11T15:03:24.476212+00:00 app[web.1]: 190.240.161.182:0 - "GET / HTTP/1.1" 500
2024-09-11T15:03:24.592011+00:00 app[web.1]: [2024-09-11 15:03:24 +0000] [29] [ERROR] Exception in ASGI application
2024-09-11T15:03:24.592013+00:00 app[web.1]: Traceback (most recent call last):
2024-09-11T15:03:24.592014+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/protocols/http/h11_impl.py", line 406, in run_asgi
2024-09-11T15:03:24.592014+00:00 app[web.1]:     result = await app(  # type: ignore[func-returns-value]
2024-09-11T15:03:24.592015+00:00 app[web.1]:              ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592015+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/middleware/proxy_headers.py", line 70, in __call__
2024-09-11T15:03:24.592015+00:00 app[web.1]:     return await self.app(scope, receive, send)
2024-09-11T15:03:24.592018+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592019+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/uvicorn/middleware/asgi2.py", line 15, in __call__
2024-09-11T15:03:24.592019+00:00 app[web.1]:     await instance(receive, send)
2024-09-11T15:03:24.592019+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 357, in nr_async_asgi
2024-09-11T15:03:24.592020+00:00 app[web.1]:     return await coro
2024-09-11T15:03:24.592020+00:00 app[web.1]:            ^^^^^^^^^^
2024-09-11T15:03:24.592020+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/common/async_proxy.py", line 148, in __next__
2024-09-11T15:03:24.592021+00:00 app[web.1]:     return self.send(None)
2024-09-11T15:03:24.592022+00:00 app[web.1]:            ^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592022+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/common/async_proxy.py", line 120, in send
2024-09-11T15:03:24.592022+00:00 app[web.1]:     return self.__wrapped__.send(value)
2024-09-11T15:03:24.592023+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592023+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 69, in __call__
2024-09-11T15:03:24.592023+00:00 app[web.1]:     return await self.app(scope, receive, self.send_inject_browser_agent)
2024-09-11T15:03:24.592024+00:00 app[web.1]:                  ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592024+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 48, in double_to_single_callable
2024-09-11T15:03:24.592024+00:00 app[web.1]:     coro_function = wrapped(scope)
2024-09-11T15:03:24.592025+00:00 app[web.1]:                     ^^^^^^^^^^^^^^
2024-09-11T15:03:24.592025+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/wsgi_application.py", line 564, in _nr_wsgi_application_wrapper_
2024-09-11T15:03:24.592026+00:00 app[web.1]:     return wrapped(*args, **kwargs)
2024-09-11T15:03:24.592026+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592026+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/wsgi_application.py", line 564, in _nr_wsgi_application_wrapper_
2024-09-11T15:03:24.592035+00:00 app[web.1]:     return wrapped(*args, **kwargs)
2024-09-11T15:03:24.592035+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592036+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/wsgi_application.py", line 564, in _nr_wsgi_application_wrapper_
2024-09-11T15:03:24.592036+00:00 app[web.1]:     return wrapped(*args, **kwargs)
2024-09-11T15:03:24.592036+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^
2024-09-11T15:03:24.592037+00:00 app[web.1]: TypeError: WSGIHandler.__call__() missing 1 required positional argument: 'start_response'
2024-09-11T15:03:24.592160+00:00 app[web.1]: 190.240.161.182:0 - "GET /favicon.ico HTTP/1.1" 500

Pipfile.lock
https://github.com/breatheco-de/apiv2/blob/edffa12373a6f6e9196b08232a5efd032ece8993/Pipfile.lock#L1

#!/bin/env bash

WEB_WORKER_CONNECTION=${WEB_WORKER_CONNECTION:-200}
# uvicorn_worker.UvicornWorker is incompatible with new relic
uvicorn.workers.UvicornWorker
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

[workato-integration]

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

[jefer94]

https://www.uvicorn.org/deployment/#gunicorn

[TimPansino]

It sounds like you're having issues due to redundant instrumentation. If you're using Django as the base web framework and a combination of gunicorn + uvicorn-worker, then you should not have any need to import or call any functions in the newrelic package. It sounds like you've manually called these things based on the previous bug report you filed, which is generally only advised if you're not using a supported framework.

If you weren't seeing data when using newrelic-admin before, it could be for a couple of reasons.

1. I don't see a NEW_RELIC_CONFIG_FILE environment variable pointing to your config, if there's no configuration for the agent in most cases it doesn't start up. You may already have all the config set outside this bash script though.
2. Your exact placement of newrelic-admin could be an issue, although I'm unsure what your bin/start-pgbouncer-stunnel does under the hood. If this is a non-python utility making subprocesses, you may need to move newrelic-admin to directly wrap gunicorn. You could try the following instead.

bin/start-pgbouncer-stunnel \
    newrelic-admin run-program gunicorn ...

Example App

To help simplify the debugging process, here's a one file example Django application that doesn't use any newrelic APIs directly and correctly reports data. I've included an example config file to go with it and a bash script that can start the app using 1 of 3 different configurations of uvicorn and or gunicorn.

main.py

import os
from django.http import HttpResponse
from django.urls import path
from django.core.asgi import get_asgi_application
from django.core.wsgi import get_wsgi_application

# Settings
os.environ.setdefault("DJANGO_SETTINGS_MODULE", "main")
ROOT_URLCONF = "main"


# Views
def index(request):
    return HttpResponse("Hello from Django! (sync view)")


async def async_index(request):
    return HttpResponse("Hello from Django! (async view)")


# URLs
urlpatterns = [
    path("", index, name="index"),
    path("async", async_index, name="async_index"),
]

# ASGI
asgi_application = get_asgi_application()

# WSGI
wsgi_application = get_wsgi_application()

newrelic.ini

[newrelic]
license_key = <YOUR_LICENSE_KEY>
app_name = django_uvicorn_worker_demo
log_level = debug
log_file = agent.log
audit_log_file = audit.log

startup_timeout = 10.0
transaction_tracer.explain_threshold = 0.0
transaction_tracer.transaction_threshold = 0.0
transaction_tracer.stack_trace_threshold = 0.0

run.sh

#!/bin/bash

export NEW_RELIC_CONFIG_FILE=newrelic.ini
newrelic-admin run-program gunicorn main:asgi_application -k uvicorn_worker.UvicornWorker
# These also work instead of gunicorn + uvicorn
# newrelic-admin run-program gunicorn main:wsgi_application
# newrelic-admin run-program uvicorn main:asgi_application

requirements.txt

newrelic==9.13.0
Django==5.1.1
gunicorn==23.0.0
uvicorn==0.30.6
uvicorn-worker==0.2.0

[jefer94]

Mmmm not, I'm not having double instrumentation https://github.com/breatheco-de/apiv2/blob/edffa12373a6f6e9196b08232a5efd032ece8993/breathecode/asgi.py and if this was the case, this couldn't get fixed changing the package from uvicorn_worker to uvicorn

[TimPansino]

2024-09-11T15:03:24.592024+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/asgi_application.py", line 48, in double_to_single_callable
2024-09-11T15:03:24.592024+00:00 app[web.1]:     coro_function = wrapped(scope)
2024-09-11T15:03:24.592025+00:00 app[web.1]:                     ^^^^^^^^^^^^^^
2024-09-11T15:03:24.592025+00:00 app[web.1]:   File "/app/.heroku/python/lib/python3.12/site-packages/newrelic/api/wsgi_application.py", line 564, in _nr_wsgi_application_wrapper_
2024-09-11T15:03:24.592026+00:00 app[web.1]:     return wrapped(*args, **kwargs)
2024-09-11T15:03:24.592026+00:00 app[web.1]:            ^^^^^^^^^^^^^^^^^^^^^^^^

I can see double instrumentation in the traceback you've provided, meaning something here is misconfigured. There shouldn't be a WSGI wrapper underneath the ASGI wrapper.

The test application I provided should demonstrate that uvicorn-worker is fully compatible with the agent. We don't have specific instrumentation hooks for either of the modules uvicorn.workers or uvicorn_worker. There should be no difference between them.

Perhaps your version of uvicorn is changed between your 2 deployments?

[jefer94]

I should test them later, but if there is double instrumentation, where is it?

[TimPansino]

I posted the relevant lines of your traceback, there's a WSGI wrapper on bottom and an ASGI wrapper on top of that. The ASGI wrapper should be the only one, meaning something is interfering with the normal operation of the gunicorn/uvicorn worker.

[workato-integration]

All attempts at reproducing this issue failed, or not enough information was available to reproduce the issue. Reading the code produces no clues as to why this behavior would occur. If more information appears later, please reopen the issue.