diff --git a/run.py b/run.py index 5f5d74a..b9ba799 100644 --- a/run.py +++ b/run.py @@ -1,5 +1,6 @@ import asyncio import os +import logging from server.server import GameServer from server.config import ServerConfig @@ -51,12 +52,18 @@ async def run_webtransport(): if __name__ == "__main__": try: + # Logging setup + level = os.environ.get("LOG_LEVEL", "INFO").upper() + logging.basicConfig(level=getattr(logging, level, logging.INFO), format="[%(asctime)s] %(levelname)s: %(message)s") mode = os.environ.get("MODE", "mem").lower() if mode == "wt": + logging.info("Starting in WebTransport mode") asyncio.run(run_webtransport()) elif mode == "quic": + logging.info("Starting in QUIC datagram mode") asyncio.run(run_quic()) else: + logging.info("Starting in in-memory transport mode") asyncio.run(run_in_memory()) except KeyboardInterrupt: pass diff --git a/server/quic_transport.py b/server/quic_transport.py index 009427a..d6459b3 100644 --- a/server/quic_transport.py +++ b/server/quic_transport.py @@ -5,6 +5,7 @@ from dataclasses import dataclass from typing import Awaitable, Callable, Dict, Optional from .transport import DatagramServerTransport, OnDatagram, TransportPeer +import logging try: @@ -31,14 +32,17 @@ class GameQuicProtocol(QuicConnectionProtocol): # type: ignore[misc] # Register by connection id self._peer_id = int(self._quic.connection_id) # type: ignore[attr-defined] self._peers[self._peer_id] = self + logging.info("QUIC peer connected: id=%s", self._peer_id) elif isinstance(event, DatagramFrameReceived): # Schedule async callback if self._peer_id is None: return peer = TransportPeer(addr=self) + logging.debug("QUIC datagram received from id=%s, %d bytes", self._peer_id, len(event.data)) asyncio.ensure_future(self._on_datagram(bytes(event.data), peer)) async def send_datagram(self, data: bytes) -> None: + logging.debug("QUIC send datagram: %d bytes", len(data)) self._quic.send_datagram_frame(data) # type: ignore[attr-defined] await self._loop.run_in_executor(None, self.transmit) # type: ignore[attr-defined] @@ -67,9 +71,9 @@ class QuicWebTransportServer(DatagramServerTransport): async def _create_protocol(*args, **kwargs): return GameQuicProtocol(*args, on_datagram=self._on_datagram, peers=self._peers, **kwargs) + logging.info("QUIC datagram server listening on %s:%d", self.host, self.port) self._server = await serve(self.host, self.port, configuration=configuration, create_protocol=_create_protocol) try: await self._server.wait_closed() finally: self._server.close() - diff --git a/server/server.py b/server/server.py index cc3786c..b52dfbd 100644 --- a/server/server.py +++ b/server/server.py @@ -2,6 +2,7 @@ from __future__ import annotations import asyncio from dataclasses import dataclass +import logging from typing import Dict, List, Optional, Tuple from collections import deque @@ -53,6 +54,7 @@ class GameServer: self.runtime = ServerRuntime(config=config, state=GameState(config.width, config.height)) self.sessions: Dict[int, PlayerSession] = {} self._config_update_interval_ticks = 50 # periodic resend + logging.info("GameServer created: field=%dx%d, tick_rate=%d TPS, wrap=%s", config.width, config.height, config.tick_rate, config.wrap_edges) async def on_datagram(self, data: bytes, peer: TransportPeer) -> None: # Minimal header parse @@ -85,6 +87,7 @@ class GameServer: # Broadcast to all sessions (requires real peer handles) for session in list(self.sessions.values()): await self.transport.send(payload, TransportPeer(session.peer)) + logging.debug("Broadcasted config_update to %d sessions", len(self.sessions)) async def relay_input_broadcast( self, @@ -115,6 +118,7 @@ class GameServer: r = self.runtime tick_duration = 1.0 / max(1, r.config.tick_rate) next_cfg_resend = self._config_update_interval_ticks + logging.info("Tick loop started at %.2f TPS", 1.0 / tick_duration) while True: start = asyncio.get_event_loop().time() # process inputs, update snakes, collisions, apples, deltas @@ -388,12 +392,14 @@ class GameServer: if pid is None: payload = build_join_deny(version=self.runtime.version, seq=self.runtime.next_seq(), reason="Server full") await self.transport.send(payload, peer) + logging.warning("JOIN denied: server full (name=%s)", name) return # Spawn snake snake = self._find_spawn() if snake is None: payload = build_join_deny(version=self.runtime.version, seq=self.runtime.next_seq(), reason="No free cell, please wait") await self.transport.send(payload, peer) + logging.warning("JOIN denied: no free cell (name=%s)", name) return # Register session and snake color_id = preferred if (preferred is not None) else self._choose_color_id() @@ -403,6 +409,7 @@ class GameServer: self.runtime.state.snakes[pid] = snake self.runtime.state.occupy_snake(snake) self._ensure_apples() + logging.info("JOIN accepted: player_id=%d name=%s color=%d len=%d at=%s", pid, name, color_id, snake.length, snake.body[0]) # Send join_ack cfg = self.runtime.config ack = build_join_ack( @@ -445,7 +452,7 @@ class GameServer: full = pack_header( self.runtime.version, PacketType.STATE_FULL, 0, self.runtime.next_seq(), self.runtime.state.tick & 0xFFFF ) + body - await self.transport.send(full, peer) + await self.transport.send(full, peer) else: # Partition by packing whole snakes first, apples only in first part; chunk a single oversized snake using 2-bit chunks update_id = self.runtime.next_update_id() @@ -563,6 +570,7 @@ class GameServer: break if player_id is None: return + logging.debug("INPUT from player_id=%d: %d events (base_tick=%d)", player_id, len(events), base_tick) # Relay to others immediately for prediction await self.relay_input_broadcast( from_player_id=player_id, diff --git a/server/static_server.py b/server/static_server.py index ca80ffb..57b2c0c 100644 --- a/server/static_server.py +++ b/server/static_server.py @@ -1,6 +1,7 @@ from __future__ import annotations import ssl +import logging import threading from http.server import ThreadingHTTPServer, SimpleHTTPRequestHandler from pathlib import Path @@ -31,5 +32,5 @@ def start_https_static(host: str, port: int, certfile: str, keyfile: str, docroo t = threading.Thread(target=httpd.serve_forever, name="https-static", daemon=True) t.start() + logging.info("HTTPS static server listening on https://%s:%d serving '%s'", host, port, docroot_path) return httpd, t - diff --git a/server/transport.py b/server/transport.py index 764689e..8dcd153 100644 --- a/server/transport.py +++ b/server/transport.py @@ -2,6 +2,7 @@ from __future__ import annotations import asyncio from dataclasses import dataclass +import logging from typing import Awaitable, Callable, Optional, Tuple @@ -37,7 +38,7 @@ class InMemoryTransport(DatagramServerTransport): await self._on_datagram(data, peer) async def run(self) -> None: - # Nothing to do in in-memory test transport + logging.info("InMemory transport started (no network)") await asyncio.Future() diff --git a/server/webtransport_server.py b/server/webtransport_server.py index bbb429f..9d80849 100644 --- a/server/webtransport_server.py +++ b/server/webtransport_server.py @@ -5,6 +5,7 @@ from dataclasses import dataclass from typing import Awaitable, Callable, Dict, Optional from .transport import DatagramServerTransport, OnDatagram, TransportPeer +import logging try: @@ -49,6 +50,7 @@ class GameWTProtocol(QuicConnectionProtocol): # type: ignore[misc] # In WebTransport over H3, datagrams use the CONNECT stream id as flow_id flow_id = event.stream_id # type: ignore[attr-defined] self._sessions[flow_id] = WTSession(flow_id=flow_id, proto=self) + logging.info("WT CONNECT accepted: flow_id=%s", flow_id) # Send 2xx to accept the session if self._http is not None: self._http.send_headers(event.stream_id, [(b":status", b"200")]) @@ -62,6 +64,7 @@ class GameWTProtocol(QuicConnectionProtocol): # type: ignore[misc] if not sess: return peer = TransportPeer(addr=(self, flow_id)) + logging.debug("WT datagram received: flow_id=%s, %d bytes", flow_id, len(data)) asyncio.ensure_future(self._on_datagram(bytes(data), peer)) def quic_event_received(self, event) -> None: # type: ignore[override] @@ -79,6 +82,7 @@ class GameWTProtocol(QuicConnectionProtocol): # type: ignore[misc] if self._http is None: return try: + logging.debug("WT send datagram: flow_id=%s, %d bytes", flow_id, len(data)) self._http.send_datagram(flow_id, data) await self._loop.run_in_executor(None, self.transmit) # type: ignore[attr-defined] except Exception: @@ -117,9 +121,9 @@ class WebTransportServer(DatagramServerTransport): async def _create_protocol(*args, **kwargs): return GameWTProtocol(*args, on_datagram=self._on_datagram, sessions=self._sessions, **kwargs) + logging.info("WebTransport (H3) server listening on %s:%d", self.host, self.port) self._server = await serve(self.host, self.port, configuration=configuration, create_protocol=_create_protocol) try: await self._server.wait_closed() finally: self._server.close() -