Starlette Request change to _form attribute breaks rollbar starlette integration

[srisi]

Rollbar uses the _.form attribute from a starlette request to extract POST form data:

pyrollbar/rollbar/__init__.py

Lines 1393 to 1397 in c3b6510

	if hasattr(request, '_form'):
	request_data['POST'] = {
	k: v.filename if isinstance(v, UploadFile) else v
	for k, v in request._form.items()
	}

However, the starlette Request was changed in February to have a default _form value of None:
https://github.com/encode/starlette/blob/b3add7e7ac61c16af953644e2778ea32d9e125ba/starlette/requests.py#L190-L202

This breaks the rollbar request parsing since it expects the data to be form data to be a dict.

Likely if hasattr(request, '_form') and isinstance(request, dict) would do the trick.

[configureng]

This also breaks the fastapi integration as well as it relies on starlette. Trying to get the request body from a post just errors.

[ayharano]

I was wondering if isn't there another way to access the form data without relying on _form as it is a protected attribute, indicating that it is subject to inner (nonpublic) changes.

[ghost]

Hey, Thanks for reporting this issue. We'll look into this and I'll get back to you whenever we have a solution.

[phillipuniverse]

@srisi if you look at the RollbarLoggingRouteHandler, you can see that the request.body() and request.form() is invoked, presumably to prevent exactly such a problem from occurring

pyrollbar/rollbar/contrib/fastapi/routing.py

Lines 86 to 92 in 853ee85

	except Exception:
	# FastAPI requires the `python-multipart` package to parse the content
	if not request._stream_consumed:
	await request.body()
	await request.form()
	exc_info = sys.exc_info()

Thus, the form and body is retrieved successfully if your endpoint raises an exception, example:

from fastapi.applications import FastAPI
from rollbar.contrib.fastapi.routing import RollbarLoggingRoute

app = FastAPI()

rollbar_router = APIRouter(route_class=RollbarLoggingRoute())


@rollbar_router.post("/exception")
async def ok(body: dict[str, str]) -> None:
    raise ValueError("Failed!")  # Rollbar gets logged with request body

However, if you hookup the Rollbar logging handler and do a logger.error(), that breaks down as you indicated. Here's an example that exhibits the exception you posted:

from fastapi.applications import FastAPI
from rollbar.contrib.fastapi.routing import RollbarLoggingRoute
from rollbar.logger import RollbarHandler

logger = logging.getLogger(__name__)
logger.addHandler(RollbarHandler())

app = FastAPI()

rollbar_router = APIRouter(route_class=RollbarLoggingRoute())


@rollbar_router.post("/handled-error")
async def log_error_and_move_on(body: dict[str, str]) -> dict[str, str]:
    logger.error("Something bad happened")
    return {"message": "moved on"}

The fix is a little obtuse because you have to bridge between sync and async code, and specifically if running inside or outside an event loop (which means things like asyncio.run() are out).

Here's a monkeypatch that is working in my environment, hope it helps you! Put this next to wherever you have your rollbar.init():

import rollbar

orig_add_fastapi_request_data = rollbar._build_fastapi_request_data

def request_body_adding_rollbar_data(request: Any) -> Any:
    """
    The request body and form data are lazily instantiated and it is possible that if there was
    no exception captured by the rollbar.contrib.fastapi.routing.RollbarLoggingRoute and instead
    just a logger.error(), this might not have been read

    This copies in the functionality from the rollbar.contrib.fastapi.routing.RollbarLoggingRoute
    in case a Rollbar is emitted within a FastAPI endpoint (e.g. a logger.error())
    """

    async def init_request_body():
        if not request._stream_consumed:
            await request.body()
        await request.form()

    # End-around way to make this work inside and outside a running event loop
    with ThreadPoolExecutor(1) as pool:
        pool.submit(lambda: asyncio.run(init_request_body())).result()

    return orig_add_fastapi_request_data(request)

rollbar._build_fastapi_request_data = request_body_adding_rollbar_data

[phillipuniverse]

Here's another fix that doesn't go with a "sledgehammer" approach to tie up the event loop to read in the form and body. This works around the issue in the parent function by just setting the ._form attribute to an empty dictionary before calling the parent, then sets it back to None before continuing

import rollbar

orig_add_fastapi_request_data = rollbar._build_fastapi_request_data

def allow_form_data_none_fastapi_request_data(request: Any) -> Any:
    """
    The request body and form data are lazily instantiated and it is possible that if there was
    no exception captured by the rollbar.contrib.fastapi.routing.RollbarLoggingRoute and instead
    just a logger.error(), this might not have been read

    This sets the _form to an empty dictionary to allow the parent function to run without
    an exception
    """

    form_data_set = False
    if hasattr(request, "_form") and request._form is None:
        request._form = {}
        form_data_set = True
    result = orig_add_fastapi_request_data(request)
    if form_data_set:
        request._form = None
    return result

rollbar._build_fastapi_request_data = allow_form_data_none_fastapi_request_data

[ghost]

Thanks @phillipuniverse for jumping on this one, I appreciate your help :) @srisi @configureng @ayharano Can you confirm if this workaround works for you?

[ayharano]

Hi @rollbar-bborsits

I was able to use @phillipuniverse #423 (comment) solution and it seems to be working with the most recent FastAPI and Starlette versions

However, as the solution was placed in the rollbar client's app side, the rollbar item listing displays Python icon, not FastAPI

If a solution could be based on that and placed inside pyrollbar, I would appreciate.

Python version 3.10

Packages:

fastapi==0.97.0
rollbar==0.16.3
starlette[full]==0.27.0

services/rollbar.py

# From https://github.com/rollbar/pyrollbar/issues/423#issuecomment-1574067802

from typing import Any

import rollbar

orig_add_fastapi_request_data = rollbar._build_fastapi_request_data


def allow_form_data_none_fastapi_request_data(request: Any) -> Any:
    """
    The request body and form data are lazily instantiated and it is possible that if there was
    no exception captured by the rollbar.contrib.fastapi.routing.RollbarLoggingRoute and instead
    just a logger.error(), this might not have been read

    This sets the _form to an empty dictionary to allow the parent function to run without
    an exception
    """

    form_data_set = False
    if hasattr(request, "_form") and request._form is None:
        request._form = {}
        form_data_set = True
    result = orig_add_fastapi_request_data(request)
    if form_data_set:
        request._form = None
    return result


rollbar._build_fastapi_request_data = allow_form_data_none_fastapi_request_data


__all__ = ["rollbar"]

app/main.py

from fastapi import FastAPI

...

from settings.config import settings

...

app = FastAPI()

...

if settings.ENABLE_ROLLBAR_LOGGING:
    from rollbar.contrib.fastapi import LoggerMiddleware
    from rollbar.contrib.fastapi import add_to as rollbar_add_to

    from services.rollbar import rollbar  # here - using the altered rollbar object to then use `init`

    rollbar_add_to(app)
    rollbar.init(
        settings.ROLLBAR_ACCESS_TOKEN,
        environment=f"{settings.ENVIRONMENT}-suffix",
        handler="async",
    )

    # According to the Rollbar documentation, the LoggerMiddleware must be added last:
    # - https://docs.rollbar.com/docs/fastapi#integrate-with-logging-handler
    app.add_middleware(LoggerMiddleware)