config: log config source changes (#1959)

* config: log config source changes

* use internal log import

authenticate/authenticate.go

@@ -81,7 +81,6 @@ func (a *Authenticate) OnConfigChange(cfg *config.Config) {
 		return
 	}
 
-	log.Info().Str("checksum", fmt.Sprintf("%x", cfg.Options.Checksum())).Msg("authenticate: updating options")
 	a.options.Store(cfg.Options)
 	if state, err := newAuthenticateStateFromConfig(cfg); err != nil {
 		log.Error().Err(err).Msg("authenticate: failed to update state")

authorize/authorize.go

@@ -84,7 +84,6 @@ func newPolicyEvaluator(opts *config.Options, store *evaluator.Store) (*evaluato
 
 // OnConfigChange updates internal structures based on config.Options
 func (a *Authorize) OnConfigChange(cfg *config.Config) {
-	log.Info().Str("checksum", fmt.Sprintf("%x", cfg.Options.Checksum())).Msg("authorize: updating options")
 	a.currentOptions.Store(cfg.Options)
 	if state, err := newAuthorizeStateFromConfig(cfg, a.store); err != nil {
 		log.Error().Err(err).Msg("authorize: error updating state")

config/config.go

@@ -1,6 +1,10 @@
 package config
 
-import "crypto/tls"
+import (
+	"crypto/tls"
+
+	"github.com/pomerium/pomerium/internal/hashutil"
+)
 
 // Config holds pomerium configuration options.
 type Config struct {
@@ -25,3 +29,8 @@ func (cfg *Config) AllCertificates() []tls.Certificate {
 	certs = append(certs, cfg.AutoCertificates...)
 	return certs
 }
+
+// Checksum returns the config checksum.
+func (cfg *Config) Checksum() uint64 {
+	return hashutil.MustHash(cfg)
+}

config/config_source.go

@@ -8,6 +8,8 @@ import (
 	"github.com/fsnotify/fsnotify"
 
 	"github.com/pomerium/pomerium/internal/fileutil"
+	"github.com/pomerium/pomerium/internal/log"
+	"github.com/pomerium/pomerium/internal/telemetry/metrics"
 )
 
 // A ChangeListener is called when configuration changes.
@@ -98,9 +100,12 @@ func NewFileOrEnvironmentSource(configFile string) (*FileOrEnvironmentSource, er
 		return nil, err
 	}
 
+	cfg := &Config{Options: options}
+	metrics.SetConfigInfo(cfg.Options.Services, "local", cfg.Checksum(), true)
+
 	src := &FileOrEnvironmentSource{
 		configFile: configFile,
-		config:     &Config{Options: options},
+		config:     cfg,
 	}
 	options.viper.OnConfigChange(src.onConfigChange)
 	go options.viper.WatchConfig()
@@ -110,9 +115,15 @@ func NewFileOrEnvironmentSource(configFile string) (*FileOrEnvironmentSource, er
 
 func (src *FileOrEnvironmentSource) onConfigChange(evt fsnotify.Event) {
 	src.mu.Lock()
-	newOptions := handleConfigUpdate(src.configFile, src.config.Options)
+	cfg := src.config
-	cfg := &Config{Options: newOptions}
+	options, err := newOptionsFromConfig(src.configFile)
-	src.config = cfg
+	if err == nil {
+		cfg = &Config{Options: options}
+		metrics.SetConfigInfo(cfg.Options.Services, "local", cfg.Checksum(), true)
+	} else {
+		log.Error().Err(err).Msg("config: error updating config")
+		metrics.SetConfigInfo(cfg.Options.Services, "local", cfg.Checksum(), false)
+	}
 	src.mu.Unlock()
 
 	src.Trigger(cfg)

config/options.go

@@ -353,8 +353,6 @@ func newOptionsFromConfig(configFile string) (*Options, error) {
 		return int64(len(o.GetAllPolicies()))
 	})
 
-	metrics.SetConfigChecksum(serviceName, o.Checksum())
-
 	return o, nil
 }
 
@@ -1065,31 +1063,6 @@ func (o *Options) ApplySettings(settings *config.Settings) {
 	}
 }
 
-// handleConfigUpdate takes configuration file, an existing options struct, and
-// returns new options if any change is detected. If no change was detected, the
-// existing option will be returned.
-func handleConfigUpdate(configFile string, opt *Options) *Options {
-	serviceName := telemetry.ServiceName(opt.Services)
-
-	newOpt, err := newOptionsFromConfig(configFile)
-	if err != nil {
-		log.Error().Err(err).Msg("config: could not reload configuration")
-		metrics.SetConfigInfo(serviceName, false)
-		return opt
-	}
-	optChecksum := opt.Checksum()
-	newOptChecksum := newOpt.Checksum()
-
-	log.Debug().Str("old-checksum", fmt.Sprintf("%x", optChecksum)).Str("new-checksum", fmt.Sprintf("%x", newOptChecksum)).Msg("config: checksum change")
-
-	if newOptChecksum == optChecksum {
-		log.Debug().Msg("config: loaded configuration has not changed")
-		return opt
-	}
-
-	return newOpt
-}
-
 func dataDir() string {
 	homeDir, _ := os.UserHomeDir()
 	if homeDir == "" {

internal/databroker/config_source.go

@@ -8,6 +8,7 @@ import (
 	"github.com/pomerium/pomerium/config"
 	"github.com/pomerium/pomerium/internal/hashutil"
 	"github.com/pomerium/pomerium/internal/log"
+	"github.com/pomerium/pomerium/internal/telemetry/metrics"
 	"github.com/pomerium/pomerium/internal/telemetry/trace"
 	"github.com/pomerium/pomerium/pkg/grpc"
 	configpb "github.com/pomerium/pomerium/pkg/grpc/config"
@@ -134,6 +135,8 @@ func (src *ConfigSource) rebuild(firstTime bool) {
 	if !firstTime {
 		src.Trigger(cfg)
 	}
+
+	metrics.SetConfigInfo(cfg.Options.Services, "databroker", cfg.Checksum(), true)
 }
 
 func (src *ConfigSource) runUpdater(cfg *config.Config) {

internal/telemetry/metrics/info.go

@@ -2,6 +2,7 @@ package metrics
 
 import (
 	"context"
+	"fmt"
 	"time"
 
 	"go.opencensus.io/metric/metricproducer"
@@ -73,8 +74,10 @@ func RecordIdentityManagerLastRefresh() {
 
 // SetConfigInfo records the status, checksum and timestamp of a configuration
 // reload. You must register InfoViews or the related config views before calling
-func SetConfigInfo(service string, success bool) {
+func SetConfigInfo(service string, configName string, checksum uint64, success bool) {
 	if success {
+		registry.setConfigChecksum(service, configName, checksum)
+
 		serviceTag := tag.Insert(TagKeyService, service)
 		if err := stats.RecordWithTags(
 			context.Background(),
@@ -94,6 +97,11 @@ func SetConfigInfo(service string, success bool) {
 	} else {
 		stats.Record(context.Background(), configLastReloadSuccess.M(0))
 	}
+	log.Info().
+		Str("service", service).
+		Str("config", configName).
+		Str("checksum", fmt.Sprintf("%x", checksum)).
+		Msg("config: updated config")
 }
 
 // SetBuildInfo records the pomerium build info. You must call RegisterInfoMetrics to
@@ -107,12 +115,6 @@ func RegisterInfoMetrics() {
 	metricproducer.GlobalManager().AddProducer(registry.registry)
 }
 
-// SetConfigChecksum creates the configuration checksum metric.  You must call RegisterInfoMetrics to
-// have this exported
-func SetConfigChecksum(service string, checksum uint64) {
-	registry.setConfigChecksum(service, checksum)
-}
-
 // AddPolicyCountCallback sets the function to call when exporting the
 // policy count metric.   You must call RegisterInfoMetrics to have this
 // exported

internal/telemetry/metrics/info_test.go

@@ -27,7 +27,7 @@ func Test_SetConfigInfo(t *testing.T) {
 		t.Run(tt.name, func(t *testing.T) {
 			view.Unregister(InfoViews...)
 			view.Register(InfoViews...)
-			SetConfigInfo("test_service", tt.success)
+			SetConfigInfo("test_service", "test config", 0, tt.success)
 
 			testDataRetrieval(ConfigLastReloadView, t, tt.wantLastReload)
 			testDataRetrieval(ConfigLastReloadSuccessView, t, tt.wantLastReloadSuccess)
@@ -63,16 +63,6 @@ func Test_AddPolicyCountCallback(t *testing.T) {
 	testMetricRetrieval(registry.registry.Read(), t, wantLabels, wantValue, metrics.PolicyCountTotal)
 }
 
-func Test_SetConfigChecksum(t *testing.T) {
-	registry = newMetricRegistry()
-
-	wantValue := uint64(42)
-	wantLabels := []metricdata.LabelValue{{Value: "test_service", Present: true}}
-	SetConfigChecksum("test_service", wantValue)
-
-	testMetricRetrieval(registry.registry.Read(), t, wantLabels, float64(wantValue), metrics.ConfigChecksumDecimal)
-}
-
 func Test_RegisterInfoMetrics(t *testing.T) {
 	metricproducer.GlobalManager().DeleteProducer(registry.registry)
 	RegisterInfoMetrics()

internal/telemetry/metrics/registry.go

@@ -54,7 +54,7 @@ func (r *metricRegistry) init() {
 
 			r.configChecksum, err = r.registry.AddFloat64Gauge(metrics.ConfigChecksumDecimal,
 				metric.WithDescription("Config checksum represented in decimal notation"),
-				metric.WithLabelKeys(metrics.ServiceLabel),
+				metric.WithLabelKeys(metrics.ServiceLabel, metrics.ConfigLabel),
 			)
 			if err != nil {
 				log.Error().Err(err).Msg("telemetry/metrics: failed to register config checksum metric")
@@ -102,11 +102,11 @@ func (r *metricRegistry) addPolicyCountCallback(service string, f func() int64)
 	}
 }
 
-func (r *metricRegistry) setConfigChecksum(service string, checksum uint64) {
+func (r *metricRegistry) setConfigChecksum(service string, configName string, checksum uint64) {
 	if r.configChecksum == nil {
 		return
 	}
-	m, err := r.configChecksum.GetEntry(metricdata.NewLabelValue(service))
+	m, err := r.configChecksum.GetEntry(metricdata.NewLabelValue(service), metricdata.NewLabelValue(configName))
 	if err != nil {
 		log.Error().Err(err).Msg("telemetry/metrics: failed to get config checksum metric")
 	}

pkg/metrics/constants.go

@@ -21,6 +21,7 @@ const (
 // labels
 const (
 	ServiceLabel   = "service"
+	ConfigLabel    = "config"
 	VersionLabel   = "version"
 	RevisionLabel  = "revision"
 	GoVersionLabel = "goversion"

proxy/proxy.go

@@ -82,7 +82,6 @@ func (p *Proxy) OnConfigChange(cfg *config.Config) {
 		return
 	}
 
-	log.Info().Str("checksum", fmt.Sprintf("%x", cfg.Options.Checksum())).Msg("proxy: updating options")
 	p.currentOptions.Store(cfg.Options)
 	p.setHandlers(cfg.Options)
 	if state, err := newProxyStateFromConfig(cfg); err != nil {