Incorrect method handler called for GET request

Hi

I’ve been experiencing a strange issue inconsistently in a project I am working on. The issue arises when a GET request is made to one of my endpoints and is handled by the POST handler at the same url. I am desperately trying to understand why this is happening as it makes no sense to me.

Here is my setup:

report_route = Blueprint("report", url_prefix="/report")

login_required = login_required(read_only_handlers=[f"{report_route.name}.root", f"{report_route.name}.post_information_page"], required_roles=["admin", "reporting"])

@report_route.get("/")
@login_required
async def root(request, user, **kwargs):
...

@report_route.post("/")
@login_required
async def update_report(request, user, **kwargs):
...
def login_required(read_only_handlers=[], required_roles=[], exclude_roles=[], billing_required=True):
    def decorator(f):
        @wraps(f)
        def decorated_function(request: Request, *args, **kwargs):
            try:
                try:
                    serialized_token = request.headers.get("Authorization").split()[1]
                except:
                    serialized_token = request.cookies.get("token")
                    if not serialized_token: 
                        raise Exception("No token, sign in")
                
                user_id = serializer.loads(str.encode(serialized_token)).get("user_id")
                user = User.get(request.ctx.db, user_id)
                if not user: raise Exception("User not found")
            except Exception as e:
                logger.debug(request.endpoint)
                logger.debug(request.method)
                logger.debug(read_only_handlers)
                logger.debug(request.headers)
                logger.debug(request.cookies)
                if any([x in request.endpoint for x in read_only_handlers]):
                    return f(request, *args, user=None, **kwargs)

                return redirect(request.app.url_for("login_page"))

Sometimes when a GET request is made to

/report?token=WyIxOSIsIjIwMjEtMDUtMDMgMTM6NDU6MjQuOTc5OTI4Il0.fhuz6VEiOn1A7NCNaaZv0tmnyQQ

The output is as follows:

neon_analytics    | 2021-05-03 13:45:25.955 | DEBUG    | routes.auth:decorated_function:69 - __main__.report.update_report
neon_analytics    | 2021-05-03 13:45:25.955 | DEBUG    | routes.auth:decorated_function:70 - GET
neon_analytics    | 2021-05-03 13:45:25.955 | DEBUG    | routes.auth:decorated_function:71 - ['report.root', 'report.post_information_page']
neon_analytics    | 2021-05-03 13:45:25.955 | DEBUG    | routes.auth:decorated_function:72 - <Header('host': 'xxxxx.xxx.xx', 'user-agent': 'Mozilla/5.0 (Macintosh; Intel Mac OS X 10.14; rv:87.0) Gecko/20100101 Firefox/87.0', 'accept': '*/*', 'accept-encoding': 'gzip, deflate, br', 'accept-language': 'en-US,en;q=0.9', 'dnt': '1', 'x-forwarded-for': 'xxx.xx.xx.xxx', 'x-forwarded-proto': 'https')>
neon_analytics    | 2021-05-03 13:45:25.956 | DEBUG    | routes.auth:decorated_function:73 - {}

…but the login page is returned.

As you can see, request.endpoint is the POST request handler (__main__.report.update_report) and not the GET request handler as expected even though request.method is GET.

A useful point of information might be that when the GET method is called with a specific argument, it makes a request to an external server which makes the unauthenticated request to the read-only page, which completes before the wrapped request is completed.

Any ideas?

Can you check the version of sanic and sanic-routing?

Hey, sure thing

sanic==21.3.2
sanic-routing==0.5.2

I think if you update to 21.3.4 (which should install sanic-routing 0.6.2), this problem should be addressed. LMK.

Will give that a try thanks!