From e78cfc0687e8057d0447011056316ae01d04abe9 Mon Sep 17 00:00:00 2001 From: Caleb Doxsey Date: Mon, 14 Apr 2025 08:20:10 -0600 Subject: [PATCH] cleanup logs (#5571) --- authorize/evaluator/evaluator.go | 12 ++++------ cmd/pomerium/main.go | 4 ---- config/config_source.go | 6 +---- config/metrics.go | 1 - config/options.go | 11 --------- internal/log/grpc.go | 6 ++--- pkg/envoy/resource_monitor_linux.go | 2 +- pkg/grpc/databroker/syncer.go | 37 +++++++++++++++++------------ 8 files changed, 31 insertions(+), 48 deletions(-) diff --git a/authorize/evaluator/evaluator.go b/authorize/evaluator/evaluator.go index 0d13f166c..491e01c95 100644 --- a/authorize/evaluator/evaluator.go +++ b/authorize/evaluator/evaluator.go @@ -109,7 +109,7 @@ func New( ) (*Evaluator, error) { cfg := getConfig(options...) - err := updateStore(ctx, store, cfg) + err := updateStore(store, cfg) if err != nil { return nil, err } @@ -321,8 +321,8 @@ func (e *Evaluator) getClientCA(policy *config.Policy) (string, error) { return string(e.clientCA), nil } -func updateStore(ctx context.Context, store *store.Store, cfg *evaluatorConfig) error { - jwk, err := getJWK(ctx, cfg) +func updateStore(store *store.Store, cfg *evaluatorConfig) error { + jwk, err := getJWK(cfg) if err != nil { return fmt.Errorf("authorize: couldn't create signer: %w", err) } @@ -339,7 +339,7 @@ func updateStore(ctx context.Context, store *store.Store, cfg *evaluatorConfig) return nil } -func getJWK(ctx context.Context, cfg *evaluatorConfig) (*jose.JSONWebKey, error) { +func getJWK(cfg *evaluatorConfig) (*jose.JSONWebKey, error) { var decodedCert []byte // if we don't have a signing key, generate one if len(cfg.SigningKey) == 0 { @@ -359,10 +359,6 @@ func getJWK(ctx context.Context, cfg *evaluatorConfig) (*jose.JSONWebKey, error) if err != nil { return nil, fmt.Errorf("couldn't generate signing key: %w", err) } - log.Ctx(ctx).Info().Str("Algorithm", jwk.Algorithm). - Str("KeyID", jwk.KeyID). - Interface("Public Key", jwk.Public()). - Msg("authorize: signing key") return jwk, nil } diff --git a/cmd/pomerium/main.go b/cmd/pomerium/main.go index f277ed5be..30918e50a 100644 --- a/cmd/pomerium/main.go +++ b/cmd/pomerium/main.go @@ -53,10 +53,6 @@ func main() { } func run(ctx context.Context, configFile string) error { - ctx = log.WithContext(ctx, func(c zerolog.Context) zerolog.Context { - return c.Str("config_file_source", configFile).Bool("bootstrap", true) - }) - var src config.Source src, err := config.NewFileOrEnvironmentSource(ctx, configFile, files.FullVersion()) diff --git a/config/config_source.go b/config/config_source.go index 954f9d6c0..c0cffa14a 100644 --- a/config/config_source.go +++ b/config/config_source.go @@ -108,10 +108,6 @@ func NewFileOrEnvironmentSource( ctx context.Context, configFile, envoyVersion string, ) (*FileOrEnvironmentSource, error) { - ctx = log.WithContext(ctx, func(c zerolog.Context) zerolog.Context { - return c.Str("config_file_source", configFile) - }) - options, err := newOptionsFromConfig(configFile) if err != nil { return nil, err @@ -254,7 +250,7 @@ func (src *FileWatcherSource) onConfigChange(ctx context.Context, cfg *Config) { // store the config and trigger an update src.cfg = cfg.Clone() src.hash = getAllConfigFilePathsHash(src.cfg) - log.Ctx(ctx).Info().Uint64("hash", src.hash).Msg("config/filewatchersource: underlying config change, triggering update") + log.Ctx(ctx).Debug().Uint64("hash", src.hash).Msg("config/filewatchersource: underlying config change, triggering update") src.Trigger(ctx, src.cfg) } diff --git a/config/metrics.go b/config/metrics.go index 5b03a230c..60f6df44c 100644 --- a/config/metrics.go +++ b/config/metrics.go @@ -93,7 +93,6 @@ func (mgr *MetricsManager) updateServer(ctx context.Context, cfg *Config) { mgr.handler = nil if mgr.addr == "" { - log.Ctx(ctx).Info().Msg("metrics: http server disabled") return } diff --git a/config/options.go b/config/options.go index cd1b7ed88..83dac417c 100644 --- a/config/options.go +++ b/config/options.go @@ -655,14 +655,11 @@ func (o *Options) Validate() error { return fmt.Errorf("config: failed to parse headers: %w", err) } - hasCert := false - if o.Cert != "" || o.Key != "" { _, err := cryptutil.CertificateFromBase64(o.Cert, o.Key) if err != nil { return fmt.Errorf("config: bad cert base64 %w", err) } - hasCert = true } for _, c := range o.CertificateData { @@ -670,7 +667,6 @@ func (o *Options) Validate() error { if err != nil { return fmt.Errorf("config: bad cert entry, cert is invalid: %w", err) } - hasCert = true } for _, c := range o.CertificateFiles { @@ -678,7 +674,6 @@ func (o *Options) Validate() error { if err != nil { return fmt.Errorf("config: bad cert entry, file reference invalid. %w", err) } - hasCert = true } if o.CertFile != "" || o.KeyFile != "" { @@ -686,7 +681,6 @@ func (o *Options) Validate() error { if err != nil { return fmt.Errorf("config: bad cert file %w", err) } - hasCert = true } if err := o.DownstreamMTLS.validate(); err != nil { @@ -696,11 +690,6 @@ func (o *Options) Validate() error { // strip quotes from redirect address (#811) o.HTTPRedirectAddr = strings.Trim(o.HTTPRedirectAddr, `"'`) - if !o.InsecureServer && !hasCert && !o.AutocertOptions.Enable { - log.Ctx(ctx).Info().Msg("neither `autocert`, " + - "`insecure_server` or manually provided certificates were provided, server will be using a self-signed certificate") - } - if err := ValidateDNSLookupFamily(o.DNSLookupFamily); err != nil { return fmt.Errorf("config: %w", err) } diff --git a/internal/log/grpc.go b/internal/log/grpc.go index 7b130e88e..922f6f44e 100644 --- a/internal/log/grpc.go +++ b/internal/log/grpc.go @@ -51,19 +51,19 @@ type grpcLogger struct { func (c *grpcLogger) Info(args ...any) { if c.getLevel() <= zerolog.DebugLevel { - Logger().Info().Msg(fmt.Sprint(args...)) + Logger().Debug().Msg(fmt.Sprint(args...)) } } func (c *grpcLogger) Infoln(args ...any) { if c.getLevel() <= zerolog.DebugLevel { - Logger().Info().Msg(fmt.Sprintln(args...)) + Logger().Debug().Msg(fmt.Sprintln(args...)) } } func (c *grpcLogger) Infof(format string, args ...any) { if c.getLevel() <= zerolog.DebugLevel { - Logger().Info().Msg(fmt.Sprintf(format, args...)) + Logger().Debug().Msg(fmt.Sprintf(format, args...)) } } diff --git a/pkg/envoy/resource_monitor_linux.go b/pkg/envoy/resource_monitor_linux.go index 5fef12b58..fd1e02fc2 100644 --- a/pkg/envoy/resource_monitor_linux.go +++ b/pkg/envoy/resource_monitor_linux.go @@ -283,7 +283,7 @@ func (s *sharedResourceMonitor) Run(ctx context.Context, envoyPid int) error { if envoyCgroup != s.cgroup { return fmt.Errorf("envoy process is not in the expected cgroup: %s", envoyCgroup) } - log.Ctx(ctx).Info().Str("service", "envoy").Str("cgroup", s.cgroup).Msg("starting resource monitor") + log.Ctx(ctx).Debug().Str("service", "envoy").Str("cgroup", s.cgroup).Msg("starting resource monitor") ctx, ca := context.WithCancelCause(ctx) diff --git a/pkg/grpc/databroker/syncer.go b/pkg/grpc/databroker/syncer.go index 4391024fd..dd38b6805 100644 --- a/pkg/grpc/databroker/syncer.go +++ b/pkg/grpc/databroker/syncer.go @@ -101,7 +101,7 @@ func NewSyncer(ctx context.Context, id string, handler SyncerHandler, options .. id: id, } if s.cfg.withFastForward { - s.handler = newFastForwardHandler(s.logCtx(closeCtx), handler) + s.handler = newFastForwardHandler(closeCtx, handler) } return s } @@ -120,7 +120,6 @@ func (syncer *Syncer) Run(ctx context.Context) error { cancel() }() - ctx = syncer.logCtx(ctx) for { var err error if syncer.serverVersion == 0 { @@ -130,7 +129,11 @@ func (syncer *Syncer) Run(ctx context.Context) error { } if err != nil { - log.Ctx(ctx).Error().Err(err).Msg("sync") + log.Ctx(ctx).Error(). + Str("syncer_id", syncer.id). + Str("syncer_type", syncer.cfg.typeURL). + Err(err). + Msg("sync") select { case <-ctx.Done(): return context.Cause(ctx) @@ -141,7 +144,10 @@ func (syncer *Syncer) Run(ctx context.Context) error { } func (syncer *Syncer) init(ctx context.Context) error { - log.Ctx(ctx).Debug().Msg("initial sync") + log.Ctx(ctx).Debug(). + Str("syncer_id", syncer.id). + Str("syncer_type", syncer.cfg.typeURL). + Msg("initial sync") records, recordVersion, serverVersion, err := InitialSync(ctx, syncer.handler.GetDataBrokerServiceClient(), &SyncLatestRequest{ Type: syncer.cfg.typeURL, }) @@ -173,12 +179,18 @@ func (syncer *Syncer) sync(ctx context.Context) error { return fmt.Errorf("error calling sync: %w", err) } - log.Ctx(ctx).Debug().Msg("listening for updates") + log.Ctx(ctx).Debug(). + Str("syncer_id", syncer.id). + Str("syncer_type", syncer.cfg.typeURL). + Msg("listening for updates") for { res, err := stream.Recv() if status.Code(err) == codes.Aborted { - log.Ctx(ctx).Error().Err(err).Msg("aborted sync due to mismatched server version") + log.Ctx(ctx).Error().Err(err). + Str("syncer_id", syncer.id). + Str("syncer_type", syncer.cfg.typeURL). + Msg("aborted sync due to mismatched server version") // server version changed, so re-init syncer.serverVersion = 0 return nil @@ -190,11 +202,13 @@ func (syncer *Syncer) sync(ctx context.Context) error { } rec := res.GetRecord() - log.Ctx(logCtxRec(ctx, rec)).Debug().Msg("syncer got record") + log.Ctx(logCtxRec(ctx, rec)).Debug(). + Str("syncer_id", syncer.id). + Str("syncer_type", syncer.cfg.typeURL). + Msg("syncer got record") syncer.recordVersion = res.GetRecord().GetVersion() if syncer.cfg.typeURL == "" || syncer.cfg.typeURL == res.GetRecord().GetType() { - ctx := logCtxRec(ctx, rec) syncer.handler.UpdateRecords( context.WithValue(ctx, contextkeys.UpdateRecordsVersion, rec.GetVersion()), syncer.serverVersion, []*Record{rec}) @@ -210,10 +224,3 @@ func logCtxRec(ctx context.Context, rec *Record) context.Context { Uint64("record_version", rec.GetVersion()) }) } - -func (syncer *Syncer) logCtx(ctx context.Context) context.Context { - return log.WithContext(ctx, func(c zerolog.Context) zerolog.Context { - return c.Str("syncer_id", syncer.id). - Str("syncer_type", syncer.cfg.typeURL) - }) -}