Fix logging and use coloredlogs for nicer output

api/config.dev.py

@@ -1,6 +1,7 @@
 HOST = "0.0.0.0"
 PORT = 3000
 DEBUG = True
+VERBOSE = False
 AUTO_RESTART = True
 SECRET = "!!!!!!!!!!!!CHANGE ME!!!!!!!!!!!!"
 POSTGRES_URL = "postgresql+asyncpg://obs:obs@postgres/obs"

api/config.py.example

@@ -4,6 +4,7 @@ PORT = 3000
 
 # Extended log output, but slower
 DEBUG = False
+VERBOSE = DEBUG
 AUTO_RESTART = DEBUG
 
 # Required to encrypt or sign sessions, cookies, tokens, etc.

api/obs/api/app.py

@@ -24,7 +24,7 @@ from obs.api.db import User, make_session, connect_db
 
 log = logging.getLogger(__name__)
 
-app = Sanic("OpenBikeSensor Portal API")
+app = Sanic("OpenBikeSensor Portal API", log_config={})
 app.update_config("./config.py")
 c = app.config
 
@@ -32,8 +32,8 @@ api = Blueprint("api", url_prefix="/api")
 auth = Blueprint("auth", url_prefix="")
 
 
-@api.exception(SanicException, BaseException)
-def _handle_sanic_errors(_request, exception):
+@app.exception(SanicException, BaseException)
+async def _handle_sanic_errors(_request, exception):
     log.error("Exception in handler: %s", exception, exc_info=True)
     return json_response(
         {

api/obs/api/routes/login.py

@@ -18,6 +18,8 @@ log = logging.getLogger(__name__)
 
 client = Client(client_authn_method=CLIENT_AUTHN_METHOD)
 
+# Do not show verbose library output, even when the appliaction is in debug mode
+logging.getLogger('oic').setLevel(logging.INFO)
 
 @auth.before_server_start
 async def connect_auth_client(app, loop):

api/obs/bin/openbikesensor_api.py

@@ -1,28 +1,64 @@
 #!/usr/bin/env python3
 
+import math
 import sys
 import os
 import argparse
 import asyncio
 import logging
 
+import coloredlogs
+
 from obs.api.app import app
 from obs.api.db import connect_db
 
+log = logging.getLogger(__name__)
+
+
+def format_size(n, b=1024):
+    if n == 0:
+        return "0 B"
+    if n < 0:
+        return "-" + format_size(n, b)
+    e = math.floor(math.log(n, b))
+    prefixes = ["", "Ki", "Mi", "Gi", "Ti"] if b == 1024 else ["", "K", "M", "G", "T"]
+    e = min(e, len(prefixes) - 1)
+    r = n / b**e
+    s = f"{r:0.2f}" if e > 0 else str(n)
+    return f"{s} {prefixes[e]}B"
+
+
+class AccessLogFilter(logging.Filter):
+    def filter(self, record):
+        if not record.msg:
+            record.msg = (
+                f"{record.request} - {record.status} ({format_size(record.byte)})"
+            )
+        return True
+
 
 def main():
     debug = app.config.DEBUG
 
-    logging.basicConfig(
-        level=logging.DEBUG if debug else logging.INFO,
-        format="%(levelname)s: %(message)s",
+    coloredlogs.install(
+        level=logging.DEBUG if app.config.get("VERBOSE", debug) else logging.INFO,
+        milliseconds=True,
+        isatty=True,
     )
 
+    for ln in ["sanic.root", "sanic.error", "sanic.access"]:
+        l = logging.getLogger(ln)
+        for h in list(l.handlers):
+            l.removeHandler(h)
+
+    logging.getLogger("sanic.access").addFilter(AccessLogFilter())
+
     app.run(
         host=app.config.HOST,
         port=app.config.PORT,
         debug=debug,
         auto_reload=app.config.get("AUTO_RELOAD", debug),
+        # access_log=False,
     )
 
 

api/requirements.txt

@@ -1,3 +1,4 @@
+coloredlogs~=15.0.1
 sanic~=21.9.3
 oic~=1.3.0
 sanic-session~=0.8.0

api/setup.py

@@ -10,6 +10,7 @@ setup(
     packages=find_packages(),
     package_data={},
     install_requires=[
+        "coloredlogs~=15.0.1",
         "sanic~=21.9.3",
         "oic>=1.3.0, <2",
         "sanic-session~=0.8.0",