fix: [WIN-NPM] fix units of new latency metrics (#2018)

* fix: new latency metrics use seconds instead of milliseconds

* chore: lint

* fix: lower buckets to start at 8 milliseconds

Author: huntergregory

npm/metrics/acls_windows.go

@@ -7,7 +7,7 @@ func RecordACLLatency(timer *Timer, op OperationKind) {
 	labels := prometheus.Labels{
 		operationLabel: string(op),
 	}
-	aclLatency.With(labels).Observe(timer.timeElapsed())
+	aclLatency.With(labels).Observe(timer.timeElapsedSeconds())
 }
 
 // IncACLFailures should be used in Windows DP to record the number of failures for individual ACL operations.

npm/metrics/endpoints_windows.go

@@ -1,15 +1,15 @@
 package metrics
 
 func RecordListEndpointsLatency(timer *Timer) {
-	listEndpointsLatency.Observe(timer.timeElapsed())
+	listEndpointsLatency.Observe(timer.timeElapsedSeconds())
 }
 
 func IncListEndpointsFailures() {
 	listEndpointsFailures.Inc()
 }
 
 func RecordGetEndpointLatency(timer *Timer) {
-	getEndpointLatency.Observe(timer.timeElapsed())
+	getEndpointLatency.Observe(timer.timeElapsedSeconds())
 }
 
 func IncGetEndpointFailures() {

npm/metrics/prometheus-metrics.go

@@ -202,7 +202,7 @@ func InitializeWindowsMetrics() {
 			Subsystem: windowsPrefix,
 			Help:      "Latency  in seconds to list HNS endpoints latency",
 			//nolint:gomnd // default bucket consts
-			Buckets: prometheus.ExponentialBuckets(0.016, 2, 14), // upper bounds of 16 ms to ~2 minutes
+			Buckets: prometheus.ExponentialBuckets(0.008, 2, 14), // upper bounds of 8 ms to 65 seconds
 		},
 	)
 
@@ -213,7 +213,7 @@ func InitializeWindowsMetrics() {
 			Subsystem: windowsPrefix,
 			Help:      "Latency in seconds to get a single HNS endpoint",
 			//nolint:gomnd // default bucket consts
-			Buckets: prometheus.ExponentialBuckets(0.016, 2, 14), // upper bounds of 16 ms to ~2 minutes
+			Buckets: prometheus.ExponentialBuckets(0.008, 2, 14), // upper bounds of 8 ms to 65 seconds
 		},
 	)
 
@@ -224,7 +224,7 @@ func InitializeWindowsMetrics() {
 			Subsystem: windowsPrefix,
 			Help:      "Latency in seconds to get the HNS network",
 			//nolint:gomnd // default bucket consts
-			Buckets: prometheus.ExponentialBuckets(0.016, 2, 14), // upper bounds of 16 ms to ~2 minutes
+			Buckets: prometheus.ExponentialBuckets(0.008, 2, 14), // upper bounds of 8 ms to 65 seconds
 		},
 	)
 
@@ -235,7 +235,7 @@ func InitializeWindowsMetrics() {
 			Subsystem: windowsPrefix,
 			Help:      "Latency in seconds to add/update ACLs by operation label",
 			//nolint:gomnd // default bucket consts
-			Buckets: prometheus.ExponentialBuckets(0.016, 2, 14), // upper bounds of 16 ms to ~2 minutes
+			Buckets: prometheus.ExponentialBuckets(0.008, 2, 14), // upper bounds of 8 ms to 65 seconds
 		},
 		[]string{operationLabel},
 	)
@@ -247,7 +247,7 @@ func InitializeWindowsMetrics() {
 			Subsystem: windowsPrefix,
 			Help:      "Latency in seconds to add/update/delete SetPolicies by operation & is_nested label",
 			//nolint:gomnd // default bucket consts
-			Buckets: prometheus.ExponentialBuckets(0.016, 2, 14), // upper bounds of 16 ms to ~2 minutes
+			Buckets: prometheus.ExponentialBuckets(0.008, 2, 14), // upper bounds of 8 ms to 65 seconds
 		},
 		[]string{operationLabel, isNestedLabel},
 	)

npm/metrics/setpolicies_windows.go

@@ -11,7 +11,7 @@ func RecordSetPolicyLatency(timer *Timer, op OperationKind, isNested bool) {
 		operationLabel: string(op),
 		isNestedLabel:  nested,
 	}
-	setPolicyLatency.With(labels).Observe(timer.timeElapsed())
+	setPolicyLatency.With(labels).Observe(timer.timeElapsedSeconds())
 }
 
 func IncSetPolicyFailures(op OperationKind, isNested bool) {
@@ -27,7 +27,7 @@ func IncSetPolicyFailures(op OperationKind, isNested bool) {
 }
 
 func RecordGetNetworkLatency(timer *Timer) {
-	getNetworkLatency.Observe(timer.timeElapsed())
+	getNetworkLatency.Observe(timer.timeElapsedSeconds())
 }
 
 func IncGetNetworkFailures() {

npm/metrics/timer.go

@@ -7,6 +7,8 @@ import (
 	"github.com/prometheus/client_golang/prometheus"
 )
 
+const billion float64 = 1e+09
+
 // Timer is a one-time-use tool for recording time between a start and end point
 type Timer struct {
 	before int64
@@ -18,12 +20,14 @@ func StartNewTimer() *Timer {
 	return &Timer{time.Now().UnixNano(), 0}
 }
 
-// stopAndRecord ends a timer and records its delta in a summary
+// stopAndRecord uses milliseconds.
+// It ends a timer and records its delta in a summary
 func (timer *Timer) stopAndRecord(observer prometheus.Summary) {
 	observer.Observe(timer.timeElapsed())
 }
 
-// stopAndRecordCRUDExecTime ends a timer and records its delta in a summary (unless the operation is NoOp) with the specified operation as a label.
+// stopAndRecordCRUDExecTime uses milliseconds.
+// It ends a timer and records its delta in a summary (unless the operation is NoOp) with the specified operation as a label.
 func (timer *Timer) stopAndRecordCRUDExecTime(observer *prometheus.SummaryVec, op OperationKind, hadError bool) {
 	timer.stop()
 	if !op.isValid() {
@@ -46,10 +50,19 @@ func (timer *Timer) stop() {
 	timer.after = time.Now().UnixNano()
 }
 
+// timeElapsed returns milliseconds
 func (timer *Timer) timeElapsed() float64 {
 	if timer.after == 0 {
 		timer.stop()
 	}
 	millisecondDifference := float64(timer.after-timer.before) / 1000000.0
 	return millisecondDifference
 }
+
+// timeElapsedSeconds returns seconds
+func (timer *Timer) timeElapsedSeconds() float64 {
+	if timer.after == 0 {
+		timer.stop()
+	}
+	return float64(timer.after-timer.before) / billion
+}

npm/metrics/timer_test.go

@@ -19,3 +19,10 @@ func TestTimeElapsed(t *testing.T) {
 		require.FailNowf(t, "", "expected elapsed time for timer to be  %f but got %f", expectedDuration, duration)
 	}
 }
+
+func TestTimeElapsedSeconds(t *testing.T) {
+	timer := StartNewTimer()
+	time.Sleep(time.Millisecond * 1100)
+	require.GreaterOrEqual(t, timer.timeElapsedSeconds(), 1.0)
+	require.LessOrEqual(t, timer.timeElapsedSeconds(), 3.0)
+}