Logging: add informative console logs for startup, ports, connections, JOIN/deny, input, and periodic events

- Configure logging via LOG_LEVEL env (default INFO)
- Log when servers start listening (WT/QUIC/InMemory/HTTPS static)
- Log WT CONNECT accept, QUIC peer connect, datagram traffic at DEBUG
- Log GameServer creation, tick loop start, JOIN accept/deny, config_update broadcasts, and input reception

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

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()
-

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,

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
-

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()
 
 

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()
-