Event log

client/mm/event_log.go

@@ -0,0 +1,186 @@
+package mm
+
+import (
+	"sync"
+	"time"
+
+	"decred.org/dcrdex/client/asset"
+	"decred.org/dcrdex/client/core"
+	"decred.org/dcrdex/dex"
+	"decred.org/dcrdex/dex/calc"
+)
+
+const (
+	eventTypeOrdersPlaced    = "OrdersPlaced"
+	eventTypeOrdersCancelled = "OrdersCanceled"
+	eventTypeMatch           = "Match"
+	eventTypeFeesConfirmed   = "FeesConfirmed"
+)
+
+type Event struct {
+	Type        string      `json:"type"`
+	TimeStamp   int64       `json:"timeStamp"`
+	OrderIDs    []dex.Bytes `json:"orderIDs"`
+	MatchIDs    []dex.Bytes `json:"matchIDs"`
+	FundingTxID dex.Bytes   `json:"fundingTxID"`
+	BaseDelta   int64       `json:"baseDelta"`
+	QuoteDelta  int64       `json:"quoteDelta"`
+	BaseFees    uint64      `json:"baseFees"`
+	QuoteFees   uint64      `json:"quoteFees"`
+}
+
+type EventLog struct {
+	mtx                    sync.Mutex
+	events                 []Event
+	startTime              int64
+	endTime                int64
+	changeInBaseInventory  int64
+	changeInQuoteInventory int64
+	totalBaseFees          uint64
+	totalQuoteFees         uint64
+	baseFiatRate           float64
+	quoteFiatRate          float64
+
+	host          string
+	baseID        uint32
+	quoteID       uint32
+	baseUnitInfo  dex.UnitInfo
+	quoteUnitInfo dex.UnitInfo
+}
+
+func (el *EventLog) logOrdersPlaced(orderIDs []dex.Bytes, fundingTx *core.FundingTx, sell bool) {
+	el.mtx.Lock()
+	defer el.mtx.Unlock()
+
+	var baseFees, quoteFees uint64
+	if sell {
+		baseFees += fundingTx.Fees
+		el.totalBaseFees += fundingTx.Fees
+	} else {
+		quoteFees += fundingTx.Fees
+		el.totalQuoteFees += fundingTx.Fees
+	}
+
+	el.events = append(el.events, Event{
+		Type:        eventTypeOrdersPlaced,
+		TimeStamp:   time.Now().UnixNano(),
+		OrderIDs:    orderIDs,
+		FundingTxID: fundingTx.ID,
+		BaseDelta:   0,
+		QuoteDelta:  0,
+		BaseFees:    baseFees,
+		QuoteFees:   quoteFees,
+	})
+}
+
+func (el *EventLog) logOrdersCanceled(orderIDs []dex.Bytes) {
+	el.events = append(el.events, Event{
+		Type:      eventTypeOrdersCancelled,
+		TimeStamp: time.Now().UnixNano(),
+		OrderIDs:  orderIDs,
+	})
+}
+
+func (el *EventLog) logMatch(orderID dex.Bytes, matchID dex.Bytes, sell bool, qty, rate uint64) {
+	el.mtx.Lock()
+	defer el.mtx.Unlock()
+
+	var baseDelta, quoteDelta int64
+	if sell {
+		baseDelta -= int64(qty)
+		quoteDelta += int64(calc.BaseToQuote(rate, qty))
+	} else {
+		baseDelta += int64(qty)
+		quoteDelta -= int64(calc.BaseToQuote(rate, qty))
+	}
+
+	el.changeInBaseInventory += baseDelta
+	el.changeInQuoteInventory += quoteDelta
+
+	el.events = append(el.events, Event{
+		Type:       eventTypeMatch,
+		TimeStamp:  time.Now().UnixNano(),
+		OrderIDs:   []dex.Bytes{orderID},
+		MatchIDs:   []dex.Bytes{matchID},
+		BaseDelta:  baseDelta,
+		QuoteDelta: quoteDelta,
+	})
+}
+
+func (el *EventLog) logFeesConfirmed(orderID dex.Bytes, swapFees, redeemFees uint64, sell bool) {
+	var baseFees, quoteFees uint64
+	if sell {
+		baseFees = swapFees
+		quoteFees = redeemFees
+	} else {
+		baseFees = redeemFees
+		quoteFees = swapFees
+	}
+
+	el.events = append(el.events, Event{
+		Type:      eventTypeFeesConfirmed,
+		TimeStamp: time.Now().UnixNano(),
+		OrderIDs:  []dex.Bytes{orderID},
+		BaseFees:  baseFees,
+		QuoteFees: quoteFees,
+	})
+}
+
+func (el *EventLog) updateFiatRates(base float64, quote float64) {
+	el.baseFiatRate = base
+	el.quoteFiatRate = quote
+}
+
+type eventsStats struct {
+	BaseChange   int64   `json:"baseChange"`
+	QuoteChange  int64   `json:"quoteChange"`
+	BaseFees     uint64  `json:"baseFees"`
+	QuoteFees    uint64  `json:"quoteFees"`
+	FiatGainLoss float64 `json:"fiatGainLossWithFees"`
+}
+
+func (el *EventLog) stats() *eventsStats {
+	el.mtx.Lock()
+	defer el.mtx.Unlock()
+
+	events := make([]Event, len(el.events))
+	copy(events, el.events)
+
+	baseConvFactor := float64(el.baseUnitInfo.Conventional.ConversionFactor)
+	quoteConvFactor := float64(el.quoteUnitInfo.Conventional.ConversionFactor)
+
+	changeInBaseConventional := float64(el.changeInBaseInventory-int64(el.totalBaseFees)) / baseConvFactor
+	changeInQuoteConventional := float64(el.changeInQuoteInventory-int64(el.totalQuoteFees)) / quoteConvFactor
+	changeInBaseFiat := changeInBaseConventional * el.baseFiatRate
+	changeInQuoteFiat := changeInQuoteConventional * el.quoteFiatRate
+	fiatGainLoss := changeInBaseFiat + changeInQuoteFiat
+
+	return &eventsStats{
+		BaseChange:   el.changeInBaseInventory,
+		QuoteChange:  el.changeInQuoteInventory,
+		BaseFees:     el.totalBaseFees,
+		QuoteFees:    el.totalQuoteFees,
+		FiatGainLoss: fiatGainLoss,
+	}
+}
+
+func newEventLog(host string, baseID, quoteID uint32) (*EventLog, error) {
+	baseUnitInfo, err := asset.UnitInfo(baseID)
+	if err != nil {
+		return nil, err
+	}
+
+	quoteUnitInfo, err := asset.UnitInfo(quoteID)
+	if err != nil {
+		return nil, err
+	}
+
+	return &EventLog{
+		baseUnitInfo:  baseUnitInfo,
+		quoteUnitInfo: quoteUnitInfo,
+		startTime:     time.Now().UnixNano(),
+		host:          host,
+		baseID:        baseID,
+		quoteID:       quoteID,
+	}, nil
+}

client/mm/mm.go

@@ -135,6 +135,7 @@ type orderInfo struct {
 	excessFeesReturned        bool
 	matchesSeen               map[order.MatchID]struct{}
 	matchesRefunded           map[order.MatchID]struct{}
+	matchesLogged             map[order.MatchID]struct{}
 }
 
 // finishedProcessing returns true when the MarketMaker no longer needs to
@@ -169,6 +170,9 @@ type MarketMaker struct {
 	syncedOracle   *priceOracle
 	unsyncedOracle *priceOracle
 
+	eventLogsMtx sync.RWMutex
+	eventLogs    map[string]*EventLog
+
 	runningBotsMtx sync.RWMutex
 	runningBots    map[string]interface{}
 
@@ -319,6 +323,33 @@ func (m *MarketMaker) MarketReport(base, quote uint32) (*MarketReport, error) {
 	}, nil
 }
 
+type RunStatus struct {
+	*eventsStats
+	BaseBalance  *botBalance `json:"baseBalance"`
+	QuoteBalance *botBalance `json:"quoteBalance"`
+}
+
+func (m *MarketMaker) RunStats(host string, base, quote uint32) (*RunStatus, error) {
+	m.eventLogsMtx.RLock()
+	defer m.eventLogsMtx.RUnlock()
+
+	mktID := dexMarketID(host, base, quote)
+	eventLog, found := m.eventLogs[mktID]
+	if !found {
+		return nil, fmt.Errorf("no event log for %s", mktID)
+	}
+
+	eventsStats := eventLog.stats()
+	baseBalance := m.botBalance(mktID, base)
+	quoteBalance := m.botBalance(mktID, quote)
+
+	return &RunStatus{
+		eventsStats,
+		&baseBalance,
+		&quoteBalance,
+	}, nil
+}
+
 func (m *MarketMaker) loginAndUnlockWallets(pw []byte, cfgs []*BotConfig) error {
 	err := m.core.Login(pw)
 	if err != nil {
@@ -362,6 +393,75 @@ func validateAndFilterEnabledConfigs(cfgs []*BotConfig) ([]*BotConfig, error) {
 	return enabledCfgs, nil
 }
 
+func (m *MarketMaker) setupEventLogs(cfgs []*BotConfig) error {
+	m.eventLogsMtx.Lock()
+	defer m.eventLogsMtx.Unlock()
+
+	m.eventLogs = make(map[string]*EventLog, len(cfgs))
+	for _, cfg := range cfgs {
+		log, err := newEventLog(cfg.Host, cfg.BaseAsset, cfg.QuoteAsset)
+		if err != nil {
+			return fmt.Errorf("failed to create event log for market %s-%d-%d: %w",
+				cfg.Host, cfg.BaseAsset, cfg.QuoteAsset, err)
+		}
+		m.eventLogs[dexMarketID(cfg.Host, cfg.BaseAsset, cfg.QuoteAsset)] = log
+	}
+
+	return nil
+}
+
+func (m *MarketMaker) logOrdersPlaced(botID string, orderIDs []dex.Bytes, fundingTx *core.FundingTx, sell bool) {
+	m.eventLogsMtx.RLock()
+	defer m.eventLogsMtx.RUnlock()
+
+	log, ok := m.eventLogs[botID]
+	if !ok {
+		m.log.Errorf("logOrdersPlaced: event log not found for bot %s", botID)
+		return
+	}
+
+	log.logOrdersPlaced(orderIDs, fundingTx, sell)
+}
+
+func (m *MarketMaker) logOrdersCanceled(botID string, orderIDs []dex.Bytes) {
+	m.eventLogsMtx.RLock()
+	defer m.eventLogsMtx.RUnlock()
+
+	log, ok := m.eventLogs[botID]
+	if !ok {
+		m.log.Errorf("logOrdersCanceled: event log not found for bot %s", botID)
+		return
+	}
+
+	log.logOrdersCanceled(orderIDs)
+}
+
+func (m *MarketMaker) logMatch(botID string, orderID dex.Bytes, matchID dex.Bytes, sell bool, qty, rate uint64) {
+	m.eventLogsMtx.RLock()
+	defer m.eventLogsMtx.RUnlock()
+
+	log, ok := m.eventLogs[botID]
+	if !ok {
+		m.log.Errorf("logMatch: event log not found for bot %s", botID)
+		return
+	}
+
+	log.logMatch(orderID, matchID, sell, qty, rate)
+}
+
+func (m *MarketMaker) logFeesConfirmed(botID string, orderID dex.Bytes, swapFees, redeemFees uint64, sell bool) {
+	m.eventLogsMtx.RLock()
+	defer m.eventLogsMtx.RUnlock()
+
+	log, ok := m.eventLogs[botID]
+	if !ok {
+		m.log.Errorf("logOrder: event log not found for bot %s", botID)
+		return
+	}
+
+	log.logFeesConfirmed(orderID, swapFees, redeemFees, sell)
+}
+
 func (m *MarketMaker) setupBalances(cfgs []*BotConfig) error {
 	m.botBalances = make(map[string]*botBalances, len(cfgs))
 
@@ -542,22 +642,27 @@ func (m *MarketMaker) modifyBotBalance(botID string, mods []*balanceMod) {
 }
 
 // botBalance returns a bot's balance of an asset.
-func (m *MarketMaker) botBalance(botID string, assetID uint32) uint64 {
+func (m *MarketMaker) botBalance(botID string, assetID uint32) botBalance {
 	bb := m.botBalances[botID]
 	if bb == nil {
 		m.log.Errorf("balance: bot %s not found", botID)
-		return 0
+		return botBalance{}
 	}
 
 	bb.mtx.RLock()
 	defer bb.mtx.RUnlock()
 
-	if _, found := bb.balances[assetID]; found {
-		return bb.balances[assetID].Available
+	balance, found := bb.balances[assetID]
+	if found {
+		return *balance
 	}
 
 	m.log.Errorf("balance: asset %d not found for bot %s", assetID, botID)
-	return 0
+	return botBalance{}
+}
+
+func (m *MarketMaker) botAvailableBalance(botID string, assetID uint32) uint64 {
+	return m.botBalance(botID, assetID).Available
 }
 
 func (m *MarketMaker) getOrderInfo(id dex.Bytes) *orderInfo {
@@ -595,6 +700,8 @@ func (m *MarketMaker) handleMatchUpdate(match *core.Match, oid dex.Bytes) {
 	if _, seen := orderInfo.matchesSeen[matchID]; !seen {
 		orderInfo.matchesSeen[matchID] = struct{}{}
 
+		m.logMatch(orderInfo.bot, oid, matchID[:], orderInfo.order.Sell, match.Qty, match.Rate)
+
 		var maxRedeemFees uint64
 		if orderInfo.initialRedeemFeesLocked == 0 {
 			numLots := match.Qty / orderInfo.lotSize
@@ -795,6 +902,7 @@ func (m *MarketMaker) handleOrderUpdate(o *core.Order) {
 			}
 		}
 
+		m.logFeesConfirmed(orderInfo.bot, o.ID, o.FeesPaid.Swap, o.FeesPaid.Redemption, o.Sell)
 		orderInfo.excessFeesReturned = true
 	}
 
@@ -847,6 +955,10 @@ func (m *MarketMaker) Run(ctx context.Context, cfgs []*BotConfig, pw []byte) err
 		return err
 	}
 
+	if err := m.setupEventLogs(enabledCfgs); err != nil {
+		return err
+	}
+
 	user := m.core.User()
 
 	startedMarketMaking = true

client/mm/mm_basic.go

@@ -414,6 +414,7 @@ func (m *basicMarketMaker) placeMultiTrade(placements []*rateLots, sell bool) {
 		m.ords[oid] = ord
 	}
 	m.ordMtx.Unlock()
+
 }
 
 func (m *basicMarketMaker) processFiatRates(rates map[uint32]float64) {
@@ -503,6 +504,7 @@ func (m *basicMarketMaker) rebalance(newEpoch uint64) {
 	if len(buyOrders) > 0 {
 		m.placeMultiTrade(buyOrders, false)
 	}
+
 	if len(sellOrders) > 0 {
 		m.placeMultiTrade(sellOrders, true)
 	}