Send update metric at certain intervals (closes #516) (#536)

* Initial commit

* Address review - inject start time, add border tests

* Rename startTime, fix boundary condition.

* Add lastMetricUpdateTime to struct.

* Fix delete start time.

* Fix exporting.

* Remove debug.

* Change update time pattern.

cmd/trade.go

@@ -384,6 +384,7 @@ func makeBot(
 	threadTracker *multithreading.ThreadTracker,
 	options inputs,
 	metricsTracker *metrics.MetricsTracker,
+	botStart time.Time,
 ) *trader.Trader {
 	timeController := plugins.MakeIntervalTimeController(
 		time.Duration(botConfig.TickIntervalSeconds)*time.Second,
@@ -485,6 +486,7 @@ func makeBot(
 		dataKey,
 		alert,
 		metricsTracker,
+		botStart,
 	)
 }
 
@@ -518,7 +520,6 @@ func runTradeCmd(options inputs) {
 		guiVersionFlag = guiVersion
 	}
 
-
 	deviceID, e := machineid.ID()
 	if e != nil {
 		logger.Fatal(l, fmt.Errorf("could not generate machine id: %s", e))
@@ -699,6 +700,7 @@ func runTradeCmd(options inputs) {
 		threadTracker,
 		options,
 		metricsTracker,
+		botStart,
 	)
 	// --- end initialization of objects ---
 	// --- start initialization of services ---

support/metrics/metricsTracker.go

@@ -24,13 +24,14 @@ const (
 // and can be used to directly send events to the
 // Amplitude HTTP API.
 type MetricsTracker struct {
-	client     *http.Client
-	apiKey     string
-	userID     string
-	deviceID   string
-	props      commonProps
-	start      time.Time
-	isDisabled bool
+	client              *http.Client
+	apiKey              string
+	userID              string
+	deviceID            string
+	props               commonProps
+	botStartTime        time.Time
+	isDisabled          bool
+	updateEventSentTime time.Time
 }
 
 // TODO DS Investigate other fields to add to this top-level event.
@@ -109,7 +110,7 @@ func MakeMetricsTracker(
 	deviceID string,
 	apiKey string,
 	client *http.Client,
-	start time.Time,
+	botStartTime time.Time,
 	version string,
 	goos string,
 	goarch string,
@@ -136,16 +137,21 @@ func MakeMetricsTracker(
 	}
 
 	return &MetricsTracker{
-		client:     client,
-		apiKey:     apiKey,
-		userID:     userID,
-		deviceID:   deviceID,
-		props:      props,
-		start:      start,
-		isDisabled: isDisabled,
+		client:       client,
+		apiKey:       apiKey,
+		userID:       userID,
+		deviceID:     deviceID,
+		props:        props,
+		botStartTime: botStartTime,
+		isDisabled:   isDisabled,
 	}, nil
 }
 
+// GetUpdateEventSentTime gets the last sent time of the update event.
+func (mt *MetricsTracker) GetUpdateEventSentTime() time.Time {
+	return mt.updateEventSentTime
+}
+
 // SendStartupEvent sends the startup Amplitude event.
 func (mt *MetricsTracker) SendStartupEvent() error {
 	return mt.sendEvent(startupEventName, mt.props)
@@ -154,19 +160,25 @@ func (mt *MetricsTracker) SendStartupEvent() error {
 // SendUpdateEvent sends the update Amplitude event.
 func (mt *MetricsTracker) SendUpdateEvent(now time.Time, success bool, millisForUpdate int64) error {
 	commonProps := mt.props
-	commonProps.SecondsSinceStart = now.Sub(mt.start).Seconds()
+	commonProps.SecondsSinceStart = now.Sub(mt.botStartTime).Seconds()
 	updateProps := updateProps{
 		commonProps:     commonProps,
 		Success:         success,
 		MillisForUpdate: millisForUpdate,
 	}
-	return mt.sendEvent(updateEventName, updateProps)
+	e := mt.sendEvent(updateEventName, updateProps)
+	if e != nil {
+		return fmt.Errorf("could not send update event: %s", e)
+	}
+
+	mt.updateEventSentTime = now
+	return nil
 }
 
 // SendDeleteEvent sends the delete Amplitude event.
 func (mt *MetricsTracker) SendDeleteEvent(exit bool) error {
 	commonProps := mt.props
-	commonProps.SecondsSinceStart = time.Now().Sub(mt.start).Seconds()
+	commonProps.SecondsSinceStart = time.Now().Sub(mt.botStartTime).Seconds()
 	deleteProps := deleteProps{
 		commonProps: commonProps,
 		Exit:        exit,
@@ -188,7 +200,7 @@ func (mt *MetricsTracker) sendEvent(eventType string, eventProps interface{}) er
 		ApiKey: mt.apiKey,
 		Events: []event{{
 			UserID:    mt.userID,
-			SessionID: mt.start.Unix() * 1000, // convert to millis based on docs
+			SessionID: mt.botStartTime.Unix() * 1000, // convert to millis based on docs
 			DeviceID:  mt.deviceID,
 			EventType: eventType,
 			Props:     eventProps,

trader/trader.go

@@ -46,6 +46,7 @@ type Trader struct {
 	dataKey                        *model.BotKey
 	alert                          api.Alert
 	metricsTracker                 *metrics.MetricsTracker
+	startTime                      time.Time
 
 	// initialized runtime vars
 	deleteCycles int64
@@ -83,6 +84,7 @@ func MakeTrader(
 	dataKey *model.BotKey,
 	alert api.Alert,
 	metricsTracker *metrics.MetricsTracker,
+	startTime time.Time,
 ) *Trader {
 	return &Trader{
 		api:                            api,
@@ -107,6 +109,7 @@ func MakeTrader(
 		dataKey:                        dataKey,
 		alert:                          alert,
 		metricsTracker:                 metricsTracker,
+		startTime:                      startTime,
 		// initialized runtime vars
 		deleteCycles: 0,
 	}
@@ -121,15 +124,17 @@ func (t *Trader) Start() {
 		currentUpdateTime := time.Now()
 		if lastUpdateTime.IsZero() || t.timeController.ShouldUpdate(lastUpdateTime, currentUpdateTime) {
 			success := t.update()
-			millisForUpdate := time.Since(currentUpdateTime).Milliseconds()
-			e := t.threadTracker.TriggerGoroutine(func(inputs []interface{}) {
-				e := t.metricsTracker.SendUpdateEvent(currentUpdateTime, success, millisForUpdate)
+			if shouldSendUpdateMetric(t.startTime, currentUpdateTime, t.metricsTracker.GetUpdateEventSentTime()) {
+				millisForUpdate := time.Since(currentUpdateTime).Milliseconds()
+				e := t.threadTracker.TriggerGoroutine(func(inputs []interface{}) {
+					e := t.metricsTracker.SendUpdateEvent(currentUpdateTime, success, millisForUpdate)
+					if e != nil {
+						log.Printf("failed to send update event metric: %s", e)
+					}
+				}, nil)
 				if e != nil {
-					log.Printf("failed to send update event metric: %s", e)
+					log.Printf("failed to trigger goroutine for send update event: %s", e)
 				}
-			}, nil)
-			if e != nil {
-				log.Printf("failed to trigger goroutine for send update event: %s", e)
 			}
 
 			if t.fixedIterations != nil && success {
@@ -154,6 +159,22 @@ func (t *Trader) Start() {
 	}
 }
 
+func shouldSendUpdateMetric(start, currentUpdate, lastMetricUpdate time.Time) bool {
+	timeFromStart := currentUpdate.Sub(start)
+	var refreshMetricInterval time.Duration
+	switch {
+	case timeFromStart <= 5*time.Minute:
+		refreshMetricInterval = 5 * time.Second
+	case timeFromStart <= 1*time.Hour:
+		refreshMetricInterval = 10 * time.Minute
+	default:
+		refreshMetricInterval = 1 * time.Hour
+	}
+
+	timeSinceLastUpdate := currentUpdate.Sub(lastMetricUpdate)
+	return timeSinceLastUpdate >= refreshMetricInterval
+}
+
 // deletes all offers for the bot (not all offers on the account)
 func (t *Trader) deleteAllOffers(isAsync bool) {
 	logPrefix := ""

trader/trader_test.go

@@ -2,6 +2,7 @@ package trader
 
 import (
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 
@@ -159,3 +160,84 @@ func TestIsStateSynchronized(t *testing.T) {
 		})
 	}
 }
+
+func TestShouldSendUpdateMetric(t *testing.T) {
+	now := time.Now()
+	testCases := []struct {
+		name                 string
+		start                time.Time
+		currentUpdate        time.Time
+		lastMetricUpdate     time.Time
+		wantShouldSendMetric bool
+	}{
+		{
+			name:                 "first 5 mins - border - refresh",
+			start:                now.Add(-5 * time.Minute),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-5 * time.Second),
+			wantShouldSendMetric: true,
+		},
+		{
+			name:                 "first 5 mins - greater than - refresh",
+			start:                now.Add(-5 * time.Minute),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-5*time.Second - time.Nanosecond),
+			wantShouldSendMetric: true,
+		},
+		{
+			name:                 "first 5 mins - less than - no refresh",
+			start:                now.Add(-5 * time.Minute),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-5*time.Second + time.Nanosecond),
+			wantShouldSendMetric: false,
+		},
+		{
+			name:                 "first hour - border - refresh",
+			start:                now.Add(-1 * time.Hour),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-10 * time.Minute),
+			wantShouldSendMetric: true,
+		},
+		{
+			name:                 "first hour - greater than - refresh",
+			start:                now.Add(-1 * time.Hour),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-10*time.Minute - time.Nanosecond),
+			wantShouldSendMetric: true,
+		},
+		{
+			name:                 "first hour - less than - no refresh",
+			start:                now.Add(-1 * time.Hour),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-10*time.Minute + time.Nanosecond),
+			wantShouldSendMetric: false,
+		},
+		{
+			name:                 "past first hour - border - refresh",
+			start:                now.Add(-2 * time.Hour),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-1 * time.Hour),
+			wantShouldSendMetric: true,
+		},
+		{
+			name:                 "past first hour - greater than - refresh",
+			start:                now.Add(-2 * time.Hour),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-1*time.Hour - time.Nanosecond),
+			wantShouldSendMetric: true,
+		},
+		{
+			name:                 "past first hour - less than - no refresh",
+			start:                now.Add(-2 * time.Hour),
+			currentUpdate:        now,
+			lastMetricUpdate:     now.Add(-1*time.Hour + time.Nanosecond),
+			wantShouldSendMetric: false,
+		},
+	}
+	for _, k := range testCases {
+		t.Run(k.name, func(t *testing.T) {
+			actual := shouldSendUpdateMetric(k.start, k.currentUpdate, k.lastMetricUpdate)
+			assert.Equal(t, k.wantShouldSendMetric, actual)
+		})
+	}
+}