logging stuff (#13)

* chore: replace all prints with loggers * chore: update deps * feat: toggle logging verbosity
drift-labs · Dec 28, 2023 · 3e34d8c · 3e34d8c
1 parent 9de5a86
commit 3e34d8c
Show file tree

Hide file tree

Showing 6 changed files with 68 additions and 65 deletions.
diff --git a/python/README.md b/python/README.md
@@ -27,7 +27,7 @@ However, the ```JitterSniper``` also requires a ```SlotSubscriber``` in its cons
         Pubkey.from_string("J1TnP8zvVxbtF5KFp5xRmWuvG9McnhzmBd9XGfCyuxFP"),
     )
 
-    jitter_shotgun = JitterShotgun(drift_client, auction_subscriber, jit_proxy_client)
+    jitter_shotgun = JitterShotgun(drift_client, auction_subscriber, jit_proxy_client, True) # The boolean is logging verbosity, True = verbose.
 
     jit_params = JitParams(
         bid=-1_000_000,

diff --git a/python/sdk/examples/shotgun.py b/python/sdk/examples/shotgun.py
@@ -14,9 +14,9 @@
 from driftpy.auction_subscriber.types import AuctionSubscriberConfig
 from driftpy.keypair import load_keypair
 
-from jit_proxy.jitter.jitter_shotgun import JitterShotgun
-from jit_proxy.jitter.base_jitter import JitParams
-from jit_proxy.jit_proxy_client import JitProxyClient, PriceType
+from jit_proxy.jitter.jitter_shotgun import JitterShotgun # type: ignore
+from jit_proxy.jitter.base_jitter import JitParams # type: ignore
+from jit_proxy.jit_proxy_client import JitProxyClient, PriceType #type: ignore
 
 
 async def main():
@@ -44,7 +44,7 @@ async def main():
         Pubkey.from_string("J1TnP8zvVxbtF5KFp5xRmWuvG9McnhzmBd9XGfCyuxFP"),
     )
 
-    jitter_shotgun = JitterShotgun(drift_client, auction_subscriber, jit_proxy_client)
+    jitter_shotgun = JitterShotgun(drift_client, auction_subscriber, jit_proxy_client, True)
 
     jit_params = JitParams(
         bid=-1_000_000,

diff --git a/python/sdk/examples/sniper.py b/python/sdk/examples/sniper.py
@@ -48,7 +48,7 @@ async def main():
     )
 
     jitter_sniper = JitterSniper(
-        drift_client, slot_subscriber, auction_subscriber, jit_proxy_client
+        drift_client, slot_subscriber, auction_subscriber, jit_proxy_client, True
     )
 
     jit_params = JitParams(

diff --git a/python/sdk/jit_proxy/jitter/base_jitter.py b/python/sdk/jit_proxy/jitter/base_jitter.py
@@ -18,9 +18,6 @@
 
 UserFilter = Callable[[UserAccount, str, Order], bool]
 
-logging.basicConfig(level=logging.INFO)
-logger = logging.getLogger(__name__)
-
 @dataclass
 class JitParams:
     bid: int
@@ -38,6 +35,7 @@ def __init__(
         drift_client: DriftClient,
         auction_subscriber: AuctionSubscriber,
         jit_proxy_client: JitProxyClient,
+        verbose: bool,
     ):
         self.drift_client = drift_client
         self.auction_subscriber = auction_subscriber
@@ -47,6 +45,15 @@ def __init__(
         self.ongoing_auctions: Dict[str, asyncio.Future] = {}
         self.user_filter: Optional[UserFilter] = None
 
+        if verbose:
+            logging_level = logging.INFO
+        else:
+            logging_level = logging.WARNING
+
+        logging.basicConfig(level=logging_level)
+        self.logger = logging.getLogger(__name__)
+
+
     @abstractmethod
     async def subscribe(self):
         await self.drift_client.subscribe()
@@ -60,59 +67,59 @@ def on_account_update_sync(self, taker: UserAccount, taker_key: Pubkey, slot: in
         asyncio.create_task(self.on_account_update(taker, taker_key, slot))
 
     async def on_account_update(self, taker: UserAccount, taker_key: Pubkey, slot: int):
-        logger.info("Auction received!")
-        logger.info("----------------------------")
+        self.logger.info("Auction received!")
+        self.logger.info("----------------------------")
         taker_key_str = str(taker_key)
 
         taker_stats_key = get_user_stats_account_public_key(
             self.drift_client.program_id, taker.authority
         )
 
-        logger.info(f"Taker: {taker.authority}")
+        self.logger.info(f"Taker: {taker.authority}")
 
         for order in taker.orders:
             if not is_variant(order.status, "Open"):
-                logger.info("Order is closed.")
-                logger.info("----------------------------")
+                self.logger.info("Order is closed.")
+                self.logger.info("----------------------------")
                 continue
 
             if not has_auction_price(order, slot):
-                logger.info("Order does not have auction price.")
-                logger.info("----------------------------")
+                self.logger.info("Order does not have auction price.")
+                self.logger.info("----------------------------")
                 continue
 
             if self.user_filter is not None:
                 if self.user_filter(taker, taker_key_str, order):
-                    logger.info("User filtered out.")
+                    self.logger.info("User filtered out.")
                     return
 
             order_sig = self.get_order_signatures(taker_key_str, order.order_id)
 
-            logger.info(f"Order sig: {order_sig}")
+            self.logger.info(f"Order sig: {order_sig}")
 
             if order_sig in self.ongoing_auctions:
                 continue
 
-            logger.info(f"Market Type: {str(order.market_type)}")
-            logger.info(f"Market Index: {order.market_index}")
-            logger.info(f"Order Price: {convert_to_number(order.price)}")
-            logger.info(f"Order Type: {str(order.order_type)}")
-            logger.info(f"Order Direction: {str(order.direction)}")
-            logger.info(
+            self.logger.info(f"Market Type: {str(order.market_type)}")
+            self.logger.info(f"Market Index: {order.market_index}")
+            self.logger.info(f"Order Price: {convert_to_number(order.price)}")
+            self.logger.info(f"Order Type: {str(order.order_type)}")
+            self.logger.info(f"Order Direction: {str(order.direction)}")
+            self.logger.info(
                 f"Auction Start Price: {convert_to_number(order.auction_start_price)}"
             )
-            logger.info(f"Auction End Price: {convert_to_number(order.auction_end_price)}")
-            logger.info(
+            self.logger.info(f"Auction End Price: {convert_to_number(order.auction_end_price)}")
+            self.logger.info(
                 f"Order Base Asset Amount: {convert_to_number(order.base_asset_amount)}"
             )
-            logger.info(
+            self.logger.info(
                 f"Order Base Asset Amount Filled: {convert_to_number(order.base_asset_amount_filled)}"
             )
 
             if is_variant(order.order_type, "Perp"):
-                logger.info("Perp Auction")
+                self.logger.info("Perp Auction")
                 if not order.market_index in self.perp_params:
-                    logger.info(f"Jitter not listening to {order.market_index}")
+                    self.logger.info(f"Jitter not listening to {order.market_index}")
                     return
 
                 perp_market_account = self.drift_client.get_perp_market_account(
@@ -123,8 +130,8 @@ async def on_account_update(self, taker: UserAccount, taker_key: Pubkey, slot: i
                     order.base_asset_amount - order.base_asset_amount_filled
                     <= perp_market_account.amm.min_order_size
                 ):
-                    logger.info("Order filled within min_order_size")
-                    logger.info("----------------------------")
+                    self.logger.info("Order filled within min_order_size")
+                    self.logger.info("----------------------------")
                     return
 
                 future = asyncio.create_task(
@@ -135,10 +142,10 @@ async def on_account_update(self, taker: UserAccount, taker_key: Pubkey, slot: i
                 self.ongoing_auctions[order_sig] = future
 
             else:
-                logger.info("Spot Auction")
+                self.logger.info("Spot Auction")
                 if not order.market_index in self.spot_params:
-                    logger.info(f"Jitter not listening to {order.market_index}")
-                    logger.info("----------------------------")
+                    self.logger.info(f"Jitter not listening to {order.market_index}")
+                    self.logger.info("----------------------------")
                     return
 
                 spot_market_account = self.drift_client.get_spot_market_account(
@@ -149,8 +156,8 @@ async def on_account_update(self, taker: UserAccount, taker_key: Pubkey, slot: i
                     order.base_asset_amount - order.base_asset_amount_filled
                     <= spot_market_account.min_order_size
                 ):
-                    logger.info("Order filled within min_order_size")
-                    logger.info("----------------------------")
+                    self.logger.info("Order filled within min_order_size")
+                    self.logger.info("----------------------------")
                     return
 
                 future = asyncio.create_task(

diff --git a/python/sdk/jit_proxy/jitter/jitter_shotgun.py b/python/sdk/jit_proxy/jitter/jitter_shotgun.py
@@ -1,5 +1,4 @@
 import asyncio
-import logging
 
 from typing import Any, Coroutine
 
@@ -13,17 +12,16 @@
 from jit_proxy.jitter.base_jitter import BaseJitter
 from jit_proxy.jit_proxy_client import JitIxParams, JitProxyClient
 
-logging.basicConfig(level=logging.INFO)
-logger = logging.getLogger(__name__)
 
 class JitterShotgun(BaseJitter):
     def __init__(
         self,
         drift_client: DriftClient,
         auction_subscriber: AuctionSubscriber,
         jit_proxy_client: JitProxyClient,
+        verbose: bool,
     ):
-        super().__init__(drift_client, auction_subscriber, jit_proxy_client)
+        super().__init__(drift_client, auction_subscriber, jit_proxy_client, verbose)
 
     async def subscribe(self):
         await super().subscribe()
@@ -36,7 +34,7 @@ async def create_try_fill(
         order: Order,
         order_sig: str,
     ) -> Coroutine[Any, Any, None]:
-        logger.info("JitterShotgun: Creating Try Fill")
+        self.logger.info("JitterShotgun: Creating Try Fill")
 
         async def try_fill():
             for _ in range(10):
@@ -56,7 +54,7 @@ async def try_fill():
 
                 referrer_info = self.get_referrer_info(taker_stats)
 
-                logger.info(f"Trying to fill {order_sig}")
+                self.logger.info(f"Trying to fill {order_sig}")
 
                 try:
                     sig = await self.jit_proxy_client.jit(
@@ -76,19 +74,19 @@ async def try_fill():
                         )
                     )
 
-                    logger.info(f"Filled {order_sig}")
-                    logger.info(f"Signature: {sig}")
+                    self.logger.info(f"Filled {order_sig}")
+                    self.logger.info(f"Signature: {sig}")
                     await asyncio.sleep(10)  # sleep for 10 seconds
                     del self.ongoing_auctions[order_sig]
                     return
                 except Exception as e:
-                    logger.error(f"Failed to fill {order_sig}: {e}")
+                    self.logger.error(f"Failed to fill {order_sig}: {e}")
                     if "0x1770" in str(e) or "0x1771" in str(e):
-                        logger.error("Order does not cross params yet, retrying")
+                        self.logger.error("Order does not cross params yet, retrying")
                     elif "0x1793" in str(e):
-                        logger.error("Oracle invalid, retrying")
+                        self.logger.error("Oracle invalid, retrying")
                     elif "0x1772" in str(e):
-                        logger.error("Order already filled")
+                        self.logger.error("Order already filled")
                         # we don't want to retry if the order is filled
                         break
                     else:

diff --git a/python/sdk/jit_proxy/jitter/jitter_sniper.py b/python/sdk/jit_proxy/jitter/jitter_sniper.py
@@ -1,5 +1,4 @@
 import asyncio
-import logging
 
 from dataclasses import dataclass
 from typing import Any, Coroutine
@@ -21,8 +20,6 @@
 from jit_proxy.jitter.base_jitter import BaseJitter
 from jit_proxy.jit_proxy_client import JitProxyClient
 
-logging.basicConfig(level=logging.INFO)
-logger = logging.getLogger(__name__)
 
 @dataclass
 class AuctionAndOrderDetails:
@@ -43,8 +40,9 @@ def __init__(
         slot_subscriber: SlotSubscriber,
         auction_subscriber: AuctionSubscriber,
         jit_proxy_client: JitProxyClient,
+        verbose: bool,
     ):
-        super().__init__(drift_client, auction_subscriber, jit_proxy_client)
+        super().__init__(drift_client, auction_subscriber, jit_proxy_client, verbose)
         self.slot_subscriber = slot_subscriber
 
     async def subscribe(self):
@@ -59,7 +57,7 @@ async def create_try_fill(
         order: Order,
         order_sig: str,
     ) -> Coroutine[Any, Any, None]:
-        logger.info("JitterSniper: Creating Try Fill")
+        self.logger.info("JitterSniper: Creating Try Fill")
 
         async def try_fill():
             params = (
@@ -88,7 +86,7 @@ async def try_fill():
                     order.direction, "Short"
                 ):
                     if current_perp_pos.base_asset_amount <= params.min_position:
-                        logger.warning(
+                        self.logger.warning(
                             f"Order would increase existing short (mkt \
                               {str(order.market_type)}-{order.market_index} \
                               ) too much"
@@ -99,15 +97,15 @@ async def try_fill():
                         order.direction, "Long"
                     ):
                         if current_perp_pos.base_asset_amount >= params.max_position:
-                            logger.warning(
+                            self.logger.warning(
                                 f"Order would increase existing long (mkt \
                               {str(order.market_type)}-{order.market_index} \
                               ) too much"
                             )
                         del self.ongoing_auctions[order_sig]
                         return
 
-            logger.info(
+            self.logger.info(
                 f"""
                 Taker wants to {order.direction}, order slot is {order.slot},
                 My market: {details.bid}@{details.ask},
@@ -129,7 +127,7 @@ async def try_fill():
             )
 
             if slot == -1:
-                logger.info("Auction expired without crossing")
+                self.logger.info("Auction expired without crossing")
                 if order_sig in self.ongoing_auctions:
                     del self.ongoing_auctions[order_sig]
                 return
@@ -157,7 +155,7 @@ async def try_fill():
                 PRICE_PRECISION,
             )
 
-            logger.info(
+            self.logger.info(
                 f"""
                 Expected auction price: {details.auction_start_price + details.slots_until_cross * details.step_size}
                 Actual auction price: {auction_price}
@@ -167,7 +165,7 @@ async def try_fill():
             """
             )
 
-            logger.info(
+            self.logger.info(
                 f"""
                 Trying to fill {order_sig} with:
                 market: {bid}@{ask}
@@ -195,19 +193,19 @@ async def try_fill():
                         }
                     )
 
-                    logger.info(f"Filled {order_sig}")
-                    logger.info(f"tx signature: {tx_sig_and_slot.tx_sig}")
+                    self.logger.info(f"Filled {order_sig}")
+                    self.logger.info(f"tx signature: {tx_sig_and_slot.tx_sig}")
                     await asyncio.sleep(3)  # Sleep for 3 seconds
                     del self.ongoing_auctions[order_sig]
                     return
                 except Exception as e:
-                    logger.error(f"Failed to fill {order_sig}: {e}")
+                    self.logger.error(f"Failed to fill {order_sig}: {e}")
                     if "0x1770" in str(e) or "0x1771" in str(e):
-                        logger.error("Order does not cross params yet")
+                        self.logger.error("Order does not cross params yet")
                     elif "0x1793" in str(e):
-                        logger.error("Oracle invalid")
+                        self.logger.error("Oracle invalid")
                     elif "0x1772" in str(e):
-                        logger.error("Order already filled")
+                        self.logger.error("Order already filled")
                         # we don't want to retry if the order is filled
                         break
                     else: