Logging Systems

.claude/settings.json

@@ -6,7 +6,11 @@
       "Bash(ruff format:*)",
       "Bash(basedpyright:*)"
     ],
-    "deny": []
+    "deny": [
+      "Edit(CHANGELOG.md)",
+      "MultiEdit(CHANGELOG.md)",
+      "Write(CHANGELOG.md)"
+    ]
   },
   "hooks": {
     "PostToolUse": [

docs/index.md

@@ -36,7 +36,6 @@ BalatroBot is a Python framework designed to help developers create automated bo
 
     [:octicons-arrow-right-24: Protocol API](protocol-api.md)
 
-
 - :octicons-sparkle-fill-16:{ .lg .middle } __Documentation for LLM__
 
     ---

docs/logging-systems.md

@@ -0,0 +1,119 @@
+# Logging Systems
+
+BalatroBot implements three distinct logging systems to support different aspects of development, debugging, and analysis:
+
+1. [**JSONL Run Logging**](#jsonl-run-logging) - Records complete game runs for replay and analysis
+2. [**Python SDK Logging**](#python-sdk-logging) - Future logging capabilities for the Python framework
+3. [**Mod Logging**](#mod-logging) - Traditional streamodded logging for mod development and debugging
+
+## JSONL Run Logging
+
+The run logging system records complete game runs as JSONL (JSON Lines) files. Each line represents a single game action with its parameters, timestamp, and game state **before** the action.
+
+The system hooks into these game functions:
+
+- `start_run`: begins a new game run
+- `skip_or_select_blind`: blind selection actions
+- `play_hand_or_discard`: card play actions
+- `cash_out`: end blind and collect rewards
+- `shop`: shop interactions
+- `go_to_menu`: return to main menu
+
+The JSONL files are automatically created when:
+
+- **Playing manually**: Starting a new run through the game interface
+- **Using the API**: Interacting with the game through the TCP API
+
+Files are saved as: `{mod_path}/runs/YYYYMMDDTHHMMSS.jsonl`
+
+!!! tip "Replay runs"
+
+    The JSONL logs enable complete run replay for testing and analysis.
+
+    ```python
+    state = load_jsonl_run("20250714T145700.jsonl")
+    for step in state:
+        send_and_receive_api_message(
+            tcp_client,
+            step["function"]["name"],
+            step["function"]["arguments"]
+        )
+    ```
+
+Examples for runs can be found in the [test suite](https://github.com/S1M0N38/balatrobot/tree/main/tests/runs).
+
+### Format Specification
+
+Each log entry follows this structure:
+
+```json
+{
+  "timestamp_ms": int,
+  "function": {
+    "name": "...",
+    "arguments": {...}
+  },
+  "game_state": { ... }
+}
+```
+
+- **`timestamp_ms`**: Unix timestamp in milliseconds when the action occurred
+- **`function`**: The game function that was called
+  - `name`: Function name (e.g., "start_run", "play_hand_or_discard", "cash_out")
+  - `arguments`: Arguments passed to the function
+- **`game_state`**: Complete game state **before** the function execution
+
+## Python SDK Logging
+
+The Python SDK (`src/balatrobot/`) implements structured logging for bot development and debugging. The logging system provides visibility into client operations, API communications, and error handling.
+
+### What Gets Logged
+
+The `BalatroClient` logs the following operations:
+
+- **Connection events**: When connecting to and disconnecting from the game API
+- **API requests**: Function names being called and their completion status
+- **Errors**: Connection failures, socket errors, and invalid API responses
+
+### Configuration Example
+
+The SDK uses Python's built-in `logging` module. Configure it in your bot code before using the client:
+
+```python
+import logging
+from balatrobot import BalatroClient
+
+# Configure logging
+log_format = '%(asctime)s [%(levelname)s] %(name)s: %(message)s'
+console_handler = logging.StreamHandler()
+console_handler.setLevel(logging.INFO)
+file_handler = logging.FileHandler('balatrobot.log')
+file_handler.setLevel(logging.DEBUG)
+
+logging.basicConfig(
+    level=logging.DEBUG,
+    format=log_format,
+    handlers=[console_handler, file_handler]
+)
+
+# Use the client
+with BalatroClient() as client:
+    state = client.get_game_state()
+    client.start_run(deck="Red Deck", stake=1)
+```
+
+## Mod Logging
+
+BalatroBot uses Steamodded's built-in logging system for mod development and debugging.
+
+- **Traditional logging**: Standard log levels (DEBUG, INFO, WARNING, ERROR)
+- **Development focus**: Primarily for debugging mod functionality
+- **Console output**: Displays in game console and log files
+
+```lua
+-- Available through Steamodded
+sendDebugMessage("This is a debug message")
+sendInfoMessage("This is an info message")
+sendWarningMessage("This is a warning message")
+sendErrorMessage("This is an error message")
+```

mkdocs.yml

@@ -39,7 +39,6 @@ plugins:
         The project enables real-time bidirectional communication between the game and bot through TCP sockets.
       sections:
         Documentation:
-          - index.md
           - installation.md
           - developing-bots.md
           - balatrobot-api.md
@@ -62,6 +61,7 @@ nav:
   - Developing Bots: developing-bots.md
   - BalatroBot API: balatrobot-api.md
   - Protocol API: protocol-api.md
+  - Logging Systems: logging-systems.md
 markdown_extensions:
   - toc:
       toc_depth: 3

src/balatrobot/client.py

@@ -1,6 +1,7 @@
 """Main BalatroBot client for communicating with the game."""
 
 import json
+import logging
 import socket
 from typing import Any, Literal, Self
 
@@ -18,6 +19,8 @@
     StartRunRequest,
 )
 
+logger = logging.getLogger(__name__)
+
 
 class BalatroClient:
     """Client for communicating with the BalatroBot game API."""
@@ -58,6 +61,7 @@ def connect(self) -> None:
         if self._connected:
             return
 
+        logger.info(f"Connecting to BalatroBot API at {self.host}:{self.port}")
         try:
             self._socket = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
             self._socket.settimeout(self.timeout)
@@ -66,7 +70,11 @@ def connect(self) -> None:
             )
             self._socket.connect((self.host, self.port))
             self._connected = True
+            logger.info(
+                f"Successfully connected to BalatroBot API at {self.host}:{self.port}"
+            )
         except (socket.error, OSError) as e:
+            logger.error(f"Failed to connect to {self.host}:{self.port}: {e}")
             raise ConnectionFailedError(
                 f"Failed to connect to {self.host}:{self.port}",
                 error_code="E008",
@@ -76,6 +84,7 @@ def connect(self) -> None:
     def disconnect(self) -> None:
         """Disconnect from the BalatroBot game API."""
         if self._socket:
+            logger.info(f"Disconnecting from BalatroBot API at {self.host}:{self.port}")
             self._socket.close()
             self._socket = None
         self._connected = False
@@ -106,6 +115,7 @@ def _send_request(self, name: str, arguments: dict[str, Any]) -> dict[str, Any]:
 
         # Create and validate request
         request = APIRequest(name=name, arguments=arguments)
+        logger.debug(f"Sending API request: {name}")
 
         try:
             # Send request
@@ -118,17 +128,21 @@ def _send_request(self, name: str, arguments: dict[str, Any]) -> dict[str, Any]:
 
             # Check for error response
             if "error" in response_data:
+                logger.error(f"API request {name} failed: {response_data.get('error')}")
                 raise create_exception_from_error_response(response_data)
 
+            logger.debug(f"API request {name} completed successfully")
             return response_data
 
         except socket.error as e:
+            logger.error(f"Socket error during API request {name}: {e}")
             raise ConnectionFailedError(
                 f"Socket error during communication: {e}",
                 error_code="E008",
                 context={"error": str(e)},
             ) from e
         except json.JSONDecodeError as e:
+            logger.error(f"Invalid JSON response from API request {name}: {e}")
             raise BalatroError(
                 f"Invalid JSON response from game: {e}",
                 error_code="E001",

src/lua/log.lua

@@ -17,14 +17,14 @@ end
 
 ---Logs a function call to the JSONL file
 ---@param function_name string The name of the function being called
----@param params table The parameters passed to the function
-function LOG.write(function_name, params)
+---@param arguments table The parameters passed to the function
+function LOG.write(function_name, arguments)
   ---@type LogEntry
   local log_entry = {
     timestamp_ms = math.floor(socket.gettime() * 1000),
     ["function"] = {
       name = function_name,
-      params = params,
+      arguments = arguments,
     },
     -- game_state before the function call
     game_state = utils.get_game_state(),
@@ -57,9 +57,9 @@ end
 function LOG.hook_go_to_menu()
   local original_function = G.FUNCS.go_to_menu
   G.FUNCS.go_to_menu = function(args)
-    local params = {}
+    local arguments = {}
     local name = "go_to_menu"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.go_to_menu for logging", "LOG")
@@ -77,14 +77,14 @@ function LOG.hook_start_run()
     local timestamp = LOG.generate_iso8601_timestamp()
     LOG.current_run_file = LOG.mod_path .. "runs/" .. timestamp .. ".jsonl"
     sendInfoMessage("Starting new run log: " .. timestamp .. ".jsonl", "LOG")
-    local params = {
+    local arguments = {
       deck = G.GAME.selected_back.name,
       stake = args.stake,
       seed = args.seed,
       challenge = args.challenge and args.challenge.name,
     }
     local name = "start_run"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(game_state, args)
   end
   sendDebugMessage("Hooked into G.FUNCS.start_run for logging", "LOG")
@@ -98,9 +98,9 @@ end
 function LOG.hook_select_blind()
   local original_function = G.FUNCS.select_blind
   G.FUNCS.select_blind = function(args)
-    local params = { action = "select" }
+    local arguments = { action = "select" }
     local name = "skip_or_select_blind"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.select_blind for logging", "LOG")
@@ -110,9 +110,9 @@ end
 function LOG.hook_skip_blind()
   local original_function = G.FUNCS.skip_blind
   G.FUNCS.skip_blind = function(args)
-    local params = { action = "skip" }
+    local arguments = { action = "skip" }
     local name = "skip_or_select_blind"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.skip_blind for logging", "LOG")
@@ -132,9 +132,9 @@ function LOG.hook_play_cards_from_highlighted()
         table.insert(cards, i - 1) -- Adjust for 0-based indexing
       end
     end
-    local params = { action = "play_hand", cards = cards }
+    local arguments = { action = "play_hand", cards = cards }
     local name = "play_hand_or_discard"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.play_cards_from_highlighted for logging", "LOG")
@@ -150,9 +150,9 @@ function LOG.hook_discard_cards_from_highlighted()
         table.insert(cards, i - 1) -- Adjust for 0-based indexing
       end
     end
-    local params = { action = "discard", cards = cards }
+    local arguments = { action = "discard", cards = cards }
     local name = "play_hand_or_discard"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.discard_cards_from_highlighted for logging", "LOG")
@@ -166,9 +166,9 @@ end
 function LOG.hook_cash_out()
   local original_function = G.FUNCS.cash_out
   G.FUNCS.cash_out = function(args)
-    local params = {}
+    local arguments = {}
     local name = "cash_out"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.cash_out for logging", "LOG")
@@ -182,9 +182,9 @@ end
 function LOG.hook_toggle_shop()
   local original_function = G.FUNCS.toggle_shop
   G.FUNCS.toggle_shop = function(args)
-    local params = { action = "next_round" }
+    local arguments = { action = "next_round" }
     local name = "shop"
-    LOG.write(name, params)
+    LOG.write(name, arguments)
     return original_function(args)
   end
   sendDebugMessage("Hooked into G.FUNCS.toggle_shop for logging", "LOG")

src/lua/types.lua

@@ -123,7 +123,7 @@
 
 ---@class LogEntry
 ---@field timestamp_ms number Timestamp in milliseconds since epoch
----@field function {name: string, params: table} Function call information
+---@field function {name: string, arguments: table} Function call information
 ---@field game_state GameStateResponse Game state at time of logging
 
 -- =============================================================================

tests/lua/test_runs.py

@@ -53,7 +53,7 @@ def test_replay_run(self, tcp_client: socket.socket, jsonl_file: Path) -> None:
 
             # Call the API function with recorded parameters
             actual_game_state = send_and_receive_api_message(
-                tcp_client, function_call["name"], function_call["params"]
+                tcp_client, function_call["name"], function_call["arguments"]
             )
 
             # Compare with the game_state from the next step (if it exists)
@@ -64,7 +64,7 @@ def test_replay_run(self, tcp_client: socket.socket, jsonl_file: Path) -> None:
                 # Assert complete game state equality
                 assert actual_game_state == expected_game_state, (
                     f"Game state mismatch at step {step_num + 1} in {jsonl_file.name}\n"
-                    f"Function: {function_call['name']}({function_call['params']})\n"
+                    f"Function: {function_call['name']}({function_call['arguments']})\n"
                     f"Expected: {expected_game_state}\n"
                     f"Actual: {actual_game_state}"
                 )