Improve execution client debug logging for Polymarket

Author: cjdsellers

RELEASES.md

@@ -51,6 +51,7 @@ None
 - Improved Cython-Rust indicator parity for `WilderMovingAverage` (RMA) (#2653), thanks @nicolad
 - Improved zero size trade logging for Binance Futures (#2588), thanks @bartolootrit
 - Improved error handling on API key authentication errors for Polymarket
+- Improved execution client debug logging for Polymarket
 - Improved exception on deserializing order from cache database
 - Improved `None` condition checks for value types, which now raise a `TypeError` instead of an obscure `AttributeError`
 - Implemented remaining Display for orders in Rust (#2614), thanks @nicolad

examples/live/polymarket/polymarket_market_maker.py

@@ -111,6 +111,7 @@
             passphrase=None,  # 'POLYMARKET_PASSPHRASE' env var
             instrument_provider=instrument_provider_config,
             generate_order_history_from_trades=False,
+            log_raw_ws_messages=False,
         ),
     },
     timeout_connection=60.0,

nautilus_trader/adapters/polymarket/config.py

@@ -116,6 +116,9 @@ class PolymarketExecClientConfig(LiveExecClientConfig, frozen=True):
         If True, uses trades history to generate reports for orders which are no longer active.
         The Polymarket API only returns active orders and trades.
         This feature is experimental and is not currently recommended (leave set to False).
+    log_raw_ws_messages : bool, default False
+        If raw websocket messages should be logged with debug level.
+        Note: there will be a performance penalty parsing the JSON without an efficient msgspec decoder.
 
     """
 
@@ -132,3 +135,4 @@ class PolymarketExecClientConfig(LiveExecClientConfig, frozen=True):
     retry_delay_initial_ms: PositiveInt | None = None
     retry_delay_max_ms: PositiveInt | None = None
     generate_order_history_from_trades: bool = False
+    log_raw_ws_messages: bool = False

nautilus_trader/adapters/polymarket/execution.py

@@ -14,6 +14,7 @@
 # -------------------------------------------------------------------------------------------------
 
 import asyncio
+import json
 from collections import defaultdict
 from collections.abc import Coroutine
 from typing import Any
@@ -157,6 +158,7 @@ def __init__(
         self._log.info(f"{config.retry_delay_initial_ms=}", LogColor.BLUE)
         self._log.info(f"{config.retry_delay_max_ms=}", LogColor.BLUE)
         self._log.info(f"{config.generate_order_history_from_trades=}", LogColor.BLUE)
+        self._log.info(f"{config.log_raw_ws_messages=}", LogColor.BLUE)
 
         account_id = AccountId(f"{name or POLYMARKET_VENUE.value}-001")
         self._set_account_id(account_id)
@@ -864,9 +866,13 @@ async def _submit_order(self, command: SubmitOrder) -> None:
             await self._retry_manager_pool.release(retry_manager)
 
     def _handle_ws_message(self, raw: bytes) -> None:
-        # Uncomment for development
-        # self._log.info(str(json.dumps(msgspec.json.decode(raw), indent=4)), color=LogColor.MAGENTA)
         try:
+            if self._config.log_raw_ws_messages:
+                self._log.debug(
+                    str(json.dumps(msgspec.json.decode(raw), indent=4)),
+                    color=LogColor.MAGENTA,
+                )
+
             ws_message = self._decoder_user_msg.decode(raw)
             for msg in ws_message:
                 if isinstance(msg, PolymarketUserOrder):
@@ -928,6 +934,8 @@ async def _wait_for_ack_trade(
         self._handle_ws_trade_msg(msg, wait_for_ack=False)
 
     def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
+        self._log.debug(f"Handling order message, {wait_for_ack=}")
+
         venue_order_id = msg.venue_order_id()
         instrument_id = get_polymarket_instrument_id(msg.market, msg.asset_id)
         instrument = self._cache.instrument(instrument_id)
@@ -939,6 +947,7 @@ def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
             return
 
         client_order_id = self._cache.client_order_id(venue_order_id)
+        self._log.debug(f"Processing order update for {client_order_id!r}")
 
         strategy_id = None
         if client_order_id:
@@ -956,6 +965,8 @@ def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
 
         match msg.type:
             case PolymarketEventType.PLACEMENT:
+                self._log.debug(f"PLACEMENT: {client_order_id!r}", LogColor.MAGENTA)
+
                 self.generate_order_accepted(
                     strategy_id=strategy_id,
                     instrument_id=instrument_id,
@@ -964,6 +975,8 @@ def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
                     ts_event=self._clock.timestamp_ns(),
                 )
             case PolymarketEventType.CANCELLATION:
+                self._log.debug(f"CANCELLATION: {client_order_id!r}", LogColor.MAGENTA)
+
                 self.generate_order_canceled(
                     strategy_id=strategy_id,
                     instrument_id=instrument_id,
@@ -972,6 +985,8 @@ def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
                     ts_event=millis_to_nanos(int(msg.timestamp)),
                 )
             case PolymarketEventType.UPDATE:  # Matched
+                self._log.debug(f"UPDATE: {client_order_id!r}", LogColor.MAGENTA)
+
                 assert msg.associate_trades is not None  # Type checking
                 order = self._cache.order(client_order_id)
 
@@ -999,6 +1014,7 @@ def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
                     return
 
                 if order.is_closed:
+                    self._log.warning(f"Order already closed - skipping fill: {order}")
                     return  # Already closed (only status update)
 
                 matched_qty = instrument.make_qty(float(msg.size_matched))
@@ -1023,6 +1039,8 @@ def _handle_ws_order_msg(self, msg: PolymarketUserOrder, wait_for_ack: bool):
                 )
 
                 self._loop.create_task(self._update_account_state())
+            case _:
+                raise RuntimeError(f"Unknown `PolymarketEventType`, was '{msg.type.value}'")
 
     def _handle_ws_trade_msg(self, msg: PolymarketUserTrade, wait_for_ack: bool):
         self._log.debug(f"Handling trade message, {wait_for_ack=}")
@@ -1063,6 +1081,7 @@ def _handle_ws_trade_msg(self, msg: PolymarketUserTrade, wait_for_ack: bool):
         order = self._cache.order(client_order_id)
 
         if order.is_closed:
+            self._log.warning(f"Order already closed - skipping trade: {order}")
             return  # Already closed (only status update)
 
         last_qty = instrument.make_qty(msg.last_qty(self._wallet_address))