diff --git a/controller/internal/policy/api_session_enforcer.go b/controller/internal/policy/api_session_enforcer.go index 939ab2ab0..918572753 100644 --- a/controller/internal/policy/api_session_enforcer.go +++ b/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))) } } diff --git a/controller/internal/policy/revocation_enforcer.go b/controller/internal/policy/revocation_enforcer.go index d08b42681..139bf175d 100644 --- a/controller/internal/policy/revocation_enforcer.go +++ b/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 diff --git a/controller/internal/policy/service_policy_enforcer.go b/controller/internal/policy/service_policy_enforcer.go index c01ff49ce..5b4596200 100644 --- a/controller/internal/policy/service_policy_enforcer.go +++ b/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 } diff --git a/controller/internal/policy/session_enforcer_test.go b/controller/internal/policy/session_enforcer_test.go index 59eeb9be0..507e7ce2c 100644 --- a/controller/internal/policy/session_enforcer_test.go +++ b/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())