perf: better update_order_status handle

Closes #7
2025-07-20 19:08:56 +08:00
parent 9eaab25451
commit c79316c978
1 changed files with 100 additions and 106 deletions
--- a/main.py
+++ b/main.py
@@ -8,19 +8,8 @@ from dataclasses import dataclass
 import mexc_spot_v3

 # 配置日志
-CUSTOM_DEBUG_LEVEL = 15
-logging.addLevelName(CUSTOM_DEBUG_LEVEL, "CUSTOM_DEBUG")
-
-
-class CustomLogger(logging.getLoggerClass()):
-    def custom_debug(self, msg, *args, **kwargs):
-        if self.isEnabledFor(CUSTOM_DEBUG_LEVEL):
-            self._log(CUSTOM_DEBUG_LEVEL, msg, args, **kwargs)
-
-
-logging.setLoggerClass(CustomLogger)
 logging.basicConfig(
-    level=CUSTOM_DEBUG_LEVEL,
+    level=logging.DEBUG,
    format="%(asctime)s - %(name)s - %(levelname)s - %(message)s",
    handlers=[
        logging.FileHandler("output/mexc_spot_grid_bot.log", encoding="utf-8"),
@@ -28,9 +17,6 @@ logging.basicConfig(
    ],
 )
 logger = logging.getLogger(__name__)
-logger.custom_debug = lambda msg, *args, **kwargs: logger._log(  # pylint: disable=W0212
-    CUSTOM_DEBUG_LEVEL, msg, args, **kwargs
-)


@dataclass
@@ -60,7 +46,7 @@ class GridTradingBot:
                - reserve_base: 保留的基础货币数量 (如 1 BTC)
                - reserve_quote: 保留的报价货币数量 (如 100 USDC)
        """
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.__init__] Initializing GridTradingBot with config: %r",
            conf,
        )
@@ -83,7 +69,7 @@ class GridTradingBot:
        self.current_sell_levels = 0

        # 初始化API
-        logger.custom_debug("[GridTradingBot.__init__] Initializing MEXC API clients")
+        logger.debug("[GridTradingBot.__init__] Initializing MEXC API clients")
        self.api_trade = mexc_spot_v3.mexc_trade()
        self.api_market = mexc_spot_v3.mexc_market()

@@ -165,14 +151,14 @@ class GridTradingBot:

    def api_get_price(self) -> float:
        """获取当前市场价格"""
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.api_get_price] Fetching current market price for symbol: %s",
            self.symbol,
        )
        try:
            ticker = self.api_market.get_price({"symbol": self.symbol})
            price = float(ticker["price"])
-            logger.custom_debug(
+            logger.debug(
                "[GridTradingBot.api_get_price] Current market price: %f", price
            )
            return price
@@ -191,7 +177,7 @@ class GridTradingBot:
        base_available = 0.0
        quote_available = 0.0

-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.api_get_balances] Fetching balances for %s and %s",
            base_currency,
            quote_currency,
@@ -201,20 +187,20 @@ class GridTradingBot:
            for balance in balances.get("balances", []):
                if balance["asset"] == base_currency:
                    base_available = float(balance["free"])
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.api_get_balances] Base currency (%s) available: %f",
                        base_currency,
                        base_available,
                    )
                elif balance["asset"] == quote_currency:
                    quote_available = float(balance["free"])
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.api_get_balances] Quote currency (%s) available: %f",
                        quote_currency,
                        quote_available,
                    )

-            logger.custom_debug(
+            logger.debug(
                "[GridTradingBot.api_get_balances] Final balances - base: %f, quote: %f",
                base_available,
                quote_available,
@@ -229,7 +215,7 @@ class GridTradingBot:
    def calculate_order_value(self, price: float) -> float:
        """计算订单价值 (价格 * 数量)"""
        value = price * self.order_amount
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.calculate_order_value] Calculated order value: price=%f * amount=%f = %f",
            price,
            self.order_amount,
@@ -241,7 +227,7 @@ class GridTradingBot:
        """检查订单价值是否满足最小挂单要求"""
        value = self.calculate_order_value(price)
        is_valid = value >= self.min_order_value
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.is_order_value_valid] Order value validation: %f >= %f? %s",
            value,
            self.min_order_value,
@@ -261,7 +247,7 @@ class GridTradingBot:
        返回:
            计算后的价格
        """
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.calculate_grid_price] Calculating grid price: base=%f, level=%d, side=%s",
            base_price,
            level,
@@ -270,7 +256,7 @@ class GridTradingBot:

        if side == "BUY":
            price = base_price / (1 + self.grid_percentage) ** level
-            logger.custom_debug(
+            logger.debug(
                "[GridTradingBot.calculate_grid_price] Calculated BUY price: %f / (1 + %f)^%d = %f",
                base_price,
                self.grid_percentage,
@@ -280,7 +266,7 @@ class GridTradingBot:
            return price
        elif side == "SELL":
            price = base_price * (1 + self.grid_percentage) ** level
-            logger.custom_debug(
+            logger.debug(
                "[GridTradingBot.calculate_grid_price] Calculated SELL price: %f * (1 + %f)^%d = %f",
                base_price,
                self.grid_percentage,
@@ -306,7 +292,7 @@ class GridTradingBot:
        返回:
            订单ID (如果下单成功) 或 None (如果失败)
        """
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.api_place_order] Attempting to place %s order at price: %f",
            side,
            price,
@@ -323,9 +309,6 @@ class GridTradingBot:
            return None

        try:
-            # logger.custom_debug(
-            #     "[GridTradingBot.api_place_order] Sending order request to exchange"
-            # )
            order_detail = self.api_trade.post_order(
                {
                    "symbol": self.symbol,
@@ -364,7 +347,7 @@ class GridTradingBot:

    def api_cancel_order(self, order_id: str):
        """取消订单"""
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.api_cancel_order] Attempting to cancel order: %s", order_id
        )
        try:
@@ -383,7 +366,7 @@ class GridTradingBot:

    def api_cancel_all_orders(self):
        """取消所有活跃订单"""
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.api_cancel_all_orders] Attempting to cancel all open orders for symbol: %s",
            self.symbol,
        )
@@ -405,65 +388,82 @@ class GridTradingBot:

    def api_update_order_statuses(self):
        """更新所有活跃订单的状态"""
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.api_update_order_statuses] Updating status for %d active orders",
            len(self.active_orders),
        )

-        for order_id in list(self.active_orders.keys()):
-            try:
-                logger.custom_debug(
-                    "[GridTradingBot.api_update_order_statuses] Checking status for order: %s",
-                    order_id,
-                )
-                order_info = self.api_trade.get_order(
-                    {"symbol": self.symbol, "orderId": order_id}
-                )
+        # 分别处理买单和卖单
+        for side in ["BUY", "SELL"]:
+            # 获取当前方向的所有订单并按价格排序
+            orders = self.get_active_orders_by_side(side)

-                # 更新订单状态
-                old_status = self.active_orders[order_id].status
-                new_status = order_info["status"]
-                self.active_orders[order_id].status = new_status
+            # 买单从高到低排序，卖单从低到高排序
+            if side == "BUY":
+                orders.sort(key=lambda x: float(x.price), reverse=True)
+            else:
+                orders.sort(key=lambda x: float(x.price))

-                # 记录状态变化
-                if old_status != new_status:
-                    logger.info(
-                        "[GridTradingBot.api_update_order_statuses] Order %s status changed from %s to %s",
+            # 遍历订单
+            for order in orders:
+                order_id = order.order_id
+                try:
+                    logger.debug(
+                        "[GridTradingBot.api_update_order_statuses] Checking status for order: %s",
                        order_id,
-                        old_status,
-                        new_status,
+                    )
+                    order_info = self.api_trade.get_order(
+                        {"symbol": self.symbol, "orderId": order_id}
                    )

-                # 如果订单已完成，记录成交时间
-                if new_status == "FILLED":
-                    self.active_orders[order_id].filled_time = time.time()
-                    logger.custom_debug(
-                        "[GridTradingBot.api_update_order_statuses] Order %s filled at %f",
-                        order_id,
-                        self.active_orders[order_id].filled_time,
-                    )
-                    self.record_transaction(order_info)
+                    # 更新订单状态
+                    old_status = self.active_orders[order_id].status
+                    new_status = order_info["status"]
+                    self.active_orders[order_id].status = new_status

-                if new_status in ["CANCELED"]:
-                    logger.custom_debug(
-                        "[GridTradingBot.api_update_order_statuses] Removing order %s from active orders (status: %s)",
-                        order_id,
-                        new_status,
-                    )
-                    self.active_orders.pop(order_id)
+                    # 记录状态变化
+                    if old_status != new_status:
+                        logger.info(
+                            "[GridTradingBot.api_update_order_statuses] Order %s status changed from %s to %s",
+                            order_id,
+                            old_status,
+                            new_status,
+                        )

-            except Exception as e:
-                logger.error(
-                    "[GridTradingBot.api_update_order_statuses] Failed to get status for order %s: %s",
-                    order_id,
-                    str(e),
-                )
-                self.api_update_order_statuses()
+                    # 如果订单已完成，记录成交时间
+                    if new_status == "FILLED":
+                        self.active_orders[order_id].filled_time = time.time()
+                        logger.debug(
+                            "[GridTradingBot.api_update_order_statuses] Order %s filled at %f",
+                            order_id,
+                            self.active_orders[order_id].filled_time,
+                        )
+                        self.record_transaction(order_info)
+
+                    if new_status in ["CANCELED"]:
+                        logger.debug(
+                            "[GridTradingBot.api_update_order_statuses] Removing order %s from active orders (status: %s)",
+                            order_id,
+                            new_status,
+                        )
+                        self.active_orders.pop(order_id)
+
+                    if new_status == "NEW":
+                        logger.debug("[GridTradingBot.api_update_order_statuses] NEW order detected for %s side, skipping.", side)
+                        break
+
+                except Exception as e:
+                    logger.error(
+                        "[GridTradingBot.api_update_order_statuses] Failed to get status for order %s: %s",
+                        order_id,
+                        str(e),
+                    )
+                    self.api_update_order_statuses()

    def get_active_orders_by_side(self, side: str) -> List[Order]:
        """获取指定方向的所有活跃订单"""
        orders = [order for order in self.active_orders.values() if order.side == side]
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.get_active_orders_by_side] Found %d active %s orders",
            len(orders),
            side,
@@ -485,7 +485,7 @@ class GridTradingBot:
            max([order.price for order in sell_orders]) if sell_orders else None
        )

-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.get_extreme_prices] Extreme prices - lowest buy: %s, highest sell: %s",
            lowest_buy,
            highest_sell,
@@ -509,7 +509,7 @@ class GridTradingBot:
            # 初始下单: 买1和卖1
            buy_price = self.calculate_grid_price(market_price, 1, "BUY")
            sell_price = self.calculate_grid_price(market_price, 1, "SELL")
-            logger.custom_debug(
+            logger.debug(
                "[GridTradingBot.initialize_grid] Initial buy price: %f, sell price: %f",
                buy_price,
                sell_price,
@@ -525,13 +525,13 @@ class GridTradingBot:

            # 下单买1
            if quote_balance > self.reserve_quote:
-                logger.custom_debug(
+                logger.debug(
                    "[GridTradingBot.initialize_grid] Quote balance sufficient (%f > %f), checking order value",
                    quote_balance,
                    self.reserve_quote,
                )
                if self.is_order_value_valid(buy_price):
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.initialize_grid] Order value valid, placing buy order"
                    )
                    buy_order_id = self.api_place_order(buy_price, "BUY")
@@ -563,13 +563,13 @@ class GridTradingBot:

            # 下单卖1
            if base_balance > self.reserve_base:
-                logger.custom_debug(
+                logger.debug(
                    "[GridTradingBot.initialize_grid] Base balance sufficient (%f > %f), checking order value",
                    base_balance,
                    self.reserve_base,
                )
                if self.is_order_value_valid(sell_price):
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.initialize_grid] Order value valid, placing sell order"
                    )
                    sell_order_id = self.api_place_order(sell_price, "SELL")
@@ -609,7 +609,7 @@ class GridTradingBot:

    def extend_grid(self):
        """扩展网格，保证两侧都有指定个数的挂单"""
-        logger.custom_debug(
+        logger.debug(
            "[GridTradingBot.extend_grid] Extending grid - current buy levels: %d/%d, sell levels: %d/%d",
            self.current_buy_levels,
            self.grid_count,
@@ -632,24 +632,24 @@ class GridTradingBot:
                    lowest_buy = self.calculate_grid_price(
                        highest_sell, self.grid_count, "BUY"
                    )
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.extend_grid] lowest_buy was None, calculating based on highest_sell"
                    )
                new_buy_price = self.calculate_grid_price(lowest_buy, 1, "BUY")
-                logger.custom_debug(
+                logger.debug(
                    "[GridTradingBot.extend_grid] Extending buy grid - current lowest: %f, new price: %f",
                    lowest_buy,
                    new_buy_price,
                )

                if quote_balance > self.reserve_quote:
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.extend_grid] Quote balance sufficient (%f > %f), checking order value",
                        quote_balance,
                        self.reserve_quote,
                    )
                    if self.is_order_value_valid(new_buy_price):
-                        logger.custom_debug(
+                        logger.debug(
                            "[GridTradingBot.extend_grid] Order value valid, placing extended buy order"
                        )
                        buy_order_id = self.api_place_order(new_buy_price, "BUY")
@@ -690,24 +690,24 @@ class GridTradingBot:
                    highest_sell = self.calculate_grid_price(
                        lowest_buy, self.grid_count, "SELL"
                    )
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.extend_grid] highest_sell was None, calculating based on lowest_buy"
                    )
                new_sell_price = self.calculate_grid_price(highest_sell, 1, "SELL")
-                logger.custom_debug(
+                logger.debug(
                    "[GridTradingBot.extend_grid] Extending sell grid - current highest: %f, new price: %f",
                    highest_sell,
                    new_sell_price,
                )

                if base_balance > self.reserve_base:
-                    logger.custom_debug(
+                    logger.debug(
                        "[GridTradingBot.extend_grid] Base balance sufficient (%f > %f), checking order value",
                        base_balance,
                        self.reserve_base,
                    )
                    if self.is_order_value_valid(new_sell_price):
-                        logger.custom_debug(
+                        logger.debug(
                            "[GridTradingBot.extend_grid] Order value valid, placing extended sell order"
                        )
                        sell_order_id = self.api_place_order(new_sell_price, "SELL")
@@ -756,9 +756,7 @@ class GridTradingBot:
          1. 取消最低价买单
          2. 在买单侧挂一个更高价的买单（买0）
          3. 在卖单侧挂一个更高价的卖单（卖n）"""
-        logger.custom_debug(
-            "[GridTradingBot.adjust_grid] Adjusting grid with symmetric logic"
-        )
+        logger.debug("[GridTradingBot.adjust_grid] Adjusting grid with symmetric logic")

        try:
            # 获取当前所有订单的快照
@@ -772,9 +770,7 @@ class GridTradingBot:
            ]

            if newly_filled_orders:
-                logger.custom_debug(
-                    "[GridTradingBot.adjust_grid] Newly filled orders found"
-                )
+                logger.debug("[GridTradingBot.adjust_grid] Newly filled orders found")
                # 处理每个新成交的订单
                for filled_order in newly_filled_orders:
                    filled_side = filled_order.side
@@ -925,9 +921,7 @@ class GridTradingBot:
            # 主循环
            while self.running:
                try:
-                    logger.custom_debug(
-                        "[GridTradingBot.run] Starting main loop iteration"
-                    )
+                    logger.debug("[GridTradingBot.run] Starting main loop iteration")

                    # 更新订单状态
                    self.api_update_order_statuses()
@@ -940,16 +934,16 @@ class GridTradingBot:
                    self.extend_grid()

                    # 等待一段时间再检查
-                    sleep_time = 0
-                    logger.custom_debug(
+                    sleep_time = 1
+                    logger.debug(
                        "[GridTradingBot.run] Sleeping for %d seconds", sleep_time
                    )
                    time.sleep(sleep_time)

                except Exception as e:
                    logger.error("[GridTradingBot.run] Error in main loop: %s", str(e))
-                    sleep_time = 1
-                    logger.custom_debug(
+                    sleep_time = 3
+                    logger.debug(
                        "[GridTradingBot.run] Error occurred, sleeping for %d seconds",
                        sleep_time,
                    )