diff --git a/src/logging_config/config.json b/src/logging_config/config.json new file mode 100644 index 000000000..e205d0296 --- /dev/null +++ b/src/logging_config/config.json @@ -0,0 +1,61 @@ +{ + "version": 1, + "disable_existing_loggers": false, + "formatters": { + "simple": { + "format": " %(asctime)s - %(levelname)s - %(message)s", + "datefmt": "%Y-%m-%dT%H:%M:%S%z" + }, + "detailed": { + "format": " %(asctime)s - %(levelname)s - [%(module)s|L%(lineno)d] - %(message)s", + "datefmt": "%Y-%m-%dT%H:%M:%S%z" + } + }, + "filters": { + "no_errors": { + "()": "warnet.utils.NonErrorFilter" + } + }, + "handlers": { + "stdout": { + "class": "logging.StreamHandler", + "level": "DEBUG", + "formatter": "simple", + "filters": ["no_errors"], + "stream": "ext://sys.stdout" + }, + "stderr": { + "class": "logging.StreamHandler", + "level": "WARNING", + "formatter": "simple", + "stream": "ext://sys.stderr" + }, + "file": { + "class": "logging.handlers.RotatingFileHandler", + "level": "DEBUG", + "formatter": "detailed", + "filename": "warnet.log", + "maxBytes": 16000000, + "backupCount": 3 + } + }, + "loggers": { + "root": { + "level": "DEBUG", + "handlers": [ + "stdout", + "stderr", + "file" + ] + }, + "urllib3.connectionpool": { + "level": "WARNING", + "propagate": 1 + }, + + "kubernetes.client.rest": { + "level": "WARNING", + "propagate": 1 + } + } +} diff --git a/src/warnet/server.py b/src/warnet/server.py index 9b8478e5e..6a11aca13 100644 --- a/src/warnet/server.py +++ b/src/warnet/server.py @@ -1,6 +1,8 @@ import argparse import base64 +import json import logging +import logging.config import os import pkgutil import platform @@ -14,8 +16,6 @@ import traceback from datetime import datetime from io import BytesIO -from logging import StreamHandler -from logging.handlers import RotatingFileHandler from pathlib import Path import jsonschema @@ -35,6 +35,7 @@ WARNET_SERVER_PORT = 9276 CONFIG_DIR_ALREADY_EXISTS = 32001 +LOGGING_CONFIG_PATH = Path("src/logging_config/config.json") class Server: @@ -60,12 +61,10 @@ def __init__(self, backend): self.jsonrpc = JSONRPC(self.app, "/api") self.log_file_path = os.path.join(self.basedir, "warnet.log") - self.logger: logging.Logger self.setup_global_exception_handler() self.setup_logging() self.setup_rpc() self.logger.info("Started server") - self.app.add_url_rule("/-/healthy", view_func=self.healthy) # register a well known /-/healthy endpoint for liveness tests # we regard warnet as healthy if the http server is up @@ -101,30 +100,23 @@ def healthy(self): return "warnet is healthy" def setup_logging(self): - # Ensure the directory exists os.makedirs(os.path.dirname(self.log_file_path), exist_ok=True) - # Configure root logger - logging.basicConfig( - level=logging.DEBUG, - handlers=[ - RotatingFileHandler( - self.log_file_path, maxBytes=16_000_000, backupCount=3, delay=True - ), - StreamHandler(sys.stdout), - ], - format="%(asctime)s - %(name)s - %(levelname)s - %(message)s", - ) - # Disable urllib3.connectionpool logging - logging.getLogger("urllib3.connectionpool").setLevel(logging.CRITICAL) + with open(LOGGING_CONFIG_PATH) as f: + logging_config = json.load(f) + + # Update log file path + logging_config["handlers"]["file"]["filename"] = str(self.log_file_path) + + # Apply the config + logging.config.dictConfig(logging_config) + self.logger = logging.getLogger("warnet") self.logger.info("Logging started") - if self.backend == "k8s": - # if using k8s as a backend, tone the logging down - logging.getLogger("kubernetes.client.rest").setLevel(logging.WARNING) - def log_request(): + if "healthy" in request.path: + return # No need to log all these if not request.path.startswith("/api/"): self.logger.debug(request.path) else: @@ -439,7 +431,7 @@ def thread_start(wn): wn.apply_network_conditions() wn.wait_for_health() self.logger.info( - f"Resumed warnet named '{network}' from config dir {wn.config_dir}" + f"Successfully resumed warnet named '{network}' from config dir {wn.config_dir}" ) except Exception as e: trace = traceback.format_exc() @@ -472,6 +464,7 @@ def thread_start(wn, lock: threading.Lock): wn.warnet_up() wn.wait_for_health() wn.apply_network_conditions() + self.logger.info("Warnet started successfully") except Exception as e: trace = traceback.format_exc() self.logger.error(f"Unhandled exception starting warnet: {e}\n{trace}") diff --git a/src/warnet/tank.py b/src/warnet/tank.py index 279194084..18551498a 100644 --- a/src/warnet/tank.py +++ b/src/warnet/tank.py @@ -62,12 +62,13 @@ def _parse_version(self): def parse_graph_node(self, node): # Dynamically parse properties based on the schema + graph_properties = {} for property, specs in self.warnet.node_schema["properties"].items(): value = node.get(property, specs.get("default")) if property == "version": self._parse_version() setattr(self, property, value) - logger.debug(f"{property}={value}") + graph_properties[property] = value if self.version and self.image: raise Exception( @@ -83,7 +84,8 @@ def parse_graph_node(self, node): self.config_dir = self.warnet.config_dir / str(self.suffix) self.config_dir.mkdir(parents=True, exist_ok=True) - logger.debug(f"{self=:}") + + logger.debug(f"Parsed graph node: {self.index} with attributes: {[f'{key}={value}' for key, value in graph_properties.items()]}") @classmethod def from_graph_node(cls, index, warnet, tank=None): diff --git a/src/warnet/utils.py b/src/warnet/utils.py index 25ee1c72c..43b837d36 100644 --- a/src/warnet/utils.py +++ b/src/warnet/utils.py @@ -36,6 +36,12 @@ NODE_SCHEMA_PATH = SCHEMA / "node_schema.json" +class NonErrorFilter(logging.Filter): + + def filter(self, record: logging.LogRecord) -> bool | logging.LogRecord: + return record.levelno <= logging.INFO + + def exponential_backoff(max_retries=5, base_delay=1, max_delay=32): """ A decorator for exponential backoff.