From 3e34d8c1a15005ccb6530584fea64dc4c25a319f Mon Sep 17 00:00:00 2001 From: frank <98238480+soundsonacid@users.noreply.github.com> Date: Thu, 28 Dec 2023 14:04:17 -0600 Subject: [PATCH] logging stuff (#13) * chore: replace all prints with loggers * chore: update deps * feat: toggle logging verbosity --- python/README.md | 2 +- python/sdk/examples/shotgun.py | 8 +-- python/sdk/examples/sniper.py | 2 +- python/sdk/jit_proxy/jitter/base_jitter.py | 67 ++++++++++--------- python/sdk/jit_proxy/jitter/jitter_shotgun.py | 22 +++--- python/sdk/jit_proxy/jitter/jitter_sniper.py | 32 +++++---- 6 files changed, 68 insertions(+), 65 deletions(-) diff --git a/python/README.md b/python/README.md index 268dd9ab..08776275 100644 --- 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 index aeaf4713..d57f8a12 100644 --- 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 index b77842dc..fb649fb2 100644 --- 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 index 967a25b2..4f1f8345 100644 --- 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 index 7d64246d..866aabc2 100644 --- 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,8 +12,6 @@ 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__( @@ -22,8 +19,9 @@ def __init__( 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 index 43120988..5a37b5f2 100644 --- 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,7 +97,7 @@ 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" @@ -107,7 +105,7 @@ async def try_fill(): 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: