Merge pull request #4354 from openziti/backport/v2.0.x-policy-enforcer-metric-refs

[Backport-2.0] Hold the policy enforcers' meters rather than resolving one per run

controller/internal/policy/api_session_enforcer.go

@@ -21,6 +21,7 @@ import (
 	"time"
 
 	"github.com/michaelquigley/pfxlog"
+	"github.com/openziti/metrics"
 	"github.com/openziti/ziti/v2/common/runner"
 	"github.com/openziti/ziti/v2/controller/change"
 	"github.com/openziti/ziti/v2/controller/env"
@@ -39,6 +40,11 @@ const (
 type ApiSessionEnforcer struct {
 	appEnv         model.Env
 	sessionTimeout time.Duration
+	// Resolved once and held. A Meter lookup takes a reference on every call and only Dispose releases
+	// one, so looking one up per run accumulates references and leaves the meter sampling after the
+	// registry is disposed. Timer is not reference counted, and is held here so the two read alike.
+	runTimer    metrics.Timer
+	deleteMeter metrics.Meter
 	*runner.BaseOperation
 }
 
@@ -55,6 +61,8 @@ func NewSessionEnforcer(appEnv *env.AppEnv, frequency time.Duration, sessionTime
 	return &ApiSessionEnforcer{
 		appEnv:         appEnv,
 		sessionTimeout: sessionTimeout,
+		runTimer:       appEnv.GetMetricsRegistry().Timer(ApiSessionEnforcerRun),
+		deleteMeter:    appEnv.GetMetricsRegistry().Meter(ApiSessionEnforcerDelete),
 		BaseOperation:  runner.NewBaseOperation("ApiSessionEnforcer", frequency),
 	}
 }
@@ -63,7 +71,7 @@ func (s *ApiSessionEnforcer) Run() error {
 	startTime := time.Now()
 
 	defer func() {
-		s.appEnv.GetMetricsRegistry().Timer(ApiSessionEnforcerRun).UpdateSince(startTime)
+		s.runTimer.UpdateSince(startTime)
 	}()
 
 	oldest := time.Now().Add(s.sessionTimeout * -1)
@@ -108,7 +116,7 @@ func (s *ApiSessionEnforcer) Run() error {
 					logrus.WithError(err).Errorf("failure while deleting expired api session: %v", id)
 				}
 			}
-			s.appEnv.GetMetricsRegistry().Meter(ApiSessionEnforcerDelete).Mark(int64(len(ids)))
+			s.deleteMeter.Mark(int64(len(ids)))
 		}
 	}
 

controller/internal/policy/revocation_enforcer.go

@@ -20,6 +20,7 @@ import (
 	"time"
 
 	"github.com/michaelquigley/pfxlog"
+	"github.com/openziti/metrics"
 	"github.com/openziti/ziti/v2/common/runner"
 	"github.com/openziti/ziti/v2/controller/change"
 	"github.com/openziti/ziti/v2/controller/command"
@@ -38,6 +39,11 @@ const (
 type RevocationEnforcer struct {
 	appEnv     *env.AppEnv
 	dispatcher command.Dispatcher
+	// Resolved once and held. A Meter lookup takes a reference on every call and only Dispose releases
+	// one, so looking one up per run accumulates references and leaves the meter sampling after the
+	// registry is disposed. Timer is not reference counted, and is held here so the two read alike.
+	runTimer    metrics.Timer
+	deleteMeter metrics.Meter
 	*runner.BaseOperation
 }
 
@@ -46,6 +52,8 @@ func NewRevocationEnforcer(appEnv *env.AppEnv, frequency time.Duration, dispatch
 	return &RevocationEnforcer{
 		appEnv:        appEnv,
 		dispatcher:    dispatcher,
+		runTimer:      appEnv.GetMetricsRegistry().Timer(RevocationEnforcerRun),
+		deleteMeter:   appEnv.GetMetricsRegistry().Meter(RevocationEnforcerDelete),
 		BaseOperation: runner.NewBaseOperation("RevocationEnforcer", frequency),
 	}
 }
@@ -59,7 +67,7 @@ func (e *RevocationEnforcer) Run() error {
 	startTime := time.Now()
 
 	defer func() {
-		e.appEnv.GetMetricsRegistry().Timer(RevocationEnforcerRun).UpdateSince(startTime)
+		e.runTimer.UpdateSince(startTime)
 	}()
 
 	ctx := change.New().SetSourceType(RevocationEnforcerSource).SetChangeAuthorType(change.AuthorTypeController)
@@ -72,7 +80,7 @@ func (e *RevocationEnforcer) Run() error {
 
 	if total > 0 {
 		pfxlog.Logger().Debugf("removed %d expired revocations", total)
-		e.appEnv.GetMetricsRegistry().Meter(RevocationEnforcerDelete).Mark(int64(total))
+		e.deleteMeter.Mark(int64(total))
 	}
 
 	return nil

controller/internal/policy/service_policy_enforcer.go

@@ -21,6 +21,7 @@ import (
 	"time"
 
 	"github.com/michaelquigley/pfxlog"
+	"github.com/openziti/metrics"
 	"github.com/openziti/ziti/v2/common/runner"
 	"github.com/openziti/ziti/v2/controller/change"
 	"github.com/openziti/ziti/v2/controller/db"
@@ -38,15 +39,27 @@ const (
 
 type ServicePolicyEnforcer struct {
 	appEnv *env.AppEnv
+	// Resolved once and held. A Meter lookup takes a reference on every call and only Dispose releases
+	// one, so looking one up per run accumulates references and leaves the meter sampling after the
+	// registry is disposed. The timers are not reference counted, and are held here so the two read alike.
+	eventTimer       metrics.Timer
+	eventDeleteMeter metrics.Meter
+	runTimer         metrics.Timer
+	runDeleteMeter   metrics.Meter
 	*runner.BaseOperation
 	notify chan struct{}
 }
 
 func NewServicePolicyEnforcer(appEnv *env.AppEnv, f time.Duration) *ServicePolicyEnforcer {
+	registry := appEnv.GetMetricsRegistry()
 	result := &ServicePolicyEnforcer{
-		appEnv:        appEnv,
-		BaseOperation: runner.NewBaseOperation("ServicePolicyEnforcer", f),
-		notify:        make(chan struct{}, 1),
+		appEnv:           appEnv,
+		eventTimer:       registry.Timer(SessionPolicyEnforcerEvent),
+		eventDeleteMeter: registry.Meter(SessionPolicyEnforcerEventDeletes),
+		runTimer:         registry.Timer(SessionPolicyEnforcerRun),
+		runDeleteMeter:   registry.Meter(SessionPolicyEnforcerRunDeletes),
+		BaseOperation:    runner.NewBaseOperation("ServicePolicyEnforcer", f),
+		notify:           make(chan struct{}, 1),
 	}
 	result.notify <- struct{}{} // ensure we do a full scan on startup
 	db.ServiceEvents.AddServiceEventHandler(result.handleServiceEvent)
@@ -70,7 +83,7 @@ func (enforcer *ServicePolicyEnforcer) handleServiceEvent(event *db.ServiceEvent
 
 	startTime := time.Now()
 	defer func() {
-		enforcer.appEnv.GetMetricsRegistry().Timer(SessionPolicyEnforcerEvent).UpdateSince(startTime)
+		enforcer.eventTimer.UpdateSince(startTime)
 	}()
 
 	log := pfxlog.Logger().WithField("event", event.String())
@@ -109,7 +122,7 @@ func (enforcer *ServicePolicyEnforcer) handleServiceEvent(event *db.ServiceEvent
 		log.Debugf("session %v deleted", sessionId)
 	}
 
-	enforcer.appEnv.GetMetricsRegistry().Meter(SessionPolicyEnforcerEventDeletes).Mark(int64(len(sessionsToDelete)))
+	enforcer.eventDeleteMeter.Mark(int64(len(sessionsToDelete)))
 }
 
 func (enforcer *ServicePolicyEnforcer) Run() error {
@@ -123,7 +136,7 @@ func (enforcer *ServicePolicyEnforcer) Run() error {
 	startTime := time.Now()
 
 	defer func() {
-		enforcer.appEnv.GetMetricsRegistry().Timer(SessionPolicyEnforcerRun).UpdateSince(startTime)
+		enforcer.runTimer.UpdateSince(startTime)
 	}()
 
 	result, err := enforcer.appEnv.GetManagers().Session.Query("")
@@ -174,7 +187,7 @@ func (enforcer *ServicePolicyEnforcer) Run() error {
 		_ = enforcer.appEnv.GetManagers().Session.Delete(sessionId, ctx)
 	}
 
-	enforcer.appEnv.GetMetricsRegistry().Meter(SessionPolicyEnforcerRunDeletes).Mark(int64(len(sessionsToRemove)))
+	enforcer.runDeleteMeter.Mark(int64(len(sessionsToRemove)))
 
 	return nil
 }

controller/internal/policy/session_enforcer_test.go

@@ -21,11 +21,11 @@ import (
 	"time"
 
 	"github.com/google/go-cmp/cmp/cmpopts"
-	"github.com/openziti/ziti/v2/controller/storage/boltz"
-	"github.com/openziti/ziti/v2/controller/storage/boltztest"
 	"github.com/openziti/ziti/v2/common/eid"
 	"github.com/openziti/ziti/v2/controller/db"
 	"github.com/openziti/ziti/v2/controller/model"
+	"github.com/openziti/ziti/v2/controller/storage/boltz"
+	"github.com/openziti/ziti/v2/controller/storage/boltztest"
 	"github.com/sirupsen/logrus"
 )
 
@@ -71,9 +71,14 @@ func (ctx *enforcerTestContext) testSessionsCleanup() {
 	boltztest.RequireReload(ctx, session)
 	boltztest.RequireReload(ctx, session2)
 
+	// Built directly rather than through NewSessionEnforcer, which refuses a session timeout under a
+	// minute; the negative timeout here is what makes every session expired. The metrics still have to be
+	// supplied, since the enforcer holds them rather than resolving one per run.
 	enforcer := &ApiSessionEnforcer{
 		appEnv:         ctx,
 		sessionTimeout: -time.Second,
+		runTimer:       ctx.GetMetricsRegistry().Timer(ApiSessionEnforcerRun),
+		deleteMeter:    ctx.GetMetricsRegistry().Meter(ApiSessionEnforcerDelete),
 	}
 
 	ctx.NoError(enforcer.Run())