logging pluging and middleware helper

CHANGES.md

@@ -1,4 +1,7 @@
 # Changes
+## 0.9.0 (2021-09-27)
+- `[feature]` Logging plugin
+- `[feature]` Middleware interface - register middleware at application
 ## 0.8.2 (2021-09-23)
 - `[fix]` Fix dependency for aioredis
 ## 0.8.1 (2021-03-31)

Dockerfile

@@ -1,7 +1,7 @@
 FROM python:3.8-alpine as demo
 LABEL maintainer="madkote(at)bluewin.ch"
 RUN apk --update add --no-cache --virtual MY_DEV_PACK alpine-sdk build-base python3-dev
-RUN pip3 install fastapi-plugins uvicorn
+RUN pip3 install fastapi-plugins[all] uvicorn
 RUN mkdir -p /usr/src/app
 COPY ./scripts/demo_app.py /usr/src/app
 WORKDIR /usr/src/app

README.md

@@ -31,6 +31,7 @@ The concept is `plugin` - plug a functional utility into your application withou
  * [Health](./docs/control.md#health)
  * [Heartbeat](./docs/control.md#heartbeat)
 * [Application settings/configuration](./docs/settings.md)
+* [Logging](./docs/logger.md)
 * Celery
 * MQ
 * and much more is already in progress...
@@ -43,6 +44,7 @@ See [release notes](CHANGES.md)
  * [Redis](./docs/cache.md#redis)
  * [Scheduler](./docs/scheduler.md)
  * [Control](./docs/control.md)
+ * [Logging](./docs/logger.md)
 * `memcached` adds [Memcached](#memcached)
 * `all` add everything above
 
@@ -72,15 +74,19 @@ from fastapi_plugins.memcached import memcached_plugin
 import asyncio
 import aiojobs
 import aioredis
+import logging
 
 @fastapi_plugins.registered_configuration
 class AppSettings(
  fastapi_plugins.ControlSettings,
  fastapi_plugins.RedisSettings,
  fastapi_plugins.SchedulerSettings,
+ fastapi_plugins.LoggingSettings,
  MemcachedSettings,
 ):
  api_name: str = str(__name__)
+ logging_level: int = logging.DEBUG
+ logging_style: fastapi_plugins.LoggingStyle = fastapi_plugins.LoggingStyle.logjson
 
 
 @fastapi_plugins.registered_configuration(name='sentinel')
@@ -89,38 +95,49 @@ class AppSettingsSentinel(AppSettings):
  redis_sentinels = 'localhost:26379'
 
 
-app = fastapi.FastAPI()
+app = fastapi_plugins.register_middleware(fastapi.FastAPI())
 config = fastapi_plugins.get_config()
 
 @app.get("/")
 async def root_get(
  cache: aioredis.Redis=fastapi.Depends(fastapi_plugins.depends_redis),
- conf: pydantic.BaseSettings=fastapi.Depends(fastapi_plugins.depends_config) # noqa E501
+ conf: pydantic.BaseSettings=fastapi.Depends(fastapi_plugins.depends_config), # noqa E501
+ logger: logging.Logger=fastapi.Depends(fastapi_plugins.depends_logging)
 ) -> typing.Dict:
- return dict(ping=await cache.ping(), api_name=conf.api_name)
+ ping = await cache.ping()
+ logger.debug('root_get', extra=dict(ping=ping, api_name=conf.api_name))
+ return dict(ping=ping, api_name=conf.api_name)
 
 
 @app.post("/jobs/schedule/<timeout>")
 async def job_post(
  timeout: int=fastapi.Query(..., title='the job sleep time'),
  cache: aioredis.Redis=fastapi.Depends(fastapi_plugins.depends_redis),
  scheduler: aiojobs.Scheduler=fastapi.Depends(fastapi_plugins.depends_scheduler), # noqa E501
+ logger: logging.Logger=fastapi.Depends(fastapi_plugins.depends_logging)
 ) -> str:
  async def coro(job_id, timeout, cache):
  await cache.set(job_id, 'processing')
  try:
  await asyncio.sleep(timeout)
  if timeout == 8:
+ logger.critical('Ugly erred job %s' % job_id)
  raise Exception('ugly error')
  except asyncio.CancelledError:
  await cache.set(job_id, 'canceled')
+ logger.warning('Cancel job %s' % job_id)
  except Exception:
  await cache.set(job_id, 'erred')
+ logger.error('Erred job %s' % job_id)
  else:
  await cache.set(job_id, 'success')
+ logger.info('Done job %s' % job_id)
 
  job_id = str(uuid.uuid4()).replace('-', '')
+ logger = await fastapi_plugins.log_adapter(logger, extra=dict(job_id=job_id, timeout=timeout)) # noqa E501
+ logger.info('New job %s' % job_id)
  await cache.set(job_id, 'pending')
+ logger.debug('Pending job %s' % job_id)
  await scheduler.spawn(coro(job_id, timeout, cache))
  return job_id
 
@@ -153,6 +170,8 @@ async def memcached_demo_post(
 async def on_startup() -> None:
  await fastapi_plugins.config_plugin.init_app(app, config)
  await fastapi_plugins.config_plugin.init()
+ await fastapi_plugins.log_plugin.init_app(app, config, name=__name__)
+ await fastapi_plugins.log_plugin.init()
  await memcached_plugin.init_app(app, config)
  await memcached_plugin.init()
  await fastapi_plugins.redis_plugin.init_app(app, config=config)
@@ -174,6 +193,7 @@ async def on_shutdown() -> None:
  await fastapi_plugins.scheduler_plugin.terminate()
  await fastapi_plugins.redis_plugin.terminate()
  await memcached_plugin.terminate()
+ await fastapi_plugins.log_plugin.terminate()
  await fastapi_plugins.config_plugin.terminate()
 ```
 

alt_requirements/requirements_full.txt

@@ -1,4 +1,5 @@
 -r requirements_core.txt
 -r requirements_jobs.txt
+-r requirements_logger.txt
 -r requirements_memcached.txt
 -r requirements_redis.txt

alt_requirements/requirements_logger.txt

@@ -0,0 +1,2 @@
+-r requirements_core.txt
+python-json-logger>=2.0.*

demo.py

@@ -4,7 +4,7 @@
 '''
 :author: madkote
 :contact: madkote(at)bluewin.ch
-:copyright: Copyright 2019, madkote
+:copyright: Copyright 2021, madkote
 
 demo
 ----
@@ -14,6 +14,7 @@
 from __future__ import absolute_import
 
 import asyncio
+import logging
 import os
 import time
 
@@ -22,12 +23,10 @@
 
 import fastapi_plugins
 
-VERSION = (1, 0, 0)
-
 __all__ = []
 __author__ = 'madkote <madkote(at)bluewin.ch>'
-__version__ = '.'.join(str(x) for x in VERSION)
-__copyright__ = 'Copyright 2019, madkote'
+__version__ = '.'.join(str(x) for x in fastapi_plugins.VERSION)
+__copyright__ = 'Copyright 2021, madkote'
 
 
 class OtherSettings(pydantic.BaseSettings):
@@ -36,15 +35,17 @@ class OtherSettings(pydantic.BaseSettings):
 
 class AppSettings(
  OtherSettings,
+ fastapi_plugins.LoggingSettings,
  fastapi_plugins.RedisSettings,
  fastapi_plugins.SchedulerSettings
 ):
  api_name: str = str(__name__)
+ logging_level: int = logging.INFO
 
 
 async def test_redis():
  print('--- do redis test')
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = fastapi_plugins.RedisSettings()
  config = None
  config = AppSettings(redis_host='127.0.0.1')
@@ -71,7 +72,7 @@ async def coro(name, timeout):
  raise e
 
  print('--- do schedule test')
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = fastapi_plugins.SchedulerSettings()
  config = None
  config = AppSettings(aiojobs_limit=100)
@@ -146,9 +147,11 @@ async def coro(con, name, timeout):
  raise e
 
  print('--- do demo')
- app = fastapi.FastAPI()
- config = AppSettings()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
+ config = AppSettings(logging_style=fastapi_plugins.LoggingStyle.logfmt)
 
+ await fastapi_plugins.log_plugin.init_app(app, config, name=__name__)
+ await fastapi_plugins.log_plugin.init()
  await fastapi_plugins.redis_plugin.init_app(app=app, config=config)
  await fastapi_plugins.redis_plugin.init()
  await fastapi_plugins.scheduler_plugin.init_app(app=app, config=config)
@@ -159,20 +162,104 @@ async def coro(con, name, timeout):
  num_sleep = 0.25
 
  print('- play')
+ l = await fastapi_plugins.log_plugin()
  c = await fastapi_plugins.redis_plugin()
  s = await fastapi_plugins.scheduler_plugin()
  for i in range(num_jobs):
  await s.spawn(coro(c, str(i), i/10))
- print('- sleep', num_sleep)
+ l.info('- sleep %s' % num_sleep)
+ # print('- sleep', num_sleep)
  await asyncio.sleep(num_sleep)
- print('- check')
+ l.info('- check')
+ # print('- check')
  for i in range(num_jobs):
- print(i, '==', await c.get(str(i)))
+ l.info('%s == %s' % (i, await c.get(str(i))))
+ # print(i, '==', await c.get(str(i)))
  finally:
  print('- terminate')
  await fastapi_plugins.scheduler_plugin.terminate()
  await fastapi_plugins.redis_plugin.terminate()
- print('---test schedule done')
+ await fastapi_plugins.log_plugin.terminate()
+ print('---demo done')
+
+
+async def test_demo_custom_log():
+ async def coro(con, name, timeout):
+ try:
+ await con.set(name, '...')
+ print('> sleep', name, timeout)
+ await asyncio.sleep(timeout)
+ await con.set(name, 'done')
+ print('---> sleep done', name, timeout)
+ except asyncio.CancelledError as e:
+ print('coro cancelled', name)
+ raise e
+
+ class CustomLoggingSettings(fastapi_plugins.LoggingSettings):
+ another_format: str = '%(asctime)s %(levelname)-8s %(name)-15s %(message)s'
+
+ class CustomLoggingPlugin(fastapi_plugins.LoggingPlugin):
+ def _create_logger(
+ self, 
+ name:str, 
+ config:pydantic.BaseSettings=None
+ ) -> logging.Logger:
+ import sys
+ handler = logging.StreamHandler(stream=sys.stderr)
+ formatter = logging.Formatter(config.another_format)
+ logger = logging.getLogger(name)
+ #
+ logger.setLevel(config.logging_level)
+ handler.setLevel(config.logging_level)
+ handler.setFormatter(formatter)
+ logger.addHandler(handler)
+ return logger
+
+ class AppSettings(
+ OtherSettings,
+ fastapi_plugins.RedisSettings,
+ fastapi_plugins.SchedulerSettings,
+ CustomLoggingSettings
+ ):
+ api_name: str = str(__name__)
+ logging_level: int = logging.INFO
+
+ print('--- do demo')
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
+ config = AppSettings(logging_style=fastapi_plugins.LoggingStyle.logfmt)
+ mylog_plugin = CustomLoggingPlugin()
+
+ await mylog_plugin.init_app(app, config, name=__name__)
+ await mylog_plugin.init()
+ await fastapi_plugins.redis_plugin.init_app(app=app, config=config)
+ await fastapi_plugins.redis_plugin.init()
+ await fastapi_plugins.scheduler_plugin.init_app(app=app, config=config)
+ await fastapi_plugins.scheduler_plugin.init()
+
+ try:
+ num_jobs = 10
+ num_sleep = 0.25
+
+ print('- play')
+ l = await mylog_plugin()
+ c = await fastapi_plugins.redis_plugin()
+ s = await fastapi_plugins.scheduler_plugin()
+ for i in range(num_jobs):
+ await s.spawn(coro(c, str(i), i/10))
+ l.info('- sleep %s' % num_sleep)
+ # print('- sleep', num_sleep)
+ await asyncio.sleep(num_sleep)
+ l.info('- check')
+ # print('- check')
+ for i in range(num_jobs):
+ l.info('%s == %s' % (i, await c.get(str(i))))
+ # print(i, '==', await c.get(str(i)))
+ finally:
+ print('- terminate')
+ await fastapi_plugins.scheduler_plugin.terminate()
+ await fastapi_plugins.redis_plugin.terminate()
+ await mylog_plugin.terminate()
+ print('---demo done')
 
 
 async def test_memcached():
@@ -184,7 +271,7 @@ class MoreSettings(AppSettings, MemcachedSettings):
  memcached_prestart_tries = 5
  memcached_prestart_wait = 1
 
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = MoreSettings()
  await memcached_plugin.init_app(app=app, config=config)
  await memcached_plugin.init()
@@ -228,11 +315,18 @@ def main_demo():
  loop = asyncio.get_event_loop()
  loop.run_until_complete(test_demo())
 
+def main_demo_custom_log():
+ print(os.linesep * 3)
+ print('=' * 50)
+ loop = asyncio.get_event_loop()
+ loop.run_until_complete(test_demo_custom_log())
+
 
 if __name__ == '__main__':
  main_redis()
  main_scheduler()
  main_demo()
+ main_demo_custom_log()
  #
  try:
  main_memcached()

docker-compose.yml

@@ -5,6 +5,9 @@ services:
  environment:
  - REDIS_TYPE=redis
  - REDIS_HOST=redis
+ - LOGGING_LEVEL=10 # 0, 10, 20, 30, 40, 50
+ - LOGGING_STYLE=json # txt, json, logfmt
+ - LOGGING_FMT= # "%(asctime)s %(levelname) %(message)s"
  ports:
  - "8000:8000"
  build:

docs/cache.md

@@ -23,7 +23,7 @@ Valid variable are
  class AppSettings(OtherSettings, MemcachedSettings):
  api_name: str = str(__name__)
 
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = AppSettings()
 
  @app.get("/")
@@ -81,7 +81,7 @@ Valid variable are
  class AppSettings(OtherSettings, fastapi_plugins.RedisSettings):
  api_name: str = str(__name__)
 
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = AppSettings()
 
  @app.get("/")

docs/control.md

@@ -50,7 +50,7 @@ exception.
  return dict(myinfo='OK', mytype='counter health')
 
  myplugin = MyPluginWithHealth()
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = AppSettings()
 
  @app.get("/")
@@ -98,7 +98,7 @@ The endpoint `/control/heartbeat` returns heart beat of the application - simple
  # control_enable_heartbeat: bool = True
  # control_enable_version: bool = True
 
- app = fastapi.FastAPI()
+ app = fastapi_plugins.register_middleware(fastapi.FastAPI())
  config = AppSettings()
 
  @app.get("/")