Merge pull request #1310 from c9s/c9s/fix-pending-order-update-for-max

FIX: fix pending order update comparison

pkg/bbgo/activeorderbook.go

@@ -59,7 +59,9 @@ func (b *ActiveOrderBook) BindStream(stream types.Stream) {
 	stream.OnOrderUpdate(b.orderUpdateHandler)
 }
 
-func (b *ActiveOrderBook) waitClear(ctx context.Context, order types.Order, waitTime, timeout time.Duration) (bool, error) {
+func (b *ActiveOrderBook) waitClear(
+	ctx context.Context, order types.Order, waitTime, timeout time.Duration,
+) (bool, error) {
 	if !b.orders.Exists(order.OrderID) {
 		return true, nil
 	}
@@ -266,6 +268,7 @@ func (b *ActiveOrderBook) Update(order types.Order) {
 
 	b.mu.Lock()
 	if !b.orders.Exists(order.OrderID) {
+		log.Infof("[ActiveOrderBook] order #%d %s does not exist, adding it to pending order update", order.OrderID, order.Status)
 		b.pendingOrderUpdates.Add(order)
 		b.mu.Unlock()
 		return
@@ -275,6 +278,7 @@ func (b *ActiveOrderBook) Update(order types.Order) {
 	if previousOrder, ok := b.orders.Get(order.OrderID); ok {
 		previousUpdateTime := previousOrder.UpdateTime.Time()
 		if !previousUpdateTime.IsZero() && order.UpdateTime.Before(previousUpdateTime) {
+			log.Infof("[ActiveOrderBook] order #%d updateTime %s is out of date, skip it", order.OrderID, order.UpdateTime)
 			b.mu.Unlock()
 			return
 		}
@@ -287,6 +291,7 @@ func (b *ActiveOrderBook) Update(order types.Order) {
 		b.mu.Unlock()
 
 		if removed {
+			log.Infof("[ActiveOrderBook] order #%d is filled: %s", order.OrderID, order.String())
 			b.EmitFilled(order)
 		}
 		b.C.Emit()
@@ -330,13 +335,50 @@ func (b *ActiveOrderBook) Add(orders ...types.Order) {
 	}
 }
 
+func isNewerUpdate(a, b types.Order) bool {
+	// compare state first
+	switch a.Status {
+
+	case types.OrderStatusCanceled, types.OrderStatusRejected: // canceled is a final state
+		switch b.Status {
+		case types.OrderStatusNew, types.OrderStatusPartiallyFilled:
+			return true
+		}
+
+	case types.OrderStatusPartiallyFilled:
+		switch b.Status {
+		case types.OrderStatusNew:
+			return true
+		}
+
+	case types.OrderStatusFilled:
+		switch b.Status {
+		case types.OrderStatusFilled, types.OrderStatusPartiallyFilled, types.OrderStatusNew:
+			return true
+		}
+	}
+
+	au := time.Time(a.UpdateTime)
+	bu := time.Time(b.UpdateTime)
+
+	if !au.IsZero() && !bu.IsZero() && au.After(bu) {
+		return true
+	}
+
+	if !au.IsZero() && bu.IsZero() {
+		return true
+	}
+
+	return false
+}
+
 // add the order to the active order book and check the pending order
 func (b *ActiveOrderBook) add(order types.Order) {
 	if pendingOrder, ok := b.pendingOrderUpdates.Get(order.OrderID); ok {
 		// if the pending order update time is newer than the adding order
 		// we should use the pending order rather than the adding order.
 		// if pending order is older, than we should add the new one, and drop the pending order
-		if pendingOrder.UpdateTime.Time().After(order.UpdateTime.Time()) {
+		if isNewerUpdate(pendingOrder, order) {
 			order = pendingOrder
 		}
 

pkg/bbgo/activeorderbook_test.go

@@ -59,7 +59,7 @@ func TestActiveOrderBook_pendingOrders(t *testing.T) {
 		},
 		Status:       types.OrderStatusNew,
 		CreationTime: types.Time(now),
-		UpdateTime:   types.Time(now.Add(-time.Second)),
+		UpdateTime:   types.Time(now),
 	})
 
 	assert.True(t, filled, "filled event should be fired")

pkg/exchange/max/convert.go

@@ -67,7 +67,9 @@ func toGlobalRewards(maxRewards []max.Reward) ([]types.Reward, error) {
 	return rewards, nil
 }
 
-func toGlobalOrderStatus(orderState max.OrderState, executedVolume, remainingVolume fixedpoint.Value) types.OrderStatus {
+func toGlobalOrderStatus(
+	orderState max.OrderState, executedVolume, remainingVolume fixedpoint.Value,
+) types.OrderStatus {
 	switch orderState {
 
 	case max.OrderStateCancel:
@@ -328,6 +330,6 @@ func convertWebSocketOrderUpdate(u max.OrderUpdate) (*types.Order, error) {
 		Status:           toGlobalOrderStatus(u.State, u.ExecutedVolume, u.RemainingVolume),
 		ExecutedQuantity: u.ExecutedVolume,
 		CreationTime:     types.Time(time.Unix(0, u.CreatedAtMs*int64(time.Millisecond))),
-		UpdateTime:       types.Time(time.Unix(0, u.CreatedAtMs*int64(time.Millisecond))),
+		UpdateTime:       types.Time(time.Unix(0, u.UpdateTime*int64(time.Millisecond))),
 	}, nil
 }

pkg/types/order.go

@@ -320,9 +320,8 @@ func (o Order) String() string {
 		orderID = strconv.FormatUint(o.OrderID, 10)
 	}
 
-	desc := fmt.Sprintf("ORDER %s | %s | %s | %s | %s %-4s | %s/%s @ %s",
+	desc := fmt.Sprintf("ORDER %s | %s | %s | %s %-4s | %s/%s @ %s",
 		o.Exchange.String(),
-		o.CreationTime.Time().Local().Format(time.StampMilli),
 		orderID,
 		o.Symbol,
 		o.Type,
@@ -335,7 +334,17 @@ func (o Order) String() string {
 		desc += " Stop @ " + o.StopPrice.String()
 	}
 
-	return desc + " | " + string(o.Status)
+	desc += " | " + string(o.Status) + " | "
+
+	desc += time.Time(o.CreationTime).UTC().Format(time.StampMilli)
+
+	if time.Time(o.UpdateTime).IsZero() {
+		desc += " -> 0"
+	} else {
+		desc += " -> " + time.Time(o.UpdateTime).UTC().Format(time.StampMilli)
+	}
+
+	return desc
 }
 
 // PlainText is used for telegram-styled messages