IMPROVE: [xmaker] add more stability improvements and refactoring

pkg/bbgo/scale.go

@@ -295,7 +295,7 @@ func (rule *SlideRule) Scale() (Scale, error) {
 		return rule.QuadraticScale, nil
 	}
 
-	return nil, errors.New("no any scale is defined")
+	return nil, fmt.Errorf("no any scale is defined, avaiable scales: log, exp, linear, quadratic")
 }
 
 // LayerScale defines the scale DSL for maker layers, e.g.,

pkg/exchange/batch/time_range_query.go

@@ -9,7 +9,7 @@ import (
 	"github.com/sirupsen/logrus"
 	"golang.org/x/time/rate"
 
-	"github.com/c9s/bbgo/pkg/util"
+	"github.com/c9s/bbgo/pkg/profile/timeprofile"
 )
 
 var log = logrus.WithField("component", "batch")
@@ -56,7 +56,7 @@ func (q *AsyncTimeRangedBatchQuery) Query(ctx context.Context, ch interface{}, s
 
 			log.Debugf("batch querying %T: %v <=> %v", q.Type, startTime, endTime)
 
-			queryProfiler := util.StartTimeProfile("remoteQuery")
+			queryProfiler := timeprofile.Start("remoteQuery")
 
 			sliceInf, err := q.Q(startTime, endTime)
 			if err != nil {

pkg/util/profile.go → pkg/profile/timeprofile/timeprofile.go

@@ -1,34 +1,43 @@
-package util
+package timeprofile
 
 import (
 	"time"
 )
 
+type logFunction func(format string, args ...interface{})
+
 type TimeProfile struct {
 	Name               string
 	StartTime, EndTime time.Time
 	Duration           time.Duration
 }
 
-func StartTimeProfile(args ...string) TimeProfile {
+func Start(args ...string) TimeProfile {
 	name := ""
 	if len(args) > 0 {
 		name = args[0]
 	}
+
 	return TimeProfile{StartTime: time.Now(), Name: name}
 }
 
+// TilNow returns the duration from the start time to now
 func (p *TimeProfile) TilNow() time.Duration {
 	return time.Since(p.StartTime)
 }
 
+// Stop stops the time profile, set the end time and returns the duration
 func (p *TimeProfile) Stop() time.Duration {
 	p.EndTime = time.Now()
 	p.Duration = p.EndTime.Sub(p.StartTime)
 	return p.Duration
 }
 
-type logFunction func(format string, args ...interface{})
+// Do runs the function f and stops the time profile
+func (p *TimeProfile) Do(f func()) {
+	defer p.Stop()
+	f()
+}
 
 func (p *TimeProfile) StopAndLog(f logFunction) {
 	duration := p.Stop()

pkg/strategy/tri/strategy.go

@@ -18,10 +18,10 @@ import (
 	"github.com/c9s/bbgo/pkg/core"
 	"github.com/c9s/bbgo/pkg/exchange/retry"
 	"github.com/c9s/bbgo/pkg/fixedpoint"
+	"github.com/c9s/bbgo/pkg/profile/timeprofile"
 	"github.com/c9s/bbgo/pkg/sigchan"
 	"github.com/c9s/bbgo/pkg/style"
 	"github.com/c9s/bbgo/pkg/types"
-	"github.com/c9s/bbgo/pkg/util"
 )
 
 //go:generate bash symbols.sh
@@ -675,7 +675,7 @@ func (s *Strategy) iocOrderExecution(
 }
 
 func (s *Strategy) waitWebSocketOrderDone(ctx context.Context, orderID uint64, timeoutDuration time.Duration) (*types.Order, error) {
-	prof := util.StartTimeProfile("waitWebSocketOrderDone")
+	prof := timeprofile.Start("waitWebSocketOrderDone")
 	defer prof.StopAndLog(log.Infof)
 
 	if order, ok := s.orderStore.Get(orderID); ok {
@@ -869,7 +869,7 @@ func (s *Strategy) calculateRanks(minRatio float64, method func(p *Path) float64
 func waitForOrderFilled(
 	ctx context.Context, ex types.ExchangeOrderQueryService, order types.Order, timeout time.Duration,
 ) (*types.Order, error) {
-	prof := util.StartTimeProfile("waitForOrderFilled")
+	prof := timeprofile.Start("waitForOrderFilled")
 	defer prof.StopAndLog(log.Infof)
 
 	timeoutC := time.After(timeout)
@@ -880,7 +880,7 @@ func waitForOrderFilled(
 			return nil, fmt.Errorf("order wait timeout %s", timeout)
 
 		default:
-			p := util.StartTimeProfile("queryOrder")
+			p := timeprofile.Start("queryOrder")
 			remoteOrder, err2 := ex.QueryOrder(ctx, types.OrderQuery{
 				Symbol:  order.Symbol,
 				OrderID: strconv.FormatUint(order.OrderID, 10),

pkg/strategy/xmaker/metrics.go

@@ -2,6 +2,18 @@ package xmaker
 
 import "github.com/prometheus/client_golang/prometheus"
 
+var cancelOrderDurationMetrics = prometheus.NewHistogramVec(
+	prometheus.HistogramOpts{
+		Name: "xmaker_cancel_order_duration_milliseconds",
+		Help: "cancel order duration in milliseconds",
+	}, []string{"strategy_type", "strategy_id", "exchange", "symbol"})
+
+var makerOrderPlacementDurationMetrics = prometheus.NewHistogramVec(
+	prometheus.HistogramOpts{
+		Name: "xmaker_maker_order_placement_duration_milliseconds",
+		Help: "maker order placement duration in milliseconds",
+	}, []string{"strategy_type", "strategy_id", "exchange", "symbol"})
+
 var openOrderBidExposureInUsdMetrics = prometheus.NewGaugeVec(
 	prometheus.GaugeOpts{
 		Name: "xmaker_open_order_bid_exposure_in_usd",
@@ -77,6 +89,8 @@ func init() {
 		bidMarginMetrics,
 		askMarginMetrics,
 		aggregatedSignalMetrics,
+		cancelOrderDurationMetrics,
+		makerOrderPlacementDurationMetrics,
 		configNumOfLayersMetrics,
 		configMaxExposureMetrics,
 		configBidMarginMetrics,

pkg/strategy/xmaker/signal_book.go

@@ -21,6 +21,10 @@ func init() {
 	prometheus.MustRegister(orderBookSignalMetrics)
 }
 
+type StreamBookSetter interface {
+	SetStreamBook(book *types.StreamOrderBook)
+}
+
 type OrderBookBestPriceVolumeSignal struct {
 	RatioThreshold fixedpoint.Value `json:"ratioThreshold"`
 	MinVolume      fixedpoint.Value `json:"minVolume"`
@@ -29,7 +33,7 @@ type OrderBookBestPriceVolumeSignal struct {
 	book   *types.StreamOrderBook
 }
 
-func (s *OrderBookBestPriceVolumeSignal) BindStreamBook(book *types.StreamOrderBook) {
+func (s *OrderBookBestPriceVolumeSignal) SetStreamBook(book *types.StreamOrderBook) {
 	s.book = book
 }
 
@@ -65,7 +69,13 @@ func (s *OrderBookBestPriceVolumeSignal) CalculateSignal(ctx context.Context) (f
 		signal = -numerator.Div(denominator).Float64()
 	}
 
-	log.Infof("[OrderBookBestPriceVolumeSignal] %f bid/ask = %f/%f", signal, bid.Volume.Float64(), ask.Volume.Float64())
+	log.Infof("[OrderBookBestPriceVolumeSignal] %f bid/ask = %f/%f, bid ratio = %f, ratio threshold = %f",
+		signal,
+		bid.Volume.Float64(),
+		ask.Volume.Float64(),
+		bidRatio.Float64(),
+		s.RatioThreshold.Float64(),
+	)
 
 	orderBookSignalMetrics.WithLabelValues(s.symbol).Set(signal)
 	return signal, nil

pkg/strategy/xmaker/signal_depth.go

@@ -31,7 +31,7 @@ type DepthRatioSignal struct {
 	book   *types.StreamOrderBook
 }
 
-func (s *DepthRatioSignal) BindStreamBook(book *types.StreamOrderBook) {
+func (s *DepthRatioSignal) SetStreamBook(book *types.StreamOrderBook) {
 	s.book = book
 }