diff --git a/rules/prometheus.go b/rules/prometheus.go index fa7255d..e270cca 100644 --- a/rules/prometheus.go +++ b/rules/prometheus.go @@ -39,6 +39,13 @@ var ( Help: "etcd rules engine work buffer wait time in ms", Buckets: []float64{1, 2, 5, 10, 20, 50, 100, 200, 500, 1000, 2000, 5000, 10000, 30000, 60000, 300000, 600000}, }, []string{"method", "pattern"}) + rulesEngineCallbackWaitTime = prometheus.NewHistogramVec(prometheus.HistogramOpts{ + Name: "callback_wait_ms", + Subsystem: "etcd", + Namespace: "rules", + Help: "etcd rules engine callback wait time in ms", + Buckets: []float64{1, 2, 5, 10, 20, 50, 100, 200, 500, 1000, 2000, 5000, 10000, 30000, 60000, 300000, 600000}, + }, []string{"pattern"}) ) func init() { @@ -47,6 +54,7 @@ func init() { prometheus.MustRegister(rulesEngineEvaluations) prometheus.MustRegister(rulesEngineWorkerQueueWait) prometheus.MustRegister(rulesEngineWorkBufferWaitTime) + prometheus.MustRegister(rulesEngineCallbackWaitTime) } func incLockMetric(methodName string, pattern string, lockSucceeded bool) { @@ -68,3 +76,7 @@ func workerQueueWaitTime(methodName string, startTime time.Time) { func workBufferWaitTime(methodName, pattern string, startTime time.Time) { rulesEngineWorkBufferWaitTime.WithLabelValues(methodName, pattern).Observe(float64(time.Since(startTime).Nanoseconds() / 1e6)) } + +func callbackWaitTime(pattern string, startTime time.Time) { + rulesEngineCallbackWaitTime.WithLabelValues(pattern).Observe(float64(time.Since(startTime).Nanoseconds() / 1e6)) +} diff --git a/rules/prometheus_test.go b/rules/prometheus_test.go index 490db7c..645656e 100644 --- a/rules/prometheus_test.go +++ b/rules/prometheus_test.go @@ -66,3 +66,8 @@ func TestWorkBufferWaitTime(t *testing.T) { workBufferWaitTime("getKey", "/desired/key/pattern", time.Now()) checkMetrics(t, `rules_etcd_work_buffer_wait_ms_count{method="getKey",pattern="/desired/key/pattern"} 1`) } + +func TestCallbackWaitTime(t *testing.T) { + callbackWaitTime("/desired/key/pattern", time.Now()) + checkMetrics(t, `rules_etcd_callback_wait_ms_count{pattern="/desired/key/pattern"} 1`) +} diff --git a/rules/worker.go b/rules/worker.go index e159b41..92f999b 100644 --- a/rules/worker.go +++ b/rules/worker.go @@ -2,6 +2,7 @@ package rules import ( "sync" + "time" "go.uber.org/zap" ) @@ -100,7 +101,9 @@ func (bw *baseWorker) doWork(loggerPtr **zap.Logger, workerQueueWaitTime(metricsInfo.method, metricsInfo.startTime) bw.metrics.WorkerQueueWaitTime(metricsInfo.method, metricsInfo.startTime) if sat && !is(&bw.stopping) { + startTime := time.Now() callback() + callbackWaitTime(metricsInfo.keyPattern, startTime) } }