diff --git a/config.py b/config.py index 7d57f4e..cfdd9b6 100644 --- a/config.py +++ b/config.py @@ -11,3 +11,4 @@ class Config: SERVER_RCON_PASSWORD: str | None = data.get("SERVER_RCON_PASSWORD") MAINTAINANCE_FILE = data.get("MAINTAINANCE_FILE") or "maintainance.txt" LOG_FILE = data.get("LOG_FILE") or "logs.txt" + MINECRAFTD_LOGS = data.get("MINECRAFTD_LOGS") or "debug.log" diff --git a/controllers.py b/controllers.py index 519e841..1156131 100644 --- a/controllers.py +++ b/controllers.py @@ -2,11 +2,13 @@ import shlex from collections import deque from pathlib import Path from subprocess import PIPE, Popen +from threading import Lock from time import sleep from typing import Literal from classes import ProcessStatus, ServerStatus from config import Config +from logs import logger from mcrcon import MCRcon from mcstatus import JavaServer @@ -18,38 +20,65 @@ class ProcessController: self.last_status: Literal[ProcessStatus.STOPPED, ProcessStatus.CRASHED] = ( ProcessStatus.STOPPED ) + self._lock = Lock() def start(self) -> None: "Start the process." - if self.status() == ProcessStatus.RUNNING: - return + logger.debug("ProcessController.start()") + with self._lock: + if self.status() == ProcessStatus.RUNNING: + if self.process: + logger.debug( + "ProcessController.start() - Process was already running with PID: %s", + self.process.pid, + ) + return - self.process = Popen( - self.start_command, - stdout=PIPE, - stderr=PIPE, - ) + self.process = Popen( + self.start_command, + stdout=PIPE, + stderr=PIPE, + ) + logger.info( + "ProcessController.start() - Started process with PID: %s", + self.process.pid, + ) def status(self) -> ProcessStatus: "Check the process' status." + logger.debug("ProcessController.status()") + if not self.process: + logger.debug("ProcessController.status() => %s", self.last_status) return self.last_status match self.process.poll(): case None: + logger.debug("ProcessController.status() => ProcessStatus.RUNNING") return ProcessStatus.RUNNING case 0: + logger.debug("ProcessController.status() => ProcessStatus.STOPPED") self.last_status = ProcessStatus.STOPPED return ProcessStatus.STOPPED case _: + logger.debug("ProcessController.status() => ProcessStatus.CRASHED") self.last_status = ProcessStatus.CRASHED return ProcessStatus.CRASHED def kill(self) -> None: "Kill the process." - if self.process: - self.process.terminate() - self.process = None - self.last_status = ProcessStatus.STOPPED + logger.debug("ProcessController.kill()") + with self._lock: + if self.process: + pid = self.process.pid + self.process.kill() + code = self.process.wait() + self.process = None + logger.info( + "ProcessController.kill() - Process with PID %s killed with return code: %s", + pid, + code, + ) + self.last_status = ProcessStatus.STOPPED class ServerController: @@ -65,9 +94,11 @@ class ServerController: ) def status(self) -> ServerStatus: + logger.debug("ServerController.status()") try: status = self.server.status() except Exception: + logger.debug("ServerController.status() - Server is offline") return {"online": False} players = [] @@ -75,6 +106,7 @@ class ServerController: for player in status.players.sample: players.append(player.name) + logger.debug("ServerController.status() - Server is online") return { "online": True, "icon": status.icon, @@ -87,12 +119,18 @@ class ServerController: } def command(self, command: str) -> str: + logger.debug('ServerController.command(command="%s")', command) try: self.rcon.connect() output = self.rcon.command(command) self.rcon.disconnect() + logger.info('ServerController.command(command="%s") => %s', command, output) return output except Exception: + logger.exception( + 'ServerController.command(command="%s") - Command execution failed', + command, + ) return "" @@ -101,19 +139,28 @@ class MaintainanceController: self.mnt_file = Path(Config.MAINTAINANCE_FILE) def set(self, reason: str): + logger.debug('MaintainanceController.set(reason="%s")', reason) self.mnt_file.write_text(reason) def is_set(self) -> bool: + logger.debug("MaintainanceController.is_set() => %s", self.mnt_file.is_file()) return self.mnt_file.is_file() def get(self) -> str: if self.is_set(): + logger.debug( + "MaintainanceController.get() => %s", self.mnt_file.read_text() + ) return self.mnt_file.read_text() + + logger.debug("MaintainanceController.get() => ") return "" def unset(self): + logger.debug("MaintainanceController.unset()") if self.is_set(): self.mnt_file.unlink() + logger.debug("MaintainanceController.unset() - Maintainance file was unset") class LogsController: @@ -121,16 +168,21 @@ class LogsController: self.log_file = Path(Config.LOG_FILE) def stream(self): + logger.debug("LogsController.stream()") + i = 0 with self.log_file.open() as f: f.seek(0, 2) while True: line = f.readline() if line: + logger.debug("LogsController.stream() - Yielding line %s", i) + i += 1 yield line else: sleep(0.1) def tail(self, back: int = 10): + logger.debug("LogsController.tail(back=%s)", back) with self.log_file.open() as f: for line in deque(f, maxlen=back): yield line diff --git a/logs.py b/logs.py new file mode 100644 index 0000000..e3cb0b9 --- /dev/null +++ b/logs.py @@ -0,0 +1,15 @@ +from logging import DEBUG, INFO, FileHandler, Formatter, StreamHandler, getLogger + +from config import Config + +logger = getLogger(__name__) +logger.setLevel(DEBUG) +console = StreamHandler() +console.setLevel(INFO) +file = FileHandler(Config.MINECRAFTD_LOGS) +file.setLevel(DEBUG) +formatter = Formatter("%(asctime)s - %(levelname)s - %(message)s") +console.setFormatter(formatter) +file.setFormatter(formatter) +logger.addHandler(console) +logger.addHandler(file) diff --git a/main.py b/main.py index 00d38da..d0134d2 100644 --- a/main.py +++ b/main.py @@ -1,11 +1,11 @@ -from asyncio import create_task from typing import Annotated, Optional import uvicorn from classes import ProcessStatus from controllers import Controllers -from fastapi import FastAPI, Header +from fastapi import BackgroundTasks, FastAPI, Header from fastapi.responses import StreamingResponse +from logs import logger from models import Models from responses import Responses from util import check_password, stop_server @@ -14,14 +14,17 @@ app = FastAPI() @app.get("/start") -async def start() -> Responses.StartResponse: +async def start(tasks: BackgroundTasks) -> Responses.StartResponse: """Starts the Server's process if it is not already running. Returns: status: "started" or "running". message: The Server's response. """ + logger.debug("/start") + if Controllers.process.status() == ProcessStatus.RUNNING: + logger.debug("/start - The Server was already running") return { "status": "running", "message": "The Server was already running.", @@ -29,11 +32,13 @@ async def start() -> Responses.StartResponse: if Controllers.maintainance.is_set(): Controllers.maintainance.unset() + logger.debug("/start - Unset maintainance") - Controllers.process.start() + tasks.add_task(Controllers.process.start) + logger.info("/start - Starting server") return { - "status": "started", - "message": "The Server was started.", + "status": "starting", + "message": "The Server is starting.", } @@ -52,22 +57,30 @@ async def status() -> Responses.StatusResponse: list: the list of online players' usernames as strings. """ + logger.debug("/status") + process_status = Controllers.process.status() if process_status != ProcessStatus.RUNNING: # Crashed if process_status == ProcessStatus.CRASHED: + logger.debug("/status - The Server has crashed") return { "status": "crashed", "message": "The Server has crashed.", } # Maintainance if Controllers.maintainance.is_set(): + reason = Controllers.maintainance.get() + logger.debug( + '/status - The Server is offline due to maintainance ("%s")', reason + ) return { "status": "maintainance", "message": "The Server is offline due to maintainance.", - "reason": Controllers.maintainance.get(), + "reason": reason, } # Offline + logger.debug("/status - The Server is offline") return { "status": "offline", "message": "The Server is offline.", @@ -77,12 +90,14 @@ async def status() -> Responses.StatusResponse: # Starting if not server_status["online"]: + logger.debug("/status - The Server is starting") return { "status": "starting", "message": "The Server is starting.", } # Online + logger.debug("/status - The Server is online") return { "status": "online", "message": "The Server is online.", @@ -101,7 +116,9 @@ async def status() -> Responses.StatusResponse: @app.get("/stop") async def stop( - data: Models.StopModel, authorization: Annotated[str, Header()] + data: Models.StopModel, + authorization: Annotated[str, Header()], + tasks: BackgroundTasks, ) -> Responses.StopResponse: """Stops the Server. It waits for `countdown` seconds, then runs `/stop` on the Server, and kills it after `timeout` seconds if it's still alive. @@ -117,8 +134,12 @@ async def stop( message: The Server's response. """ + logger.debug("/stop") + check_password(authorization) - create_task(stop_server("STOPPING", data.countdown, data.reason, data.timeout)) + tasks.add_task(stop_server, "STOPPING", data.countdown, data.reason, data.timeout) + + logger.info("/stop - The Server is stopping") return { "status": "stopping", "message": "The Server is stopping.", @@ -127,7 +148,9 @@ async def stop( @app.get("/restart") async def restart( - data: Models.RestartModel, authorization: Annotated[str, Header()] + data: Models.RestartModel, + authorization: Annotated[str, Header()], + tasks: BackgroundTasks, ) -> Responses.RestartResponse: """Restarts the Server. It waits for `countdown` seconds, then runs `/stop` on the Server, and kills it after `timeout` seconds if it's still alive. @@ -145,15 +168,20 @@ async def restart( """ check_password(authorization) - create_task( - stop_server( - "RESTARTING", - data.countdown, - data.reason, - data.timeout, - Controllers.process.start, - ) + + logger.debug("/restart") + + tasks.add_task( + stop_server, + "RESTARTING", + data.countdown, + data.reason, + data.timeout, + Controllers.process.start, ) + + logger.info("/restart - The Server is restarting") + return { "status": "restarting", "message": "The Server is restarting.", @@ -162,7 +190,9 @@ async def restart( @app.get("/maintainance") async def maintainance( - data: Models.MaintainanceModel, authorization: Annotated[str, Header()] + data: Models.MaintainanceModel, + authorization: Annotated[str, Header()], + tasks: BackgroundTasks, ) -> Responses.MaintainanceResponse: """Stops the Server and sets it to maintainance status. It waits for `countdown` seconds, then runs `/stop` on the Server, and kills it after `timeout` seconds if it's still alive. @@ -179,15 +209,21 @@ async def maintainance( """ check_password(authorization) - create_task( - stop_server( - "STOPPING FOR MAINTAINANCE", - data.countdown, - data.reason, - data.timeout, - Controllers.maintainance.set(data.reason), - ) + + logger.debug("/maintainance") + + tasks.add_task( + stop_server, + "STOPPING FOR MAINTAINANCE", + data.countdown, + data.reason, + data.timeout, + Controllers.maintainance.set, + data.reason, ) + + logger.info("/maintainance - The Server is stopping for maintainance") + return { "status": "stopping", "message": "The Server is stopping for maintainance.", @@ -210,11 +246,14 @@ async def command( output: The command's output. """ + logger.debug('/command {command: "%s"}', data.command) check_password(authorization) + + output = Controllers.server.command(data.command) return { "status": "executed", "message": "The command was executed.", - "output": Controllers.server.command(data.command), + "output": output, } @@ -227,6 +266,7 @@ async def logs_stream(authorization: Annotated[str, Header()]) -> StreamingRespo Returns: text/event-stream """ + logger.debug("/logs/stream") check_password(authorization) return StreamingResponse(Controllers.logs.stream(), media_type="text/event-stream") @@ -244,6 +284,7 @@ async def logs_tail( Returns: text/event-stream """ + logger.debug("/logs/tail") check_password(authorization) return StreamingResponse(Controllers.logs.tail(data.back if data else 10)) diff --git a/responses.py b/responses.py index 8ed5a59..e116e86 100644 --- a/responses.py +++ b/responses.py @@ -4,7 +4,7 @@ from typing_extensions import TypedDict class StartResponse(TypedDict): - status: Literal["running", "started"] + status: Literal["running", "starting"] message: str diff --git a/util.py b/util.py index e9c9d96..f4cfed4 100644 --- a/util.py +++ b/util.py @@ -1,14 +1,21 @@ -from asyncio import sleep +from time import sleep from typing import Callable from classes import ProcessStatus from config import Config from controllers import Controllers from fastapi import HTTPException +from logs import logger -async def stop_server( - action: str, countdown: int, reason: str, timeout: int, then: Callable | None = None +def stop_server( + action: str, + countdown: int, + reason: str, + timeout: int, + then: Callable | None = None, + *args, + **kwargs, ): """Warns the players, stops the Server, and kills its process if its taking too long. @@ -19,27 +26,42 @@ async def stop_server( timeout (int): Seconds to wait before killing the process. then (Callable | None) (default: None): Function to be called after the Server is stopped. """ + logger.debug( + 'stop_server(action="%s", countdown=%s, reason="%s", timeout=%s, then=%s, args=%s, kwargs=%s', + action, + countdown, + reason, + timeout, + then, + args, + kwargs, + ) if countdown: + logger.debug("stop_server(...) - Starting countdown") Controllers.server.command(f"say SERVER IS {action} IN {countdown} SECONDS!!!") Controllers.server.command(f"say REASON: '{reason}'") while countdown > 0 and Controllers.server.status().get("players", {}).get( "online", 0 ): - await sleep(1) + sleep(1) countdown -= 1 + logger.info("stop_server(...) - Stopping server") Controllers.server.command("stop") while timeout > 0 and Controllers.process.status() == ProcessStatus.RUNNING: - await sleep(1) + sleep(1) timeout -= 1 if Controllers.process.status() == ProcessStatus.RUNNING: + logger.warning("stop_server(...) - Killing server") Controllers.process.kill() if then: - then() + logger.debug("stop_server(...) - Running callback") + then(*args, **kwargs) def check_password(password: str): if password != Config.MINECRAFTD_PASSWORD: + logger.debug('check_password("%s") - Password is invalid', password) raise HTTPException(401, "Password is invalid")