Merge pull request #65 from chr1st1ank/fastapi-support

Fastapi backend

Author: bobbui

.github/workflows/code_quality.yml

@@ -35,7 +35,6 @@ jobs:
     runs-on: ubuntu-latest
 
     strategy:
-      max-parallel: 4
       matrix:
         python-version: ["3.7", "3.8", "3.9"]
 
@@ -52,4 +51,28 @@ jobs:
           pip install -r test-requirements.txt
       - name: Run tests
         run:  |
-          pytest
+          pytest --ignore tests/smoketests
+
+  backendSmoketests:
+    name: Individual Backend Smoketests
+    runs-on: ubuntu-latest
+
+    strategy:
+      matrix:
+        backend: ["fastapi", "flask", "quart", "sanic"]
+
+    steps:
+      - name: Set up Python ${{ matrix.python-version }}
+        uses: actions/setup-python@v2
+        with:
+          python-version: 3.9
+      - name: "Git checkout"
+        uses: actions/checkout@v2
+      - name: Install dependencies
+        run: |
+          python -m pip install --upgrade pip
+          pip install -r tests/smoketests/${{ matrix.backend }}/requirements.txt
+      - name: Run tests
+        run:  |
+          export backend=${{ matrix.backend }}
+          pytest tests/smoketests/test_run_smoketest.py

README.md

@@ -23,7 +23,7 @@ If you're using Cloud Foundry, it might worth to check out the library [SAP/cf-p
 2. Lightweight, no dependencies, minimal configuration needed (1 LoC to get it working)
 3. Seamlessly integrate with Python native **logging** module. Support both Python 2.7.x and 3.x
 4. Auto extract **correlation-id** for distributed tracing [\[1\]](#1-what-is-correlation-idrequest-id)
-5. Support HTTP request instrumentation. Built in support for [Flask](https://github.com/pallets/flask/), [Sanic](https://github.com/channelcat/sanic), [Quart](https://gitlab.com/pgjones/quart), [Connexion](https://github.com/zalando/connexion). Extensible to support other web frameworks. PR welcome :smiley: .
+5. Support HTTP request instrumentation. Built in support for [FastAPI](https://fastapi.tiangolo.com/), [Flask](https://github.com/pallets/flask/), [Sanic](https://github.com/channelcat/sanic), [Quart](https://gitlab.com/pgjones/quart), [Connexion](https://github.com/zalando/connexion). Extensible to support other web frameworks. PR welcome :smiley: .
 6. Highly customizable: support inject arbitrary extra properties to JSON log message, override logging formatter, etc.  
 7. Production ready, has been used in production since 2017
 
@@ -52,8 +52,31 @@ logger.info("test logging statement")
 ```
 
 ## 2.2 Web application log
-### Flask
+### FastAPI
+```python
+import datetime, logging, sys, json_logging, fastapi, uvicorn
+
+app = fastapi.FastAPI()
+json_logging.init_fastapi(enable_json=True)
+json_logging.init_request_instrument(app)
+
+# init the logger as usual
+logger = logging.getLogger("test-logger")
+logger.setLevel(logging.DEBUG)
+logger.addHandler(logging.StreamHandler(sys.stdout))
 
+@app.get('/')
+def home():
+    logger.info("test log statement")
+    logger.info("test log statement with extra props", extra={'props': {"extra_property": 'extra_value'}})
+    correlation_id = json_logging.get_correlation_id()
+    return "Hello world : " + str(datetime.datetime.now())
+
+if __name__ == "__main__":
+    uvicorn.run(app, host='0.0.0.0', port=5000)
+```
+
+### Flask
 ```python
 import datetime, logging, sys, json_logging, flask
 
@@ -102,7 +125,7 @@ async def home(request):
     return sanic.response.text("hello world")
 
 if __name__ == "__main__":
-    app.run(host="0.0.0.0", port=8000)
+    app.run(host="0.0.0.0", port=5000)
 ```
 
 ### Quart
@@ -227,7 +250,7 @@ ResponseAdapter | Helper class help to extract logging-relevant information from
 FrameworkConfigurator |  Class to perform logging configuration for given framework as needed | no
 AppRequestInstrumentationConfigurator | Class to perform request instrumentation logging configuration | no
 
-Take a look at [**json_logging/base_framework.py**](blob/master/json_logging/framework_base.py), [**json_logging.flask**](tree/master/json_logging/framework/flask) and [**json_logging.sanic**](/tree/master/json_logging/framework/sanic) packages for reference implementations.
+Take a look at [**json_logging/base_framework.py**](json_logging/framework_base.py), [**json_logging.flask**](json_logging/framework/flask) and [**json_logging.sanic**](json_logging/framework/sanic) packages for reference implementations.
 
 # 6. FAQ & Troubleshooting
 1. I configured everything, but no logs are printed out?

example/fastapi_sample_app.py

@@ -0,0 +1,56 @@
+import logging
+
+import fastapi
+
+import json_logging
+
+app = fastapi.FastAPI()
+
+# init the logger as usual
+logger = logging.getLogger(__name__)
+logger.setLevel(logging.DEBUG)
+
+@app.get('/')
+async def home():
+    logger.info("test log statement")
+    logger.info("test log statement with extra props", extra={'props': {"extra_property": 'extra_value'}})
+    correlation_id = json_logging.get_correlation_id()
+    return "hello world" \
+           "\ncorrelation_id                    : " + correlation_id
+
+
+@app.get('/exception')
+def exception():
+    try:
+        raise RuntimeError
+    except BaseException as e:
+        logger.error("Error occurred", exc_info=e)
+        logger.exception("Error occurred", exc_info=e)
+    return "Error occurred, check log for detail"
+
+
+@app.get('/exclude_from_request_instrumentation')
+def exclude_from_request_instrumentation():
+    return "this request wont log request instrumentation information"
+
+
+if __name__ == "__main__":
+    import uvicorn
+    logging_config = {
+        'version': 1,
+        'disable_existing_loggers': False,
+        'handlers': {
+            'default_handler': {
+                'class': 'logging.StreamHandler',
+                'level': 'DEBUG',
+            },
+        },
+        'loggers': {
+            '': {
+                'handlers': ['default_handler'],
+            }
+        }
+    }
+    json_logging.init_fastapi(enable_json=True)
+    json_logging.init_request_instrument(app, exclude_url_patterns=[r'^/exclude_from_request_instrumentation'])
+    uvicorn.run(app, host='0.0.0.0', port=5000, log_level="debug", log_config=logging_config)

json_logging/__init__.py

@@ -395,3 +395,16 @@ def init_quart(custom_formatter=None, enable_json=False):
 
 def init_connexion(custom_formatter=None, enable_json=False):
     __init(framework_name='connexion', custom_formatter=custom_formatter, enable_json=enable_json)
+
+
+# register FastAPI support
+import json_logging.framework.fastapi as fastapi_support
+
+if fastapi_support.is_fastapi_present():
+    register_framework_support('fastapi', app_configurator=None,
+                               app_request_instrumentation_configurator=fastapi_support.FastAPIAppRequestInstrumentationConfigurator,
+                               request_adapter_class=fastapi_support.FastAPIRequestAdapter,
+                               response_adapter_class=fastapi_support.FastAPIResponseAdapter)
+
+def init_fastapi(custom_formatter=None, enable_json=False):
+    __init(framework_name='fastapi', custom_formatter=custom_formatter, enable_json=enable_json)

json_logging/framework/fastapi/__init__.py

@@ -0,0 +1,13 @@
+
+def is_fastapi_present():
+    # noinspection PyPep8,PyBroadException
+    try:
+        import fastapi
+        import starlette
+        return True
+    except:
+        return False
+
+
+if is_fastapi_present():
+    from .implementation import FastAPIAppRequestInstrumentationConfigurator, FastAPIRequestAdapter, FastAPIResponseAdapter

json_logging/framework/fastapi/implementation.py

@@ -0,0 +1,122 @@
+import logging
+
+import json_logging
+import json_logging.framework
+from json_logging.framework_base import AppRequestInstrumentationConfigurator, RequestAdapter, ResponseAdapter
+
+from json_logging.util import is_not_match_any_pattern
+
+import fastapi
+import starlette.requests
+import starlette.responses
+
+from starlette.middleware.base import BaseHTTPMiddleware, RequestResponseEndpoint
+from starlette.requests import Request
+from starlette.responses import Response
+from starlette.types import ASGIApp
+
+
+class JSONLoggingASGIMiddleware(BaseHTTPMiddleware):
+    def __init__(self, app: ASGIApp, exclude_url_patterns=tuple()) -> None:
+        super().__init__(app)
+        self.request_logger = logging.getLogger('fastapi-request-logger')
+        self.exclude_url_patterns = exclude_url_patterns
+        logging.getLogger("uvicorn.access").propagate = False
+
+    async def dispatch(self, request: Request, call_next: RequestResponseEndpoint) -> Response:
+        log_request = is_not_match_any_pattern(request.url.path, self.exclude_url_patterns)
+
+        if not log_request:
+            return await call_next(request)
+
+        request_info = json_logging.RequestInfo(request)
+        response = await call_next(request)
+        request_info.update_response_status(response)
+        self.request_logger.info(
+            "", extra={"request_info": request_info, "type": "request"}
+        )
+        return response
+
+
+class FastAPIAppRequestInstrumentationConfigurator(AppRequestInstrumentationConfigurator):
+    def config(self, app, exclude_url_patterns=tuple()):
+        if not isinstance(app, fastapi.FastAPI):
+            raise RuntimeError("app is not a valid fastapi.FastAPI instance")
+
+        # Disable standard logging
+        logging.getLogger('uvicorn.access').disabled = True
+
+        # noinspection PyAttributeOutsideInit
+        self.request_logger = logging.getLogger('fastapi-request-logger')
+
+        app.add_middleware(JSONLoggingASGIMiddleware, exclude_url_patterns=exclude_url_patterns)
+
+
+class FastAPIRequestAdapter(RequestAdapter):
+    @staticmethod
+    def get_request_class_type():
+        return starlette.requests.Request
+
+    @staticmethod
+    def support_global_request_object():
+        return False
+
+    @staticmethod
+    def get_current_request():
+        raise NotImplementedError
+
+    def get_remote_user(self, request: starlette.requests.Request):
+        try:
+            return request.user
+        except AssertionError:
+            return json_logging.EMPTY_VALUE
+
+    def get_http_header(self, request: starlette.requests.Request, header_name, default=None):
+        try:
+            if header_name in request.headers:
+                return request.headers.get(header_name)
+        except:
+            pass
+        return default
+
+    def set_correlation_id(self, request_, value):
+        request_.state.correlation_id = value
+
+    def get_correlation_id_in_request_context(self, request: starlette.requests.Request):
+        try:
+            return request.state.correlation_id
+        except AttributeError:
+            return None
+
+    def get_protocol(self, request: starlette.requests.Request):
+        protocol = str(request.scope.get('type', ''))
+        http_version = str(request.scope.get('http_version', ''))
+        if protocol.lower() == 'http' and http_version:
+            return protocol.upper() + "/" + http_version
+        return json_logging.EMPTY_VALUE
+
+    def get_path(self, request: starlette.requests.Request):
+        return request.url.path
+
+    def get_content_length(self, request: starlette.requests.Request):
+        return request.headers.get('content-length', json_logging.EMPTY_VALUE)
+
+    def get_method(self, request: starlette.requests.Request):
+        return request.method
+
+    def get_remote_ip(self, request: starlette.requests.Request):
+        return request.client.host
+
+    def get_remote_port(self, request: starlette.requests.Request):
+        return request.client.port
+
+
+class FastAPIResponseAdapter(ResponseAdapter):
+    def get_status_code(self, response: starlette.responses.Response):
+        return response.status_code
+
+    def get_response_size(self, response: starlette.responses.Response):
+        return response.headers.get('content-length', json_logging.EMPTY_VALUE)
+
+    def get_content_type(self, response: starlette.responses.Response):
+        return response.headers.get('content-type', json_logging.EMPTY_VALUE)

json_logging/util.py

@@ -120,7 +120,7 @@ def __new__(cls, *args, **kw):
 
         return cls._instance
 
-    def get_correlation_id(self, request=None,within_formatter=False):
+    def get_correlation_id(self, request=None, within_formatter=False):
         """
         Gets the correlation id from the header of the request. \
         It tries to search from json_logging.CORRELATION_ID_HEADERS list, one by one.\n

test-requirements.txt

@@ -3,6 +3,9 @@ flask
 connexion[swagger-ui]
 quart
 sanic
+fastapi
+uvicorn
+requests
 flake8
 pytest
 -e .

tests/README.md

@@ -0,0 +1,11 @@
+# Organization of the test folder
+
+```
+├───helpers         Shared functionality for all tests
+├───smoketests      A test script to run all API examples and see if they work
+│   ├───fastapi
+│   ├───flask
+│   ├───quart
+│   └───sanic
+└───test_*.py       Unit tests
+```

tests/helpers/imports.py

@@ -0,0 +1,9 @@
+"""Helper functions related to module imports"""
+import sys
+
+
+def undo_imports_from_package(package: str):
+    """Removes all imported modules from the given package from sys.modules"""
+    for k in sorted(sys.modules.keys(), key=lambda s: len(s), reverse=True):
+        if k == package or k.startswith(package + '.'):
+            del sys.modules[k]

tests/smoketests/fastapi/api.py

@@ -0,0 +1,20 @@
+import datetime, logging, sys, json_logging, fastapi, uvicorn
+
+app = fastapi.FastAPI()
+json_logging.init_fastapi(enable_json=True)
+json_logging.init_request_instrument(app)
+
+# init the logger as usual
+logger = logging.getLogger("test-logger")
+logger.setLevel(logging.DEBUG)
+logger.addHandler(logging.StreamHandler(sys.stdout))
+
+@app.get('/')
+def home():
+    logger.info("test log statement")
+    logger.info("test log statement with extra props", extra={'props': {"extra_property": 'extra_value'}})
+    correlation_id = json_logging.get_correlation_id()
+    return "Hello world : " + str(datetime.datetime.now())
+
+if __name__ == "__main__":
+    uvicorn.run(app, host='0.0.0.0', port=5000)

tests/smoketests/fastapi/requirements.txt

@@ -0,0 +1,5 @@
+fastapi
+uvicorn
+requests
+pytest
+-e .

tests/smoketests/flask/api.py

@@ -0,0 +1,20 @@
+import datetime, logging, sys, json_logging, flask
+
+app = flask.Flask(__name__)
+json_logging.init_flask(enable_json=True)
+json_logging.init_request_instrument(app)
+
+# init the logger as usual
+logger = logging.getLogger("test-logger")
+logger.setLevel(logging.DEBUG)
+logger.addHandler(logging.StreamHandler(sys.stdout))
+
+@app.route('/')
+def home():
+    logger.info("test log statement")
+    logger.info("test log statement with extra props", extra={'props': {"extra_property": 'extra_value'}})
+    correlation_id = json_logging.get_correlation_id()
+    return "Hello world : " + str(datetime.datetime.now())
+
+if __name__ == "__main__":
+    app.run(host='0.0.0.0', port=int(5000), use_reloader=False)