More logging

battleship/cli/app.py

@@ -1,11 +1,9 @@
-from datetime import datetime, timezone
-from pathlib import Path
 from typing import Annotated
 
 import pydantic
 import typer
 
-from battleship import data_home, get_client_version, tui
+from battleship import get_client_version, tui
 from battleship.cli import account, logging, play, settings
 from battleship.tui import di
 
@@ -17,16 +15,6 @@
 SENTRY_DSN = "https://[email protected]/4507262636654592"
 
 
-def make_log_sink(debug: bool) -> str:
-    now = datetime.now(tz=timezone.utc)
-
-    if debug:
-        log_home = Path()
-    else:
-        log_home = data_home
-    return str(log_home / f"client_{now:%Y-%m-%d_%H-%M-%S}.log")
-
-
 @app.callback(invoke_without_command=True)
 def main(
     ctx: typer.Context,
@@ -60,12 +48,11 @@ def main(
     your terminal. You can play against the computer or a real player via the Internet,
     customize game options and appearance, keep track of your achievements, and more.
     """
-
     ctx.ensure_object(dict)
     ctx.obj["server_url"] = server_url
     ctx.obj["debug"] = debug
 
-    logging.configure_logger(make_log_sink(debug))
+    logging.configure_logger(debug)
     logging.configure_sentry(SENTRY_DSN)
 
     try:

battleship/cli/logging.py

@@ -1,11 +1,24 @@
+from datetime import datetime, timezone
+from pathlib import Path
+
 import loguru
 import sentry_sdk
 from sentry_offline import make_offline_transport
 
 from battleship import PACKAGE_NAME, data_home, get_client_version
 
 
-def configure_logger(sink: str, log_size: str = "1 MB", level: str = "DEBUG") -> None:
+def configure_logger(debug: bool) -> None:
+    if debug:
+        now = datetime.now(tz=timezone.utc)
+        sink = str(Path() / f"client_{now:%Y-%m-%d_%H-%M-%S}.log")
+        log_size = "10 MB"
+        level = "DEBUG"
+    else:
+        sink = str(data_home / "client.log")
+        log_size = "5 MB"
+        level = "INFO"
+
     loguru.logger.enable(PACKAGE_NAME)
     loguru.logger.remove()
     loguru.logger.add(sink, rotation=log_size, level=level)

battleship/client/client.py

@@ -212,7 +212,7 @@ async def refresh_id_token(self, refresh_token: str) -> Credentials:
 
     async def load_credentials(self) -> None:
         credentials = self.credentials_provider.load()
-        logger.debug("Credentials loaded: {creds}.", creds=credentials)
+        logger.info("Credentials loaded: {creds}.", creds=credentials)
 
         if not credentials:
             return
@@ -487,9 +487,9 @@ async def log_request(request: Request) -> None:
         if isinstance(content, dict) and "password" in content:
             content["password"] = "[REDACTED]"
 
-    logger.debug(
-        "Make {method} request to {path} with content {content}.",
+    logger.info(
+        "{method} -> {url} | {content}.",
         method=request.method,
-        path=request.url.path,
+        url=request.url,
         content=content,
     )

battleship/tui/app.py

@@ -9,6 +9,7 @@
 from textual.events import Mount, Unmount
 from textual.screen import Screen
 
+from battleship import get_client_version
 from battleship.client import Client, ClientError, ConnectionEvent
 from battleship.tui import screens, strategies
 from battleship.tui.di import container
@@ -114,11 +115,22 @@ async def create_multiplayer_session(
         no_adjacent_ships: bool,
     ) -> None:
         if not self._client.logged_in:
-            logger.warning("Cannot create multiplayer session if not logged in.")
+            logger.warning("Cannot create a multiplayer session if not logged in.")
             return
 
         name = name or f"{self._client.nickname}'s game"
 
+        logger.info(
+            "Create a multiplayer session. Name: {name}. Roster: {roster}. "
+            "Firing order: {firing_order}. Salvo mode: {salvo_mode}. "
+            "No adjacent ships: {no_adjacent_ships}",
+            name=name,
+            roster=roster_name,
+            firing_order=firing_order,
+            salvo_mode=salvo_mode,
+            no_adjacent_ships=no_adjacent_ships,
+        )
+
         session = await self._client.create_session(
             name,
             roster_name,
@@ -168,6 +180,7 @@ async def join_from_event(self, event: screens.JoinGame.JoinMultiplayerSession)
 
     @work
     async def join_multiplayer_session(self, session_id: str) -> None:
+        logger.info("Join a multiplayer session {session_id}.", session_id=session_id)
         strategy = strategies.MultiplayerStrategy(self._client.nickname, self._client)
 
         await self._client.join_game(session_id)
@@ -263,7 +276,12 @@ def run(app: BattleshipApp | None = None, debug: bool = False) -> None:
     if app is None:
         app = BattleshipApp(debug=debug)
 
+    logger.info("Starting Battleship TUI v{version}.", version=get_client_version())
+
     app.run()
 
+    logger.info("Exiting.")
+
     if app.return_code != 0:
+        logger.warning("Exit with error: {error}.", error=app.error_text)
         raise BattleshipError(app.error_text)

battleship/tui/screens/create_game.py

@@ -1,8 +1,10 @@
 from typing import Any
 
+from loguru import logger
 from textual import on
 from textual.app import ComposeResult
 from textual.containers import Container, VerticalScroll
+from textual.events import ScreenResume, ScreenSuspend
 from textual.message import Message
 from textual.screen import Screen
 from textual.widgets import Markdown
@@ -63,3 +65,11 @@ def create_session_from_event(self, event: NewGame.PlayPressed) -> None:
                 event.no_adjacent_ships,
             )
         )
+
+    @on(ScreenResume)
+    def log_enter(self) -> None:
+        logger.info("Enter {screen} screen.", screen=self.__class__.__name__)
+
+    @on(ScreenSuspend)
+    def log_leave(self) -> None:
+        logger.info("Leave {screen} screen.", screen=self.__class__.__name__)

battleship/tui/screens/game.py

@@ -2,10 +2,12 @@
 from string import Template
 from typing import Any, Iterable, Literal
 
+from loguru import logger
 from textual import on
 from textual.app import ComposeResult
 from textual.containers import Container, Grid
 from textual.coordinate import Coordinate
+from textual.events import ScreenResume, ScreenSuspend
 from textual.screen import Screen
 
 from battleship.engine import domain
@@ -167,9 +169,12 @@ def action_show_summary(self) -> None:
     def spawn_ship(self, event: Board.ShipPlaced) -> None:
         self.player_board.mode = Board.Mode.DISPLAY
         position = [convert_to_coordinate(c) for c in event.coordinates]
+        logger.info("Spawn ship #{ship_id} at {coords}.", ship_id=event.ship.id, coords=position)
         self._strategy.spawn_ship(ship_id=event.ship.id, position=position)
 
     def on_fleet_ready(self, player: str) -> None:
+        logger.info("{player}'s fleet is ready.", player=player)
+
         self.write_as_game(f":ship: {player}'s fleet is ready")
         self.players_ready += 1
 
@@ -178,6 +183,10 @@ def on_fleet_ready(self, player: str) -> None:
             self.query_one(Announcement).update_phase(text)
 
     def on_awaiting_move(self, actor: str, subject: str) -> None:
+        logger.info(
+            "{subject} is waiting for {actor} to make a move.", actor=actor, subject=subject
+        )
+
         if actor == self._player_name:
             self.player_board.player_attacks = True
         else:
@@ -191,10 +200,19 @@ def on_awaiting_move(self, actor: str, subject: str) -> None:
         self.write_as_game(f":man: {actor}'s turn. Fire at will!")
 
     def on_ship_spawned(self, player: str, ship_id: str, position: Iterable[str]) -> None:
+        logger.info(
+            "{player}'s ship #{ship_id} is spawned at {position}.",
+            player=player,
+            ship_id=ship_id,
+            position=position,
+        )
+
         self.board_map[player].paint_ship([convert_from_coordinate(p) for p in position])
         self.fleet_map[player].place(ship_id)
 
     def on_salvo(self, salvo: models.Salvo) -> None:
+        logger.info("New salvo is incoming. {salvo}", salvo=salvo)
+
         board = self.board_map[salvo.subject.name]
         fleet = self.fleet_map[salvo.subject.name]
 
@@ -223,6 +241,8 @@ def on_salvo(self, salvo: models.Salvo) -> None:
             self.board_map[salvo.actor.name].min_targets = salvo.ships_left
 
     def on_game_ended(self, winner: str, summary: models.GameSummary) -> None:
+        logger.info("Game ended. {winner} has won.", winner=winner)
+
         self.summary = summary
 
         for board in self.board_map.values():
@@ -237,6 +257,8 @@ def on_game_ended(self, winner: str, summary: models.GameSummary) -> None:
         self._strategy.unsubscribe()
 
     def on_game_cancelled(self, reason: Literal["quit", "disconnect", "error"]) -> None:
+        logger.info("Game was cancelled due to {reason}.", reason=reason)
+
         self._strategy.unsubscribe()
         self.app.pop_screen()
 
@@ -254,6 +276,8 @@ def on_game_cancelled(self, reason: Literal["quit", "disconnect", "error"]) -> N
 
     @on(Board.CellShot)
     def fire(self, event: Board.CellShot) -> None:
+        logger.info("A fire was shot at {coords}.", coords=event.coordinates)
+
         self.enemy_board.mode = Board.Mode.DISPLAY
         position = [convert_to_coordinate(c) for c in event.coordinates]
         self._strategy.fire(position=position)
@@ -271,11 +295,14 @@ def callback(should_quit: bool) -> None:
         self.app.push_screen(SessionEndModal(), callback)
 
     def cancel_game(self) -> None:
+        logger.info("Game has been cancelled.")
+
         self._strategy.cancel()
         self._strategy.unsubscribe()
 
     @on(Ship.ShowPreview)
     def show_ship_preview(self, event: Ship.ShowPreview) -> None:
+        logger.info("Preview ship {ship}.", ship=event.ship_key)
         self.player_board.mode = Board.Mode.ARRANGE
         roster_item = self._strategy.roster[event.ship_key]
         self.player_board.show_ship_preview(ship_id=roster_item.id, ship_hp=roster_item.hp)
@@ -290,3 +317,11 @@ def _format_rules(self, template: str) -> str:
             roster=self._strategy.roster.name.capitalize(),
             adjacent_ships=adjacent_ships,
         )
+
+    @on(ScreenResume)
+    def log_enter(self) -> None:
+        logger.info("Enter {screen} screen.", screen=self.__class__.__name__)
+
+    @on(ScreenSuspend)
+    def log_leave(self) -> None:
+        logger.info("Leave {screen} screen.", screen=self.__class__.__name__)

battleship/tui/screens/join_game.py

@@ -69,11 +69,14 @@ async def subscribe(self) -> None:
 
     @on(ScreenSuspend)
     async def unsubscribe(self) -> None:
-        await self.unsubscribe_from_updates()
+        if self._subscription is None:
+            return
+
+        logger.info("Unsubscribing from session updates.")
 
-        if self._subscription:
-            self._subscription.clear()
+        await self.unsubscribe_from_updates()
 
+        self._subscription.clear()
         self._subscription = None
         self._client.remove_listener(ConnectionEvent.CONNECTION_LOST, self.handle_connection_lost)
 
@@ -112,6 +115,8 @@ async def fetch_sessions(self) -> None:
                 await self.add_session(session)
 
     async def subscribe_to_updates(self) -> None:
+        logger.info("Subscribe to session updates.")
+
         try:
             self._subscription = await self._client.sessions_subscribe()
             self._subscription.on_add(self.add_session)
@@ -153,3 +158,11 @@ async def remove_session(self, session_id: SessionID) -> None:
             await item.remove()
         except NoMatches:
             pass
+
+    @on(ScreenResume)
+    def log_enter(self) -> None:
+        logger.info("Enter {screen} screen.", screen=self.__class__.__name__)
+
+    @on(ScreenSuspend)
+    def log_leave(self) -> None:
+        logger.info("Leave {screen} screen.", screen=self.__class__.__name__)

battleship/tui/screens/lobby.py

@@ -53,11 +53,14 @@ async def on_mount(self) -> None:
 
     @on(ScreenSuspend)
     async def unsubscribe(self) -> None:
-        await self.unsubscribe_from_player_count()
+        if self._player_subscription is None:
+            return
+
+        logger.info("Unsubscribe from player count updates.")
 
-        if self._player_subscription:
-            self._player_subscription.clear()
+        await self.unsubscribe_from_player_count()
 
+        self._player_subscription.clear()
         self._player_subscription = None
         self._client.remove_listener(ConnectionEvent.CONNECTION_LOST, self.handle_connection_lost)
 
@@ -72,6 +75,8 @@ async def disconnect_ws(self) -> None:
 
     @on(ListView.Selected, item="#logout")
     async def logout(self) -> None:
+        logger.info("Log out.")
+        await self.unsubscribe()
         await self._client.disconnect()
         await self._client.logout()
         self.action_back()
@@ -114,6 +119,8 @@ async def fetch_player_count(self) -> None:
             await self.update_ingame_count(count.ingame)
 
     async def subscribe_to_player_count(self) -> None:
+        logger.info("Subscribe to player count updates.")
+
         try:
             subscription = await self._client.players_subscribe()
         except ClientError as exc:
@@ -154,3 +161,11 @@ def handle_connection_impossible() -> None:
     async def _setup_player_count_updates(self) -> None:
         await self.subscribe_to_player_count()
         await self.fetch_player_count()
+
+    @on(ScreenResume)
+    def log_enter(self) -> None:
+        logger.info("Enter {screen} screen.", screen=self.__class__.__name__)
+
+    @on(ScreenSuspend)
+    def log_leave(self) -> None:
+        logger.info("Leave {screen} screen.", screen=self.__class__.__name__)

battleship/tui/screens/main_menu.py

@@ -1,6 +1,8 @@
+from loguru import logger
 from textual import on
 from textual.app import ComposeResult
 from textual.containers import Container
+from textual.events import ScreenResume, ScreenSuspend
 from textual.screen import Screen
 from textual.widgets import Label, ListItem, ListView, Markdown
 
@@ -41,3 +43,11 @@ def run_multiplayer(self) -> None:
     @on(ListView.Selected, item="#settings")
     def to_settings(self) -> None:
         self.app.switch_screen(screens.Settings())
+
+    @on(ScreenResume)
+    def log_enter(self) -> None:
+        logger.info("Enter {screen} screen.", screen=self.__class__.__name__)
+
+    @on(ScreenSuspend)
+    def log_leave(self) -> None:
+        logger.info("Leave {screen} screen.", screen=self.__class__.__name__)