ASGI External Trace

I’m trying to instrument external service call in a FastAPI application using the Stalette Middleware described here: Feature Idea: Starlette/Responder Framework Support

No external services are being shown. It seems that the transaction is only available inside the __call__ method of the middleware, and not anywhere else.

I’m running my app with the following command:

newrelic-admin run-program gunicorn -k uvicorn.workers.UvicornWorker -c "$GUNICORN_CONF" "$APP_MODULE"

  • What language agent version are you using? Any other relevant versions? (Packages, etc.)
    Python 3.7.5 / NewRelic Agent 5.4.1.134

  • What error message are you seeing if any? Paste in text or add a screenshot:
    No errors.

  • Describe what are you seeing? How does that differ than what were you expecting to see?
    No external trace appears on UI.

Apparently, this only works if the Starlette Middleware has no other BaseHTTPMiddleware applied after, which is not the case. Any ideas?

Hi @victor.lima,

Although I do not currently have an immediate workaround, I’m curious to know how exactly you are attempting to add the external service to the transaction? I’m hoping this information would help paint a clearer picture on my end. :slight_smile:

Hi!

I’m using the ExternalTrace context manager.
One thing I noticed is that the transaction is not available if I have another middleware that implements the BaseHTTPMiddleware from Starlette after the NewRelic middleware, which is strange :confused:.

CORSMiddleware also needs to be added before NewRelic one.

My currently applied middlewares:

app.add_middleware(SentryMiddleware)
app.add_middleware(NewRelicMiddleware)
app.add_middleware(OpenCensusMiddleware)
app.add_middleware(
    CORSMiddleware,
    allow_origins=["*"],
    allow_credentials=True,
    allow_methods=["*"],
    allow_headers=["*"],
)

OpenCensus middleware for more info:

class OpenCensusMiddleware(BaseHTTPMiddleware):
async def dispatch(self, request: Request, call_next):
    propagator = trace_context_http_header_format.TraceContextPropagator()
    span_context = propagator.from_headers(request.headers)
    tracer = Tracer(
        span_context=span_context,
        exporter=exporter,
        sampler=sampler,
        propagator=propagator,
    )
    with tracer.span(f"[{request.method}]{request.url}") as span:
        span.span_kind = SpanKind.SERVER
        span.add_attribute(HTTP_HOST, request.url.hostname)
        span.add_attribute(HTTP_METHOD, request.method)
        span.add_attribute(HTTP_URL, request.url.netloc)
        span.add_attribute(HTTP_PATH, request.url.path)
        span.add_attribute(HTTP_ROUTE, request.url.path)
        response = await call_next(request)
        span.add_attribute(HTTP_STATUS_CODE, response.status_code)
    tracer.finish()
    return response

Hi there @victor.lima,

Alas, I’m not having much luck reproducing this on my end. :disappointed:

I’m wondering if this has to do with the way the agent is integrated (within the middleware). One thing I am noticing is an un-instrumented module banner when I view the application in the UI, specifically the asyncio module, which generally indicates an agent import/integration issue.

I recommend reaching out to your account team to see if they have any other ideas for this scenario.

Thanks for the response!

I will try to make a sample project, if that’s ok, over the weekend showing the problem!

1 Like

Thanks @victor.lima - let us know when you have a chance to try that out.

1 Like

The issue likely has to do with that the middleware code and the application code where the external trace is used are not being run in the same thread.

Fastapi runs path operations differently based on if they are defined with def or async def. Routes defined as a usual sync methods are run in another threadpool so it doesnt block the main fastapi thread.

NewRelic transactions seem to be stored in a thread specific cache. Since the transaction is created in the middleware which is run in the main thread, it is not available to the external traces that are defined inside application code. Added example logs here.

With a sync path (def):

current thread:  139944094387872
---------------
middleware:  <newrelic.api.web_transaction.WebTransaction object at 0x7f4744967da0>
---------------

current thread:  139944093902592
---------------
sync path:  None
---------------

2020-01-29 08:36:14,422 - uvicorn.access - INFO - 172.24.0.1:38154 - "GET /sync-path/ HTTP/1.1" 200

With an async path (defined using async def):

current thread:  139944103485224
---------------
middleware:  <newrelic.api.web_transaction.WebTransaction object at 0x7f4744969da0>
---------------

current thread:  139944103485224
---------------
async path:  <newrelic.api.web_transaction.WebTransaction object at 0x7f4744969da0>
---------------

2020-01-29 08:36:16,885 - uvicorn.access - INFO - 172.24.0.1:38158 - "GET /async-path/ HTTP/1.1" 200
1 Like

Fastapi is convenient when writing APIs even without the async features, esp. given the tooling it provides. It would be really useful to get external-trace/function-traces for it.

@BT21 - do you think we could work around the different threads issue?

To follow up, using WebTransaction as a context manager inside the path operation works out well. It does increase the code noise but ensures that the WebTransaction is running inside the same thread as the path operation, so newrelic logs work.

Instead of wrapping the entire application like this:


@app.get("/")
def health_check():
    return "hello world"

app.add_middleware(NewRelicMiddleware)

We initialize a webtransaction manually inside each path operation.

import newrelic.agent

@app.get("/")
def health_check():
    with newrelic.agent.WebTransaction(app = newrelic.agent.application(), name = "/"):
        return "hello world"

I’d think there is no easy way to support NewRelic with sync path operations defined for FastAPI w/o significant refactoring.

@victor.lima - this might be of interest if you are still using fastapi + newrelic.

4 Likes

That is cool. Thanks for sharing that workaround with the community! :slight_smile:

1 Like

@ishan.anand1 Thanks for sharing the work around.
I’m also using FastAPI and use the web_transaction decorator.
Applying the same to your above code snippet.

import newrelic.agent

@app.get("/")
@newrelic.agent.web_transaction()
def health_check():
    return "hello world"

Working fine for me.

4 Likes

aha, this is neater! Still keeps the newrelic transaction as part of the non-async path operation method, so they run in the same thread.

FastAPI does some magic involving introspection of the function signature, so I’m generally a bit hesitant using decorators around it.

3 Likes

Nice! Thanks for sharing @b.sahu1

1 Like