diff --git a/CHANGELOG.md b/CHANGELOG.md index bc12aa7..f16e334 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -37,6 +37,9 @@ The format is based on [Keep a Changelog](https://keepachangelog.com/en/1.0.0/) ## Unreleased +### Improvements +* [#105](https://github.com/babylonlabs-io/vigilante/pull/105) Measure latency + ## v0.16.0 * [#94](https://github.com/babylonlabs-io/vigilante/pull/94) adds gosec and fixes gosec issues diff --git a/btcstaking-tracker/stakingeventwatcher/stakingeventwatcher.go b/btcstaking-tracker/stakingeventwatcher/stakingeventwatcher.go index b33fb81..2a873e1 100644 --- a/btcstaking-tracker/stakingeventwatcher/stakingeventwatcher.go +++ b/btcstaking-tracker/stakingeventwatcher/stakingeventwatcher.go @@ -175,6 +175,8 @@ func (sew *StakingEventWatcher) handleNewBlocks(blockNotifier *notifier.BlockEpo // checkBabylonDelegations iterates over all active babylon delegations, and reports not already // tracked delegations to the unbondingDelegationChan func (sew *StakingEventWatcher) checkBabylonDelegations(status btcstakingtypes.BTCDelegationStatus, addDel func(del Delegation)) error { + defer sew.latency(fmt.Sprintf("checkBabylonDelegations: %s", status))() + var i = uint64(0) for { delegations, err := sew.babylonNodeAdapter.DelegationsByStatus(status, i, sew.cfg.NewDelegationsBatchSize) @@ -610,6 +612,8 @@ func (sew *StakingEventWatcher) activateBtcDelegation( ctx, cancel := sew.quitContext() defer cancel() + defer sew.latency("activateBtcDelegation")() + if err := sew.pendingTracker.UpdateActivation(stakingTxHash, true); err != nil { sew.logger.Debugf("skipping tx %s is not in pending tracker, err: %v", stakingTxHash, err) } @@ -647,3 +651,14 @@ func (sew *StakingEventWatcher) activateBtcDelegation( }), ) } + +func (sew *StakingEventWatcher) latency(method string) func() { + startTime := time.Now() + return func() { + duration := time.Since(startTime) + sew.logger.Debug("execution time", + zap.String("method", method), + zap.Duration("latency", duration)) + sew.metrics.MethodExecutionLatency.WithLabelValues(method).Observe(duration.Seconds()) + } +} diff --git a/metrics/btcstaking_tracker.go b/metrics/btcstaking_tracker.go index 3a977d2..cf32a64 100644 --- a/metrics/btcstaking_tracker.go +++ b/metrics/btcstaking_tracker.go @@ -31,6 +31,7 @@ type UnbondingWatcherMetrics struct { DetectedNonUnbondingTransactionsCounter prometheus.Counter FailedReportedActivateDelegations prometheus.Counter ReportedActivateDelegationsCounter prometheus.Counter + MethodExecutionLatency *prometheus.HistogramVec } func newUnbondingWatcherMetrics(registry *prometheus.Registry) *UnbondingWatcherMetrics { @@ -66,6 +67,11 @@ func newUnbondingWatcherMetrics(registry *prometheus.Registry) *UnbondingWatcher Name: "unbonding_watcher_reported_activate_delegations", Help: "The total number of unbonding transactions successfully reported to Babylon node", }), + MethodExecutionLatency: registerer.NewHistogramVec(prometheus.HistogramOpts{ + Name: "unbonding_watcher_method_latency_seconds", + Help: "Latency in seconds", + Buckets: []float64{.001, .002, .005, .01, .025, .05, .1}, + }, []string{"method"}), } return uwMetrics