From c341d6405cdade1f7559187ccb1af6e3575f5b43 Mon Sep 17 00:00:00 2001 From: Debnil Sur Date: Sat, 17 Oct 2020 02:56:26 -0700 Subject: [PATCH] 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 | 4 +- support/metrics/metricsTracker.go | 50 ++++++++++++------- trader/trader.go | 35 ++++++++++--- trader/trader_test.go | 82 +++++++++++++++++++++++++++++++ 4 files changed, 144 insertions(+), 27 deletions(-) diff --git a/cmd/trade.go b/cmd/trade.go index 470f067e2..48ecdced1 100644 --- a/cmd/trade.go +++ b/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 --- diff --git a/support/metrics/metricsTracker.go b/support/metrics/metricsTracker.go index 04f5738c8..5ebd4d48d 100644 --- a/support/metrics/metricsTracker.go +++ b/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, diff --git a/trader/trader.go b/trader/trader.go index 35221064f..41192fe7d 100644 --- a/trader/trader.go +++ b/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 := "" diff --git a/trader/trader_test.go b/trader/trader_test.go index fcb682ac1..4db24afbe 100644 --- a/trader/trader_test.go +++ b/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) + }) + } +}