backtest: fix order update_time update in the matching engine

fixes: #631

apps/backtest-report/components/TradingViewChart.js

@@ -160,7 +160,7 @@ const ordersToMarkets = (interval, orders) => {
       let endTime = (startTime + intervalSecs);
       // skip the marker in the same interval of the last marker
       if (t < endTime) {
-        continue
+        // continue
       }
     }
 

pkg/backtest/matching.go

@@ -7,6 +7,7 @@ import (
 	"time"
 
 	"github.com/pkg/errors"
+	"github.com/sirupsen/logrus"
 
 	"github.com/c9s/bbgo/pkg/fixedpoint"
 	"github.com/c9s/bbgo/pkg/types"
@@ -23,15 +24,18 @@ func incTradeID() uint64 {
 	return atomic.AddUint64(&tradeID, 1)
 }
 
+var klineMatchingLogger = logrus.WithField("backtest", "klineEngine")
+
 // SimplePriceMatching implements a simple kline data driven matching engine for backtest
 //go:generate callbackgen -type SimplePriceMatching
 type SimplePriceMatching struct {
 	Symbol string
 	Market types.Market
 
-	mu        sync.Mutex
+	mu           sync.Mutex
-	bidOrders []types.Order
+	bidOrders    []types.Order
-	askOrders []types.Order
+	askOrders    []types.Order
+	closedOrders []types.Order
 
 	LastPrice   fixedpoint.Value
 	LastKLine   types.KLine
@@ -118,11 +122,9 @@ func (m *SimplePriceMatching) PlaceOrder(o types.SubmitOrder) (closedOrders *typ
 		return nil, nil, fmt.Errorf("order quantity %s is less than minQuantity %s, order: %+v", o.Quantity.String(), m.Market.MinQuantity.String(), o)
 	}
 
-	if !price.IsZero() {
+	quoteQuantity := o.Quantity.Mul(price)
-		quoteQuantity := o.Quantity.Mul(price)
+	if quoteQuantity.Compare(m.Market.MinNotional) < 0 {
-		if quoteQuantity.Compare(m.Market.MinNotional) < 0 {
+		return nil, nil, fmt.Errorf("order amount %s is less than minNotional %s, order: %+v", quoteQuantity.String(), m.Market.MinNotional.String(), o)
-			return nil, nil, fmt.Errorf("order amount %s is less than minNotional %s, order: %+v", quoteQuantity.String(), m.Market.MinNotional.String(), o)
-		}
 	}
 
 	switch o.Side {
@@ -147,7 +149,7 @@ func (m *SimplePriceMatching) PlaceOrder(o types.SubmitOrder) (closedOrders *typ
 		m.EmitOrderUpdate(order)
 
 		// emit trade before we publish order
-		trade := m.newTradeFromOrder(order, false)
+		trade := m.newTradeFromOrder(&order, false)
 		m.executeTrade(trade)
 
 		// update the order status
@@ -184,11 +186,9 @@ func (m *SimplePriceMatching) executeTrade(trade types.Trade) {
 	// execute trade, update account balances
 	if trade.IsBuyer {
 		err = m.Account.UseLockedBalance(m.Market.QuoteCurrency, trade.Price.Mul(trade.Quantity))
-
 		m.Account.AddBalance(m.Market.BaseCurrency, trade.Quantity.Sub(trade.Fee.Div(trade.Price)))
 	} else {
 		err = m.Account.UseLockedBalance(m.Market.BaseCurrency, trade.Quantity)
-
 		m.Account.AddBalance(m.Market.QuoteCurrency, trade.Quantity.Mul(trade.Price).Sub(trade.Fee))
 	}
 
@@ -201,7 +201,7 @@ func (m *SimplePriceMatching) executeTrade(trade types.Trade) {
 	return
 }
 
-func (m *SimplePriceMatching) newTradeFromOrder(order types.Order, isMaker bool) types.Trade {
+func (m *SimplePriceMatching) newTradeFromOrder(order *types.Order, isMaker bool) types.Trade {
 	// BINANCE uses 0.1% for both maker and taker
 	// MAX uses 0.050% for maker and 0.15% for taker
 	var feeRate fixedpoint.Value
@@ -258,6 +258,8 @@ func (m *SimplePriceMatching) newTradeFromOrder(order types.Order, isMaker bool)
 }
 
 func (m *SimplePriceMatching) BuyToPrice(price fixedpoint.Value) (closedOrders []types.Order, trades []types.Trade) {
+	klineMatchingLogger.Debugf("kline buy to price %s", price.String())
+
 	var askOrders []types.Order
 
 	for _, o := range m.askOrders {
@@ -320,19 +322,24 @@ func (m *SimplePriceMatching) BuyToPrice(price fixedpoint.Value) (closedOrders [
 	m.askOrders = askOrders
 	m.LastPrice = price
 
-	for _, o := range closedOrders {
+	for i := range closedOrders {
-		trade := m.newTradeFromOrder(o, true)
+		o := closedOrders[i]
+		trade := m.newTradeFromOrder(&o, true)
 		m.executeTrade(trade)
+		closedOrders[i] = o
 
 		trades = append(trades, trade)
 
 		m.EmitOrderUpdate(o)
 	}
+	m.closedOrders = append(m.closedOrders, closedOrders...)
 
 	return closedOrders, trades
 }
 
 func (m *SimplePriceMatching) SellToPrice(price fixedpoint.Value) (closedOrders []types.Order, trades []types.Trade) {
+	klineMatchingLogger.Debugf("kline sell to price %s", price.String())
+
 	var sellPrice = price
 	var bidOrders []types.Order
 	for _, o := range m.bidOrders {
@@ -370,9 +377,6 @@ func (m *SimplePriceMatching) SellToPrice(price fixedpoint.Value) (closedOrders
 
 		case types.OrderTypeLimit, types.OrderTypeLimitMaker:
 			if sellPrice.Compare(o.Price) <= 0 {
-				if o.Price.Compare(m.LastKLine.High) > 0 {
-					o.Price = m.LastKLine.High
-				}
 				o.ExecutedQuantity = o.Quantity
 				o.Status = types.OrderStatusFilled
 				closedOrders = append(closedOrders, o)
@@ -388,14 +392,17 @@ func (m *SimplePriceMatching) SellToPrice(price fixedpoint.Value) (closedOrders
 	m.bidOrders = bidOrders
 	m.LastPrice = price
 
-	for _, o := range closedOrders {
+	for i := range closedOrders {
-		trade := m.newTradeFromOrder(o, true)
+		o := closedOrders[i]
+		trade := m.newTradeFromOrder(&o, true)
 		m.executeTrade(trade)
+		closedOrders[i] = o
 
 		trades = append(trades, trade)
 
 		m.EmitOrderUpdate(o)
 	}
+	m.closedOrders = append(m.closedOrders, closedOrders...)
 
 	return closedOrders, trades
 }
@@ -410,7 +417,8 @@ func (m *SimplePriceMatching) processKLine(kline types.KLine) {
 			m.BuyToPrice(kline.High)
 		}
 
-		if kline.Low.Compare(kline.Close) > 0 {
+		// if low is lower than close, sell to low first, and then buy up to close
+		if kline.Low.Compare(kline.Close) < 0 {
 			m.SellToPrice(kline.Low)
 			m.BuyToPrice(kline.Close)
 		} else {

pkg/backtest/matching_test.go

@@ -21,7 +21,69 @@ func newLimitOrder(symbol string, side types.SideType, price, quantity float64)
 	}
 }
 
-func TestSimplePriceMatching_LimitOrder(t *testing.T) {
+func TestSimplePriceMatching_processKLine(t *testing.T) {
+	account := &types.Account{
+		MakerFeeRate: fixedpoint.NewFromFloat(0.075 * 0.01),
+		TakerFeeRate: fixedpoint.NewFromFloat(0.075 * 0.01),
+	}
+	account.UpdateBalances(types.BalanceMap{
+		"USDT": {Currency: "USDT", Available: fixedpoint.NewFromFloat(10000.0)},
+	})
+	market := types.Market{
+		Symbol:          "BTCUSDT",
+		PricePrecision:  8,
+		VolumePrecision: 8,
+		QuoteCurrency:   "USDT",
+		BaseCurrency:    "BTC",
+		MinNotional:     fixedpoint.MustNewFromString("0.001"),
+		MinAmount:       fixedpoint.MustNewFromString("10.0"),
+		MinQuantity:     fixedpoint.MustNewFromString("0.001"),
+	}
+
+	t1 := time.Date(2021, 7, 1, 0, 0, 0, 0, time.UTC)
+	engine := &SimplePriceMatching{
+		Account:     account,
+		Market:      market,
+		CurrentTime: t1,
+	}
+
+	for i := 0; i <= 5; i++ {
+		var p = 20000.0 + float64(i)*1000.0
+		_, _, err := engine.PlaceOrder(newLimitOrder("BTCUSDT", types.SideTypeBuy, p, 0.001))
+		assert.NoError(t, err)
+	}
+
+	t2 := t1.Add(time.Minute)
+
+	// should match 25000, 24000
+	k := newKLine("BTCUSDT", types.Interval1m, t2, 26000, 27000, 23000, 25000)
+	assert.Equal(t, t2.Add(time.Minute-time.Millisecond), k.EndTime.Time())
+
+	engine.processKLine(k)
+	assert.Equal(t, 3, len(engine.bidOrders))
+	assert.Len(t, engine.bidOrders, 3)
+	assert.Equal(t, 3, len(engine.closedOrders))
+
+	for _, o := range engine.closedOrders {
+		assert.Equal(t, k.EndTime.Time(), o.UpdateTime.Time())
+	}
+}
+
+func newKLine(symbol string, interval types.Interval, startTime time.Time, o, h, l, c float64) types.KLine {
+	return types.KLine{
+		Symbol:    symbol,
+		StartTime: types.Time(startTime),
+		EndTime:   types.Time(startTime.Add(interval.Duration() - time.Millisecond)),
+		Interval:  interval,
+		Open:      fixedpoint.NewFromFloat(o),
+		High:      fixedpoint.NewFromFloat(h),
+		Low:       fixedpoint.NewFromFloat(l),
+		Close:     fixedpoint.NewFromFloat(c),
+		Closed:    true,
+	}
+}
+
+func TestSimplePriceMatching_PlaceLimitOrder(t *testing.T) {
 	account := &types.Account{
 		MakerFeeRate: fixedpoint.NewFromFloat(0.075 * 0.01),
 		TakerFeeRate: fixedpoint.NewFromFloat(0.075 * 0.01),
@@ -44,9 +106,8 @@ func TestSimplePriceMatching_LimitOrder(t *testing.T) {
 	}
 
 	engine := &SimplePriceMatching{
-		CurrentTime: time.Now(),
+		Account: account,
-		Account:     account,
+		Market:  market,
-		Market:      market,
 	}
 
 	for i := 0; i < 5; i++ {