diff --git a/.gitignore b/.gitignore index 23b1cc8..5c9e495 100644 --- a/.gitignore +++ b/.gitignore @@ -52,7 +52,7 @@ coverage.xml .pytest_cache/ cover/ # 测试用的证书 -test-cert/ +test-cert/ # Translations *.mo @@ -215,3 +215,4 @@ bancho.py-master/* storage/ replays/ osu-master/* +logs/ diff --git a/app/log.py b/app/log.py index 6fe64df..4b29f17 100644 --- a/app/log.py +++ b/app/log.py @@ -127,6 +127,16 @@ logger.add( level=settings.log_level, diagnose=settings.debug, ) +logger.add( + "logs/{time:YYYY-MM-DD}.log", + rotation="00:00", + retention="30 days", + colorize=False, + format="{time:YYYY-MM-DD HH:mm:ss} {level} | {message}", + level=settings.log_level, + diagnose=settings.debug, + encoding="utf8", +) logging.basicConfig(handlers=[InterceptHandler()], level=settings.log_level, force=True) uvicorn_loggers = [ @@ -140,3 +150,5 @@ for logger_name in uvicorn_loggers: uvicorn_logger = logging.getLogger(logger_name) uvicorn_logger.handlers = [InterceptHandler()] uvicorn_logger.propagate = False + +logging.getLogger("httpx").setLevel("WARNING") diff --git a/app/signalr/hub/hub.py b/app/signalr/hub/hub.py index bbcfdfc..4d9906c 100644 --- a/app/signalr/hub/hub.py +++ b/app/signalr/hub/hub.py @@ -273,6 +273,10 @@ class Hub[TState: UserState]: result = await self.invoke_method(client, packet.target, args) except InvokeException as e: error = e.message + logger.debug( + f"Client {client.connection_token} call {packet.target}" + f" failed: {error}" + ) except Exception as e: logger.exception( f"Error invoking method {packet.target} for " diff --git a/app/signalr/hub/multiplayer.py b/app/signalr/hub/multiplayer.py index 128fb91..87eceb8 100644 --- a/app/signalr/hub/multiplayer.py +++ b/app/signalr/hub/multiplayer.py @@ -364,7 +364,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): user = next((u for u in room.users if u.user_id == client.user_id), None) if user is None: raise InvokeException("You are not in this room") - + logger.info( + f"[MultiplayerHub] {client.user_id} adding " + f"beatmap {item.beatmap_id} to room {room.room_id}" + ) await server_room.queue.add_item( item, user, @@ -383,6 +386,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): if user is None: raise InvokeException("You are not in this room") + logger.info( + f"[MultiplayerHub] {client.user_id} editing " + f"item {item.id} in room {room.room_id}" + ) await server_room.queue.edit_item( item, user, @@ -401,6 +408,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): if user is None: raise InvokeException("You are not in this room") + logger.info( + f"[MultiplayerHub] {client.user_id} removing " + f"item {item_id} from room {room.room_id}" + ) await server_room.queue.remove_item( item_id, user, @@ -666,6 +677,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): if user.state == state: return + logger.info( + f"[MultiplayerHub] {user.user_id}'s state " + f"changed from {user.state} to {state}" + ) match state: case MultiplayerUserState.IDLE: if user.state.is_playing: @@ -684,6 +699,7 @@ class MultiplayerHub(Hub[MultiplayerClientState]): or room.state == MultiplayerRoomState.WAITING_FOR_LOAD ): await self.call_noblock(client, "LoadRequested") + await self.update_room_state(server_room) async def change_user_state( @@ -767,6 +783,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): async def change_room_state( self, room: ServerMultiplayerRoom, state: MultiplayerRoomState ): + logger.debug( + f"[MultiplayerHub] Room {room.room.room_id} state " + f"changed from {room.room.state} to {state}" + ) room.room.state = state await self.broadcast_group_call( self.group_id(room.room.room_id), @@ -799,6 +819,7 @@ class MultiplayerHub(Hub[MultiplayerClientState]): if all(u.state != MultiplayerUserState.READY for u in room.users): raise InvokeException("Can't start match when no users are ready.") + logger.info(f"[MultiplayerHub] Room {room.room_id} match started") await self.start_match(server_room) async def start_match(self, room: ServerMultiplayerRoom): @@ -971,6 +992,7 @@ class MultiplayerHub(Hub[MultiplayerClientState]): room.room.host.user_id, ) del self.rooms[room.room.room_id] + logger.info(f"[MultiplayerHub] Room {room.room.room_id} ended") async def LeaveRoom(self, client: Client): store = self.get_or_create_state(client) @@ -989,6 +1011,7 @@ class MultiplayerHub(Hub[MultiplayerClientState]): user.user_id, ) await self.make_user_leave(client, server_room, user) + logger.info(f"[MultiplayerHub] {client.user_id} left room {room.room_id}") async def KickUser(self, client: Client, user_id: int): store = self.get_or_create_state(client) @@ -1017,6 +1040,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): if target_client is None: return await self.make_user_leave(target_client, server_room, user, kicked=True) + logger.info( + f"[MultiplayerHub] {user.user_id} was kicked from room {room.room_id}" + f"by {client.user_id}" + ) async def set_host(self, room: ServerMultiplayerRoom, user: MultiplayerRoomUser): room.room.host = user @@ -1046,6 +1073,10 @@ class MultiplayerHub(Hub[MultiplayerClientState]): new_host.user_id, ) await self.set_host(server_room, new_host) + logger.info( + f"[MultiplayerHub] {client.user_id} transferred host to {new_host.user_id}" + f" in room {room.room_id}" + ) async def AbortGameplay(self, client: Client): store = self.get_or_create_state(client) @@ -1100,6 +1131,9 @@ class MultiplayerHub(Hub[MultiplayerClientState]): GameplayAbortReason.HOST_ABORTED, ) await self.update_room_state(server_room) + logger.info( + f"[MultiplayerHub] {client.user_id} aborted match in room {room.room_id}" + ) async def change_user_match_state( self, room: ServerMultiplayerRoom, user: MultiplayerRoomUser diff --git a/app/signalr/hub/spectator.py b/app/signalr/hub/spectator.py index 5485732..5abe880 100644 --- a/app/signalr/hub/spectator.py +++ b/app/signalr/hub/spectator.py @@ -6,6 +6,7 @@ import lzma import struct import time from typing import override +from venv import logger from app.config import settings from app.database import Beatmap, User @@ -217,6 +218,7 @@ class SpectatorHub(Hub[StoreClientState]): maximum_statistics=state.maximum_statistics, ) ) + logger.info(f"[SpectatorHub] {client.user_id} began playing {state.beatmap_id}") await self.broadcast_group_call( self.group_id(user_id), "UserBeganPlaying", @@ -320,6 +322,10 @@ class SpectatorHub(Hub[StoreClientState]): async def _end_session(self, user_id: int, state: SpectatorState) -> None: if state.state == SpectatedUserState.Playing: state.state = SpectatedUserState.Quit + logger.info( + f"[SpectatorHub] {user_id} finished playing {state.beatmap_id} " + f"with {state.state}" + ) await self.broadcast_group_call( self.group_id(user_id), "UserFinishedPlaying", @@ -330,7 +336,9 @@ class SpectatorHub(Hub[StoreClientState]): async def StartWatchingUser(self, client: Client, target_id: int) -> None: user_id = int(client.connection_id) target_store = self.state.get(target_id) + logger.info(f"[SpectatorHub] {user_id} started watching {target_id}") if target_store and target_store.state: + logger.debug(f"[SpectatorHub] {target_id} is {target_store.state}") await self.call_noblock( client, "UserBeganPlaying", @@ -361,3 +369,4 @@ class SpectatorHub(Hub[StoreClientState]): store.watched_user.discard(target_id) if (target_client := self.get_client_by_id(str(target_id))) is not None: await self.call_noblock(target_client, "UserEndedWatching", user_id) + logger.info(f"[SpectatorHub] {user_id} ended watching {target_id}")