aws-powertools / powertools-lambda-python

A developer toolkit to implement Serverless best practices and increase developer velocity.
https://docs.powertools.aws.dev/lambda/python/latest/
MIT No Attribution
2.82k stars 391 forks source link

Bug: APIGatewayRestResolver(enable_validation=True) is validating middleware responses #5228

Open ob1-dev opened 7 hours ago

ob1-dev commented 7 hours ago

Expected Behaviour

Given the documentation, I would have expected the Validation to be skipped in the situation a middleware responds before the request gets to the route handler.

Current Behaviour

Current behaviour is that my error handler captures a the raise in the OpenAPI validation

{
  "level": "ERROR",
  "location": "handle_error_boundary:51",
  "message": "Error in GET /test: ",
  "timestamp": "2024-09-24 13:24:05,393+0000",
  "service": "test",
  "sampling_rate": "0.1",
  "cold_start": true,
  "function_name": "ApiFunction",
  "function_memory_size": "128",
  "function_arn": "arn:aws:lambda:us-east-1:012345678912:function:ApiFunction",
  "function_request_id": "e67d066f-c78e-4367-88cd-2bc6e9c48894",
  "correlation_id": "07c501c3-9b3b-45fd-aaba-d5c6598f8b7c",
  "path": "/test",
  "query_strings": {},
  "exec_info": "",
  "exception": "Traceback (most recent call last):\n  File \"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py\", line 2277, in _call_route\n    route(router_middlewares=self._router_middlewares, app=self, route_arguments=route_arguments),\n    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py\", line 432, in __call__\n    return self._middleware_stack(app)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py\", line 1409, in __call__\n    return self.current_middleware(app, self.next_middleware)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/base.py\", line 121, in __call__\n    return self.handler(app, next_middleware)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py\", line 136, in handler\n    return self._handle_response(route=route, response=response)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py\", line 143, in _handle_response\n    response.body = self._serialize_response(\n                    ^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py\", line 178, in _serialize_response\n    raise RequestValidationError(errors=_normalize_errors(errors), body=response_content)\naws_lambda_powertools.event_handler.openapi.exceptions.RequestValidationError",
  "exception_name": "RequestValidationError",
  "stack_trace": {
    "type": "RequestValidationError",
    "value": "",
    "module": "aws_lambda_powertools.event_handler.openapi.exceptions",
    "frames": [
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/api_gateway.py",
        "line": 2277,
        "function": "_call_route",
        "statement": "route(router_middlewares=self._router_middlewares, app=self, route_arguments=route_arguments),"
      },
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/api_gateway.py",
        "line": 432,
        "function": "__call__",
        "statement": "return self._middleware_stack(app)"
      },
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/api_gateway.py",
        "line": 1409,
        "function": "__call__",
        "statement": "return self.current_middleware(app, self.next_middleware)"
      },
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/middlewares/base.py",
        "line": 121,
        "function": "__call__",
        "statement": "return self.handler(app, next_middleware)"
      },
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py",
        "line": 136,
        "function": "handler",
        "statement": "return self._handle_response(route=route, response=response)"
      },
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py",
        "line": 143,
        "function": "_handle_response",
        "statement": "response.body = self._serialize_response("
      },
      {
        "file": "/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py",
        "line": 178,
        "function": "_serialize_response",
        "statement": "raise RequestValidationError(errors=_normalize_errors(errors), body=response_content)"
      }
    ]
  }
}

Code snippet

from aws_lambda_powertools.event_handler import (
    APIGatewayRestResolver,
    Response
)
from pydantic import BaseModel, ConfigDict
from aws_lambda_powertools import Logger, Tracer
from aws_lambda_powertools.logging import correlation_paths
from aws_lambda_powertools.event_handler.openapi.exceptions import (
    RequestValidationError,
)
from aws_lambda_powertools.event_handler.middlewares import NextMiddleware

import json

###
#   Test middleware
###
def test_middleware(app: APIGatewayRestResolver, next_middleware: NextMiddleware):
    # return next_middleware(app)
    return Response(status_code=401,content_type="application/json", body="{}")

def test_middleware2(app: APIGatewayRestResolver, next_middleware: NextMiddleware):
    resp = next_middleware(app)
    print(resp)
    return resp

###
#   Test Pydantic Validation
###
class TestModel(BaseModel):
    model_config = ConfigDict(from_attributes=True)
    name: str
    age: int

logger = Logger(service="test")
tracer = Tracer(service="test")

app = APIGatewayRestResolver(enable_validation=True)
app.use(middlewares=[test_middleware2, test_middleware])

@app.exception_handler(Exception)
def handle_error_boundary(ex: Exception):
    metadata = {
        "path": app.current_event.path,
        "query_strings": app.current_event.query_string_parameters,
    }
    logger.exception(
        f"Error in {app.current_event.http_method} {app.current_event.path}: {ex}",
        exec_info=ex,
        extra=metadata,
    )
    return Response(
        status_code=500,
        content_type="application/json",
        body=json.dumps({"error": "Internal server error"}),
    )

@app.get("/test")
@tracer.capture_method
def test() -> TestModel:
    return {"name": "Chris", "age": 30}

@logger.inject_lambda_context(
    correlation_id_path=correlation_paths.API_GATEWAY_REST, log_event=True
)
@tracer.capture_lambda_handler
def handler(event, context):
    return app.resolve(event, context)

Possible Solution

Perhaps the support of the Union of responses from an endpoint, or in the event a request doesn't make it to the route that Validation isn't performed.

Steps to Reproduce

template.yml

AWSTemplateFormatVersion: "2010-09-09"
Transform: AWS::Serverless-2016-10-31
Description: Hello world event handler API Gateway

Globals:
  Api:
    TracingEnabled: true
    BinaryMediaTypes: # see Binary responses section
      - "*~1*" # converts to */* for any binary type
      # NOTE: use this stricter version if you're also using CORS; */* doesn't work with CORS
      # see: https://github.com/aws-powertools/powertools-lambda-python/issues/3373#issuecomment-1821144779
      # - "image~1*" # converts to image/*
      # - "*~1csv" # converts to */csv, eg text/csv, application/csv

  Function:
    Timeout: 5
    Runtime: python3.12
    Tracing: Active
    Environment:
      Variables:
        POWERTOOLS_LOG_LEVEL: DEBUG
        POWERTOOLS_LOGGER_SAMPLE_RATE: 0.1
        POWERTOOLS_LOGGER_LOG_EVENT: true
        POWERTOOLS_SERVICE_NAME: example

Resources:
  MyLayer:
    Type: AWS::Serverless::LayerVersion
    Properties:
      LayerName: MyLayer
      ContentUri: .
      CompatibleRuntimes:
        - python3.12
    Metadata:
      BuildMethod: python3.12
  ApiFunction:
    Type: AWS::Serverless::Function
    Properties:
      Handler: lambda_test.handler
      CodeUri: src
      Description: API handler function
      Layers:
        - !Ref MyLayer
      Events:
        AnyApiEvent:
          Type: Api
          Properties:
            # NOTE: this is a catch-all rule to simplify the documentation.
            # explicit routes and methods are recommended for prod instead (see below)
            Path: /{proxy+} # Send requests on any path to the lambda function
            Method: ANY # Send requests using any http method to the lambda function

pyproject.toml

[tool.poetry]
name = "powertools-demo"
version = "0.1.0"
description = ""
authors = ["ob1-dev <chris+github@ob1.nz>"]
readme = "README.md"

[tool.poetry.dependencies]
python = "^3.12"
aws-lambda-powertools = {extras = ["pydantic", "tracer"], version = "^3.0.0"}
pydantic = "^2.9.2"

[build-system]
requires = ["poetry-core"]
build-backend = "poetry.core.masonry.api"

Preparing the requirements.txt

poetry export -f requirements.txt --without-hashes --output requirements.txt

SAM Build and Local Start-API

sam build; sam local start-api

Browse to localhost

Hitting specifically http://localhost:3000/test will now trigger the validation error

Powertools for AWS Lambda (Python) version

latest

AWS Lambda function runtime

3.12

Packaging format used

Lambda Layers

Debugging logs

START RequestId: 94462763-631d-45a9-87e1-2ae225a7f317 Version: $LATEST
{"level":"INFO","location":"decorate:445","message":{"body":null,"headers":{"Accept":"text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7","Accept-Encoding":"gzip, deflate, br, zstd","Accept-Language":"en-US,en;q=0.9","Cache-Control":"max-age=0","Connection":"keep-alive","Dnt":"1","Host":"127.0.0.1:3000","Sec-Ch-Ua":"\"Chromium\";v=\"129\", \"Not=A?Brand\";v=\"8\"","Sec-Ch-Ua-Mobile":"?0","Sec-Ch-Ua-Platform":"\"macOS\"","Sec-Fetch-Dest":"document","Sec-Fetch-Mode":"navigate","Sec-Fetch-Site":"none","Sec-Fetch-User":"?1","Upgrade-Insecure-Requests":"1","User-Agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36","X-Forwarded-Port":"3000","X-Forwarded-Proto":"http"},"httpMethod":"GET","isBase64Encoded":true,"multiValueHeaders":{"Accept":["text/html,application/xhtml+xml,application/xml;q=0.9,image/avif,image/webp,image/apng,*/*;q=0.8,application/signed-exchange;v=b3;q=0.7"],"Accept-Encoding":["gzip, deflate, br, zstd"],"Accept-Language":["en-US,en;q=0.9"],"Cache-Control":["max-age=0"],"Connection":["keep-alive"],"Dnt":["1"],"Host":["127.0.0.1:3000"],"Sec-Ch-Ua":["\"Chromium\";v=\"129\", \"Not=A?Brand\";v=\"8\""],"Sec-Ch-Ua-Mobile":["?0"],"Sec-Ch-Ua-Platform":["\"macOS\""],"Sec-Fetch-Dest":["document"],"Sec-Fetch-Mode":["navigate"],"Sec-Fetch-Site":["none"],"Sec-Fetch-User":["?1"],"Upgrade-Insecure-Requests":["1"],"User-Agent":["Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36"],"X-Forwarded-Port":["3000"],"X-Forwarded-Proto":["http"]},"multiValueQueryStringParameters":null,"path":"/test","pathParameters":{"proxy":"test"},"queryStringParameters":null,"requestContext":{"accountId":"123456789012","apiId":"1234567890","domainName":"127.0.0.1:3000","extendedRequestId":null,"httpMethod":"GET","identity":{"accountId":null,"apiKey":null,"caller":null,"cognitoAuthenticationProvider":null,"cognitoAuthenticationType":null,"cognitoIdentityPoolId":null,"sourceIp":"127.0.0.1","user":null,"userAgent":"Custom User Agent String","userArn":null},"path":"/{proxy+}","protocol":"HTTP/1.1","requestId":"37fea8d1-981b-435e-9c95-37e0ce86c7f6","requestTime":"24/Sep/2024:13:33:27 +0000","requestTimeEpoch":1727184807,"resourceId":"123456","resourcePath":"/{proxy+}","stage":"Prod"},"resource":"/{proxy+}","stageVariables":null},"timestamp":"2024-09-24 13:33:39,740+0000","service":"test","sampling_rate":"0.1","cold_start":true,"function_name":"ApiFunction","function_memory_size":"128","function_arn":"arn:aws:lambda:us-east-1:012345678912:function:ApiFunction","function_request_id":"bd54493d-19af-4d67-9d52-b3fb859bd5f2","correlation_id":"37fea8d1-981b-435e-9c95-37e0ce86c7f6"}
<aws_lambda_powertools.event_handler.api_gateway.Response object at 0x7ffffdb173b0>
{"level":"ERROR","location":"handle_error_boundary:51","message":"Error in GET /test: ","timestamp":"2024-09-24 13:33:39,745+0000","service":"test","sampling_rate":"0.1","cold_start":true,"function_name":"ApiFunction","function_memory_size":"128","function_arn":"arn:aws:lambda:us-east-1:012345678912:function:ApiFunction","function_request_id":"bd54493d-19af-4d67-9d52-b3fb859bd5f2","correlation_id":"37fea8d1-981b-435e-9c95-37e0ce86c7f6","path":"/test","query_strings":{},"exec_info":"","exception":"Traceback (most recent call last):\n  File \"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py\", line 2277, in _call_route\n    route(router_middlewares=self._router_middlewares, app=self, route_arguments=route_arguments),\n    ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py\", line 432, in __call__\n    return self._middleware_stack(app)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py\", line 1409, in __call__\n    return self.current_middleware(app, self.next_middleware)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/base.py\", line 121, in __call__\n    return self.handler(app, next_middleware)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py\", line 136, in handler\n    return self._handle_response(route=route, response=response)\n           ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py\", line 143, in _handle_response\n    response.body = self._serialize_response(\n                    ^^^^^^^^^^^^^^^^^^^^^^^^^\n  File \"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py\", line 178, in _serialize_response\n    raise RequestValidationError(errors=_normalize_errors(errors), body=response_content)\naws_lambda_powertools.event_handler.openapi.exceptions.RequestValidationError","exception_name":"RequestValidationError","stack_trace":{"type":"RequestValidationError","value":"","module":"aws_lambda_powertools.event_handler.openapi.exceptions","frames":[{"file":"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py","line":2277,"function":"_call_route","statement":"route(router_middlewares=self._router_middlewares, app=self, route_arguments=route_arguments),"},{"file":"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py","line":432,"function":"__call__","statement":"return self._middleware_stack(app)"},{"file":"/opt/python/aws_lambda_powertools/event_handler/api_gateway.py","line":1409,"function":"__call__","statement":"return self.current_middleware(app, self.next_middleware)"},{"file":"/opt/python/aws_lambda_powertools/event_handler/middlewares/base.py","line":121,"function":"__call__","statement":"return self.handler(app, next_middleware)"},{"file":"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py","line":136,"function":"handler","statement":"return self._handle_response(route=route, response=response)"},{"file":"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py","line":143,"function":"_handle_response","statement":"response.body = self._serialize_response("},{"file":"/opt/python/aws_lambda_powertools/event_handler/middlewares/openapi_validation.py","line":178,"function":"_serialize_response","statement":"raise RequestValidationError(errors=_normalize_errors(errors), body=response_content)"}]}}
END RequestId: bd54493d-19af-4d67-9d52-b3fb859bd5f2
boring-cyborg[bot] commented 7 hours ago

Thanks for opening your first issue here! We'll come back to you as soon as we can. In the meantime, check out the #python channel on our Powertools for AWS Lambda Discord: Invite link

ob1-dev commented 7 hours ago

For others experiencing the issue that, like me, was dependent on this behaviour to go from SQLAlchemy objects to JSON without really knowing the internals of pydantic, here is the workaround

If my example above adding an assumed ORM object

@app.get("/test")
@tracer.capture_method
def test() -> TestModel:
    ORM_OBJECT = method_to_go_get_thing_from_db()
    return TestModel.model_validate(ORM_OBJECT).model_dump_json()
leandrodamascena commented 6 hours ago

Hey @ob1-dev! Thanks for reporting this! I'm able to reproduce the behavior here and I'm going to check the code to see what is going on.