diff --git a/core/allnet.py b/core/allnet.py index 0594542..c938a88 100644 --- a/core/allnet.py +++ b/core/allnet.py @@ -95,14 +95,19 @@ class AllnetServlet: def handle_poweron(self, request: Request, _: Dict): request_ip = request.getClientAddress().host try: - req = AllnetPowerOnRequest(self.allnet_req_to_dict(request.content.getvalue())[0]) + req_dict = self.allnet_req_to_dict(request.content.getvalue()) + if req_dict is None: + raise AllnetRequestException() + + req = AllnetPowerOnRequest(req_dict[0]) # Validate the request. Currently we only validate the fields we plan on using if not req.game_id or not req.ver or not req.token or not req.serial or not req.ip: raise AllnetRequestException(f"Bad auth request params from {request_ip} - {vars(req)}") except AllnetRequestException as e: - self.logger.error(e) + if e.message != "": + self.logger.error(e) return b"" if req.format_ver == 3: @@ -155,14 +160,19 @@ class AllnetServlet: def handle_dlorder(self, request: Request, _: Dict): request_ip = request.getClientAddress().host try: - req = AllnetDownloadOrderRequest(self.allnet_req_to_dict(request.content.getvalue())[0]) + req_dict = self.allnet_req_to_dict(request.content.getvalue()) + if req_dict is None: + raise AllnetRequestException() + + req = AllnetDownloadOrderRequest(req_dict[0]) # Validate the request. Currently we only validate the fields we plan on using if not req.game_id or not req.ver or not req.serial: raise AllnetRequestException(f"Bad download request params from {request_ip} - {vars(req)}") except AllnetRequestException as e: - self.logger.error(e) + if e.message != "": + self.logger.error(e) return b"" resp = AllnetDownloadOrderResponse() @@ -265,7 +275,7 @@ class AllnetServlet: return self.kvp_to_dict(sections) except Exception as e: - self.logger.error(e) + self.logger.error(f"billing_req_to_dict: {e} while parsing {data}") return None def allnet_req_to_dict(self, data: str) -> Optional[List[Dict[str, Any]]]: @@ -280,7 +290,7 @@ class AllnetServlet: return self.kvp_to_dict(sections) except Exception as e: - self.logger.error(e) + self.logger.error(f"allnet_req_to_dict: {e} while parsing {data}") return None def dict_to_http_form_string(self, data:List[Dict[str, Any]], crlf: bool = False, trailing_newline: bool = True) -> Optional[str]: @@ -307,7 +317,7 @@ class AllnetServlet: return urlencode except Exception as e: - self.logger.error(e) + self.logger.error(f"dict_to_http_form_string: {e} while parsing {data}") return None class AllnetPowerOnRequest(): @@ -407,6 +417,6 @@ class BillingResponse(): # YYYY -> 4 digit year, MM -> 2 digit month, C -> Playcount during that period class AllnetRequestException(Exception): - def __init__(self, message="Allnet Request Error") -> None: + def __init__(self, message="") -> None: self.message = message super().__init__(self.message) diff --git a/index.py b/index.py index 7f28e82..da1a11b 100644 --- a/index.py +++ b/index.py @@ -1,5 +1,7 @@ #!/usr/bin/env python3 import argparse +import logging, coloredlogs +from logging.handlers import TimedRotatingFileHandler from typing import Dict import yaml from os import path, mkdir, access, W_OK @@ -17,6 +19,7 @@ class HttpDispatcher(resource.Resource): self.isLeaf = True self.map_get = Mapper() self.map_post = Mapper() + self.logger = logging.getLogger("core") self.allnet = AllnetServlet(cfg, config_dir) self.title = TitleServlet(cfg, config_dir) @@ -33,28 +36,36 @@ class HttpDispatcher(resource.Resource): self.map_get.connect("title_get", "/{game}/{version}/{endpoint:.*?}", controller="title", action="render_GET", conditions=dict(method=['GET']), requirements=dict(game=R"S...")) self.map_post.connect("title_post", "/{game}/{version}/{endpoint:.*?}", controller="title", action="render_POST", conditions=dict(method=['POST']), requirements=dict(game=R"S...")) - def render_POST(self, request: Request) -> bytes: + def render_GET(self, request: Request) -> bytes: test = self.map_get.match(request.uri.decode()) if test is None: - return b"" + self.logger.debug(f"Unknown GET endpoint {request.uri.decode()} from {request.getClientAddress().host} to port {request.getHost().port}") + request.setResponseCode(404) + return b"Endpoint not found." return self.dispatch(test, request) def render_POST(self, request: Request) -> bytes: test = self.map_post.match(request.uri.decode()) if test is None: - return b"" + self.logger.debug(f"Unknown POST endpoint {request.uri.decode()} from {request.getClientAddress().host} to port {request.getHost().port}") + request.setResponseCode(404) + return b"Endpoint not found." return self.dispatch(test, request) def dispatch(self, matcher: Dict, request: Request) -> bytes: controller = getattr(self, matcher["controller"], None) if controller is None: - return b"" + self.logger.error(f"Controller {matcher['controller']} not found via endpoint {request.uri.decode()}") + request.setResponseCode(404) + return b"Endpoint not found." handler = getattr(controller, matcher["action"], None) if handler is None: - return b"" + self.logger.error(f"Action {matcher['action']} not found in controller {matcher['controller']} via endpoint {request.uri.decode()}") + request.setResponseCode(404) + return b"Endpoint not found." url_vars = matcher url_vars.pop("controller") @@ -80,18 +91,37 @@ if __name__ == "__main__": cfg: CoreConfig = CoreConfig() cfg.update(yaml.safe_load(open(f"{args.config}/core.yaml"))) + logger = logging.getLogger("core") + if not hasattr(logger, "initialized"): + log_fmt_str = "[%(asctime)s] Core | %(levelname)s | %(message)s" + log_fmt = logging.Formatter(log_fmt_str) + + fileHandler = TimedRotatingFileHandler("{0}/{1}.log".format(cfg.server.log_dir, "core"), when="d", backupCount=10) + fileHandler.setFormatter(log_fmt) + + consoleHandler = logging.StreamHandler() + consoleHandler.setFormatter(log_fmt) + + logger.addHandler(fileHandler) + logger.addHandler(consoleHandler) + + # TODO: Add log level for core to config + logger.setLevel(cfg.allnet.loglevel) + coloredlogs.install(level=cfg.allnet.loglevel, logger=logger, fmt=log_fmt_str) + logger.initialized = True + if not path.exists(cfg.server.log_dir): mkdir(cfg.server.log_dir) if not access(cfg.server.log_dir, W_OK): - print(f"Log directory {cfg.server.log_dir} NOT writable, please check permissions") + logger.error(f"Log directory {cfg.server.log_dir} NOT writable, please check permissions") exit(1) if not cfg.aimedb.key: - print("!!AIMEDB KEY BLANK, SET KEY IN CORE.YAML!!") + logger.error("!!AIMEDB KEY BLANK, SET KEY IN CORE.YAML!!") exit(1) - print(f"ARTEMiS starting in {'develop' if cfg.server.is_develop else 'production'} mode") + logger.info(f"ARTEMiS starting in {'develop' if cfg.server.is_develop else 'production'} mode") allnet_server_str = f"tcp:{cfg.allnet.port}:interface={cfg.server.listen_address}" title_server_str = f"tcp:{cfg.title.port}:interface={cfg.server.listen_address}"