Improve logging in release mode

rpipe/__init__.py

@@ -1 +1 @@
-__version__: str = "9.0.2"  # Must be "<major>.<minor>.<patch>", all numbers
+__version__: str = "9.0.3"  # Must be "<major>.<minor>.<patch>", all numbers

rpipe/server/admin.py

@@ -51,19 +51,19 @@ def new(self, n: int) -> list[str]:
         with self._lock:
             eol = datetime.now() + timedelta(seconds=self._UID_EXPIRE)
             self._uids.update({i: eol for i in ret})
-        self._log.info("Generated %s new UIDs", n)
+        self._log.debug("Generated %s new UIDs", n)
         return ret
 
     def verify(self, uid: str) -> bool:
-        self._log.info("Verifying UID: %s", uid)
+        self._log.debug("Verifying UID: %s", uid)
         with self._lock:
             if uid not in self._uids:
                 self._log.error("UID not found: %s", uid)
                 return False
             if datetime.now() > self._uids.pop(uid):
                 self._log.warning("UID expired: %s", uid)
                 return False
-            self._log.info("UID verified.")
+            self._log.debug("UID verified")
         return True
 
 
@@ -220,7 +220,9 @@ def _verify(state: State) -> Response:
                     return Response(status=AdminEC.unauthorized)
                 stat.signer = key_file
                 # Execute function
-                self._log.info("Signature verified. Executing %s", request.full_path)
+                if (fp := request.full_path).endswith("?"):
+                    fp = fp[:-1]
+                self._log.info("Signature verified. Executing %s", fp)
                 return func(state=state, body=msg.body)
             except Exception as e:  # pylint: disable=broad-except
                 self._log.error(e, exc_info=True)

rpipe/server/app.py

@@ -3,6 +3,7 @@
 from os import environ, close as fd_close
 from dataclasses import dataclass
 from tempfile import mkstemp
+from functools import wraps
 from pathlib import Path
 import atexit
 
@@ -17,12 +18,26 @@
 
 
 app = Flask(f"rpipe_server {__version__}")
-_REUSE_DEBUG_LOG_FILE = "_REUSE_DEBUG_LOG_FILE"
 server = Server()
 admin = Admin()
+
+_REUSE_DEBUG_LOG_FILE = "_REUSE_DEBUG_LOG_FILE"
 _LOG = "app"
 
 
+def _logged(func):
+    @wraps(func)
+    def wrapper(*args, **kwargs):
+        ret = func(*args, **kwargs)
+        if not server.debug:  # Flask already does what we want
+            if (fp := request.full_path).endswith("?"):
+                fp = fp[:-1]
+            getLogger(_LOG).info('%s - "%s %s" %d', request.host_url, request.method, fp, ret.status_code)
+        return ret
+
+    return wrapper
+
+
 #
 # Dataclasses
 #
@@ -51,17 +66,19 @@ class ServerConfig:
 
 
 @app.errorhandler(404)
+@_logged
 def _page_not_found(_, *, quiet=False) -> Response:
     lg = getLogger(_LOG)
-    lg.warning("404: Request from %s for %s", request.host_url, request.url)
+    if not quiet:
+        lg.warning("404: Not found: %s", request.path)
     (lg.debug if quiet else lg.info)("Headers: %s", request.headers)
     return Response("404: Not found", status=404)
 
 
 @app.route("/")
 @app.route("/help")
+@_logged
 def _help() -> Response:
-    getLogger(_LOG).info("Request for /help")
     msg = (
         "Welcome to the web UI of rpipe. "
         "To interact with a given channel, use the path /c/<channel>. "
@@ -83,23 +100,25 @@ def _favicon() -> Response:
 
 
 @app.route("/version")
+@_logged
 def _show_version() -> Response:
-    getLogger(_LOG).info("Request for /version")
     return plaintext(__version__)
 
 
 @app.route("/supported")
+@_logged
 def _supported() -> Response:
-    getLogger(_LOG).info("Request for /supported")
     return json_response({"min": str(MIN_VERSION), "banned": []})
 
 
 @app.route("/c/<channel>", methods=["DELETE", "GET", "POST", "PUT"])
+@_logged
 def _channel(channel: str) -> Response:
     return handler(server.state, channel)
 
 
 @app.route("/q/<channel>")
+@_logged
 def _query(channel: str) -> Response:
     return query(server.state, channel)
 
@@ -108,6 +127,7 @@ def _query(channel: str) -> Response:
 
 
 @app.route("/admin/uid")
+@_logged
 def _admin_uid() -> Response:
     """
     Get a few UIDSs needed to sign admin requests
@@ -118,26 +138,31 @@ def _admin_uid() -> Response:
 
 
 @app.route("/admin/debug", methods=["POST"])
+@_logged
 def _admin_debug() -> Response:
     return admin.debug(server.state)
 
 
 @app.route("/admin/channels", methods=["POST"])
+@_logged
 def _admin_channels() -> Response:
     return admin.channels(server.state)
 
 
 @app.route("/admin/stats", methods=["POST"])
+@_logged
 def _admin_stats() -> Response:
     return admin.stats(server.state)
 
 
 @app.route("/admin/log", methods=["POST"])
+@_logged
 def _admin_log() -> Response:
     return admin.log(server.state)
 
 
 @app.route("/admin/log-level", methods=["POST"])
+@_logged
 def _admin_log_level() -> Response:
     return admin.log_level(server.state)
 

rpipe/server/server/server.py

@@ -15,9 +15,17 @@ class Server(metaclass=Singleton):
 
     def __init__(self):
         self._log = logging.getLogger("server")
+        self._debug: bool | None = None
         self.state = State()
 
+    @property
+    def debug(self) -> bool:
+        if self._debug is None:
+            raise RuntimeError("Server not started")
+        return self._debug
+
     def start(self, debug: bool, state_file: Path | None) -> None:
+        self._debug = debug
         with self.state as s:
             s.debug = debug
         self._log.info("Initializing server")