Merge pull request #1450 from c9s/feature/xdepthmaker

IMPROVE: [strategy] xdepthmaker final fine-tune

pkg/bbgo/activeorderbook.go

@@ -3,7 +3,6 @@ package bbgo
 import (
 	"context"
 	"encoding/json"
-	"sort"
 	"sync"
 	"time"
 
@@ -14,7 +13,7 @@ import (
 	"github.com/c9s/bbgo/pkg/types"
 )
 
-const CancelOrderWaitTime = 20 * time.Millisecond
+const DefaultCancelOrderWaitTime = 20 * time.Millisecond
 
 // ActiveOrderBook manages the local active order books.
 //
@@ -34,6 +33,8 @@ type ActiveOrderBook struct {
 	C sigchan.Chan
 
 	mu sync.Mutex
+
+	cancelOrderWaitTime time.Duration
 }
 
 func NewActiveOrderBook(symbol string) *ActiveOrderBook {
@@ -42,9 +43,14 @@ func NewActiveOrderBook(symbol string) *ActiveOrderBook {
 		orders:              types.NewSyncOrderMap(),
 		pendingOrderUpdates: types.NewSyncOrderMap(),
 		C:                   sigchan.New(1),
+		cancelOrderWaitTime: DefaultCancelOrderWaitTime,
 	}
 }
 
+func (b *ActiveOrderBook) SetCancelOrderWaitTime(duration time.Duration) {
+	b.cancelOrderWaitTime = duration
+}
+
 func (b *ActiveOrderBook) MarshalJSON() ([]byte, error) {
 	orders := b.Backup()
 	return json.Marshal(orders)
@@ -156,10 +162,14 @@ func (b *ActiveOrderBook) FastCancel(ctx context.Context, ex types.Exchange, ord
 }
 
 // GracefulCancel cancels the active orders gracefully
-func (b *ActiveOrderBook) GracefulCancel(ctx context.Context, ex types.Exchange, orders ...types.Order) error {
+func (b *ActiveOrderBook) GracefulCancel(ctx context.Context, ex types.Exchange, specifiedOrders ...types.Order) error {
+	cancelAll := false
+	orders := specifiedOrders
+
 	// if no orders are given, set to cancelAll
-	if len(orders) == 0 {
+	if len(specifiedOrders) == 0 {
 		orders = b.Orders()
+		cancelAll = true
 	} else {
 		// simple check on given input
 		hasSymbol := b.Symbol != ""
@@ -169,13 +179,15 @@ func (b *ActiveOrderBook) GracefulCancel(ctx context.Context, ex types.Exchange,
 			}
 		}
 	}
+
 	// optimize order cancel for back-testing
 	if IsBackTesting {
 		return ex.CancelOrders(context.Background(), orders...)
 	}
 
 	log.Debugf("[ActiveOrderBook] gracefully cancelling %s orders...", b.Symbol)
-	waitTime := CancelOrderWaitTime
+	waitTime := b.cancelOrderWaitTime
+	orderCancelTimeout := 5 * time.Second
 
 	startTime := time.Now()
 	// ensure every order is canceled
@@ -192,23 +204,28 @@ func (b *ActiveOrderBook) GracefulCancel(ctx context.Context, ex types.Exchange,
 
 		log.Debugf("[ActiveOrderBook] waiting %s for %s orders to be cancelled...", waitTime, b.Symbol)
 
-		clear, err := b.waitAllClear(ctx, waitTime, 5*time.Second)
-		if clear || err != nil {
-			break
-		}
+		if cancelAll {
+			clear, err := b.waitAllClear(ctx, waitTime, orderCancelTimeout)
+			if clear || err != nil {
+				break
+			}
 
-		log.Warnf("[ActiveOrderBook] %d %s orders are not cancelled yet:", b.NumOfOrders(), b.Symbol)
-		b.Print()
+			log.Warnf("[ActiveOrderBook] %d %s orders are not cancelled yet:", b.NumOfOrders(), b.Symbol)
+			b.Print()
+
+		} else {
+			existingOrders := b.filterExistingOrders(orders)
+			if len(existingOrders) == 0 {
+				break
+			}
+		}
 
 		// verify the current open orders via the RESTful API
-		log.Warnf("[ActiveOrderBook] using REStful API to verify active orders...")
+		log.Warnf("[ActiveOrderBook] using open orders API to verify the active orders...")
 
-		var symbolOrdersMap = map[string]types.OrderSlice{}
-		for _, order := range orders {
-			symbolOrdersMap[order.Symbol] = append(symbolOrdersMap[order.Symbol], order)
-		}
+		var symbolOrdersMap = categorizeOrderBySymbol(orders)
 
-		var leftOrders []types.Order
+		var leftOrders types.OrderSlice
 		for symbol := range symbolOrdersMap {
 			symbolOrders, ok := symbolOrdersMap[symbol]
 			if !ok {
@@ -221,13 +238,14 @@ func (b *ActiveOrderBook) GracefulCancel(ctx context.Context, ex types.Exchange,
 				continue
 			}
 
-			orderMap := types.NewOrderMap(openOrders...)
+			openOrderMap := types.NewOrderMap(openOrders...)
 			for _, o := range symbolOrders {
-				// if it's not on the order book (open orders), we should remove it from our local side
-				if !orderMap.Exists(o.OrderID) {
+				// if it's not on the order book (open orders),
+				// we should remove it from our local side
+				if !openOrderMap.Exists(o.OrderID) {
 					b.Remove(o)
 				} else {
-					leftOrders = append(leftOrders, o)
+					leftOrders.Add(o)
 				}
 			}
 		}
@@ -246,17 +264,8 @@ func (b *ActiveOrderBook) orderUpdateHandler(order types.Order) {
 
 func (b *ActiveOrderBook) Print() {
 	orders := b.orders.Orders()
-
-	// sort orders by price
-	sort.Slice(orders, func(i, j int) bool {
-		o1 := orders[i]
-		o2 := orders[j]
-		return o1.Price.Compare(o2.Price) > 0
-	})
-
-	for _, o := range orders {
-		log.Infof("%s", o)
-	}
+	orders = types.SortOrdersByPrice(orders, true)
+	orders.Print()
 }
 
 // Update updates the order by the order status and emit the related events.
@@ -441,3 +450,23 @@ func (b *ActiveOrderBook) Orders() types.OrderSlice {
 func (b *ActiveOrderBook) Lookup(f func(o types.Order) bool) *types.Order {
 	return b.orders.Lookup(f)
 }
+
+func (b *ActiveOrderBook) filterExistingOrders(orders []types.Order) (existingOrders types.OrderSlice) {
+	for _, o := range orders {
+		if b.Exists(o) {
+			existingOrders.Add(o)
+		}
+	}
+
+	return existingOrders
+}
+
+func categorizeOrderBySymbol(orders types.OrderSlice) map[string]types.OrderSlice {
+	orderMap := map[string]types.OrderSlice{}
+
+	for _, order := range orders {
+		orderMap[order.Symbol] = append(orderMap[order.Symbol], order)
+	}
+
+	return orderMap
+}

pkg/bbgo/envvar.go

@@ -0,0 +1,48 @@
+package bbgo
+
+import (
+	"os"
+
+	log "github.com/sirupsen/logrus"
+	prefixed "github.com/x-cray/logrus-prefixed-formatter"
+)
+
+func GetCurrentEnv() string {
+	env := os.Getenv("BBGO_ENV")
+	if env == "" {
+		env = "development"
+	}
+
+	return env
+}
+
+func NewLogFormatterWithEnv(env string) log.Formatter {
+	switch env {
+	case "production", "prod", "stag", "staging":
+		// always use json formatter for production and staging
+		return &log.JSONFormatter{}
+	}
+
+	return &prefixed.TextFormatter{}
+}
+
+type LogFormatterType string
+
+const (
+	LogFormatterTypePrefixed LogFormatterType = "prefixed"
+	LogFormatterTypeText     LogFormatterType = "text"
+	LogFormatterTypeJson     LogFormatterType = "json"
+)
+
+func NewLogFormatter(logFormatter LogFormatterType) log.Formatter {
+	switch logFormatter {
+	case LogFormatterTypePrefixed:
+		return &prefixed.TextFormatter{}
+	case LogFormatterTypeText:
+		return &log.TextFormatter{}
+	case LogFormatterTypeJson:
+		return &log.JSONFormatter{}
+	}
+
+	return &prefixed.TextFormatter{}
+}

pkg/cmd/root.go

@@ -17,7 +17,6 @@ import (
 	log "github.com/sirupsen/logrus"
 	"github.com/spf13/cobra"
 	"github.com/spf13/viper"
-	prefixed "github.com/x-cray/logrus-prefixed-formatter"
 
 	"github.com/c9s/bbgo/pkg/bbgo"
 	"github.com/c9s/bbgo/pkg/util"
@@ -46,10 +45,7 @@ var RootCmd = &cobra.Command{
 			log.SetLevel(log.DebugLevel)
 		}
 
-		env := os.Getenv("BBGO_ENV")
-		if env == "" {
-			env = "development"
-		}
+		env := bbgo.GetCurrentEnv()
 
 		logFormatter, err := cmd.Flags().GetString("log-formatter")
 		if err != nil {
@@ -57,22 +53,11 @@ var RootCmd = &cobra.Command{
 		}
 
 		if len(logFormatter) == 0 {
-			switch env {
-			case "production", "prod", "stag", "staging":
-				// always use json formatter for production and staging
-				log.SetFormatter(&log.JSONFormatter{})
-			default:
-				log.SetFormatter(&prefixed.TextFormatter{})
-			}
+			formatter := bbgo.NewLogFormatterWithEnv(env)
+			log.SetFormatter(formatter)
 		} else {
-			switch logFormatter {
-			case "prefixed":
-				log.SetFormatter(&prefixed.TextFormatter{})
-			case "text":
-				log.SetFormatter(&log.TextFormatter{})
-			case "json":
-				log.SetFormatter(&log.JSONFormatter{})
-			}
+			formatter := bbgo.NewLogFormatter(bbgo.LogFormatterType(logFormatter))
+			log.SetFormatter(formatter)
 		}
 
 		if token := viper.GetString("rollbar-token"); token != "" {

pkg/exchange/bitget/exchange.go

@@ -64,14 +64,20 @@ var (
 	kLineRateLimiter = rate.NewLimiter(rate.Every(time.Second/10), 5)
 )
 
-var debugf func(msg string, args ...interface{})
+type LogFunction func(msg string, args ...interface{})
+
+var debugf LogFunction
+
+func getDebugFunction() LogFunction {
+	if v, ok := util.GetEnvVarBool("DEBUG_BITGET"); ok && v {
+		return log.Infof
+	}
+
+	return func(msg string, args ...interface{}) {}
+}
 
 func init() {
-	if v, ok := util.GetEnvVarBool("DEBUG_BITGET"); ok && v {
-		debugf = log.Infof
-	} else {
-		debugf = func(msg string, args ...interface{}) {}
-	}
+	debugf = getDebugFunction()
 }
 
 type Exchange struct {

pkg/types/ordermap.go

@@ -3,6 +3,8 @@ package types
 import (
 	"sync"
 	"time"
+
+	"github.com/sirupsen/logrus"
 )
 
 // OrderMap is used for storing orders by their order id
@@ -254,6 +256,15 @@ func (m *SyncOrderMap) Orders() (slice OrderSlice) {
 
 type OrderSlice []Order
 
+func (s *OrderSlice) Add(o Order) {
+	*s = append(*s, o)
+}
+
+// Map builds up an OrderMap by the order id
+func (s OrderSlice) Map() OrderMap {
+	return NewOrderMap(s...)
+}
+
 func (s OrderSlice) SeparateBySide() (buyOrders, sellOrders []Order) {
 	for _, o := range s {
 		switch o.Side {
@@ -266,3 +277,9 @@ func (s OrderSlice) SeparateBySide() (buyOrders, sellOrders []Order) {
 
 	return buyOrders, sellOrders
 }
+
+func (s OrderSlice) Print() {
+	for _, o := range s {
+		logrus.Infof("%s", o)
+	}
+}