server: migrate to logging

Timestamps for every print, will make debugging latency issues easier,
maybe.
This commit is contained in:
Sebastian Lohff 2025-05-11 01:00:50 +02:00
parent 615840ac9f
commit 024160c169
1 changed files with 14 additions and 11 deletions

View File

@ -1,5 +1,4 @@
import asyncio import asyncio
import datetime
import json import json
import logging import logging
import re import re
@ -11,9 +10,11 @@ __VERSION__ = "0.0.1"
logging.basicConfig( logging.basicConfig(
level=logging.INFO, level=logging.INFO,
format="%(asctime)s %(name)s %(levelname)s %(message)s" format="%(asctime)s %(levelname)s %(message)s"
) )
LOG = logging.getLogger()
class Client: class Client:
freqs = {} freqs = {}
@ -24,7 +25,7 @@ class Client:
self.curr_freq = None self.curr_freq = None
async def handle(self): async def handle(self):
print(f" >>> New client {self.client} connected") LOG.info(">>> New client %s connected", self.client)
exc = None exc = None
try: try:
await self._handle_client() await self._handle_client()
@ -32,7 +33,7 @@ class Client:
exc = e exc = e
finally: finally:
# FIXME: basically handle disconnect / leave from room # FIXME: basically handle disconnect / leave from room
print(f" <<< Client {self.client} id {self.id} disconnected: {exc}") LOG.info("<<< Client %s id %s disconnected: %s", self.client, self.id, exc)
if self.curr_freq: if self.curr_freq:
await self._leave_room() await self._leave_room()
@ -50,18 +51,19 @@ class Client:
async def _handle_client(self): async def _handle_client(self):
await self._send(type="hello", name="LobbySrv 3000", version=__VERSION__) await self._send(type="hello", name="LobbySrv 3000", version=__VERSION__)
async for data in self.websocket: async for data in self.websocket:
print(f" <-- client {self.client} sent {repr(data)}")
try: try:
data = json.loads(data) data = json.loads(data)
except json.JSONDecodeError: except json.JSONDecodeError:
self._send_error("Could not decode message, invalid json") self._send_error("Could not decode message, invalid json")
LOG.error("client %s sent broken data %s", self.client, repr(data))
continue continue
if not isinstance(data, dict) or "cmd" not in data: if not isinstance(data, dict) or "cmd" not in data:
await self._send_error("Invalid format in json") await self._send_error("Invalid format in json")
LOG.error("client %s sent broken data (no cmd key in data) %s", self.client, repr(data))
continue continue
print(f"{datetime.datetime.now()} {self.client} wrote:", data) LOG.info("client %s wrote: %s", self.client, data)
match data["cmd"]: match data["cmd"]:
case "quit": case "quit":
@ -125,7 +127,7 @@ class Client:
self.curr_freq = freq self.curr_freq = freq
self.freqs[freq].append(self) self.freqs[freq].append(self)
# FIXME: do we need locking here? # FIXME: do we need locking here?
print("FREQ", self.curr_freq, freq, self.freqs) LOG.debug("FREQ %s %s %s", self.curr_freq, freq, self.freqs)
await self._send(type="join", freq=self.curr_freq, self_id=self.id, await self._send(type="join", freq=self.curr_freq, self_id=self.id,
other_players=[c.id for c in self._others(freq)]) other_players=[c.id for c in self._others(freq)])
await self._send_to_group(self._others(freq), type="player-joined", player=self.id) await self._send_to_group(self._others(freq), type="player-joined", player=self.id)
@ -152,7 +154,7 @@ class Client:
try: try:
self.freqs[self.curr_freq].remove(self) self.freqs[self.curr_freq].remove(self)
except ValueError: except ValueError:
print(f"Warning: Player {self.id} was not in freq {self.curr_freq}") LOG.warning("Player %s was not in freq %s", self.id, self.curr_freq)
if not self.freqs[self.curr_freq]: if not self.freqs[self.curr_freq]:
del self.freqs[self.curr_freq] del self.freqs[self.curr_freq]
self.curr_freq = None self.curr_freq = None
@ -167,15 +169,16 @@ class Client:
async def _send(self, ignore_exceptions=False, **kwargs): async def _send(self, ignore_exceptions=False, **kwargs):
data = json.dumps(kwargs).encode() data = json.dumps(kwargs).encode()
print(f" --> sending out to {self.client}: {data}") LOG.debug("--> sending out to %s: %s", self.client, data)
try: try:
await self.websocket.send(json.dumps(kwargs).encode() + b"\n") await self.websocket.send(json.dumps(kwargs).encode() + b"\n")
except Exception as e: except Exception as e:
print(f"Error sending data to {self.client}: {e}") LOG.error("Error sending data to %s: %s", self.client, e)
if not ignore_exceptions: if not ignore_exceptions:
raise raise
async def _send_to_group(self, group, **kwargs): async def _send_to_group(self, group, **kwargs):
LOG.info("broadcast() to %s clients: %s", len(group), kwargs)
broadcast([c.websocket for c in group], json.dumps(kwargs).encode() + b"\n") broadcast([c.websocket for c in group], json.dumps(kwargs).encode() + b"\n")
async def _send_error(self, msg: str): async def _send_error(self, msg: str):
@ -199,5 +202,5 @@ async def main():
if __name__ == "__main__": if __name__ == "__main__":
print("Starting server") LOG.info("Starting server")
asyncio.run(main()) asyncio.run(main())