diff --git a/download/download.go b/download/download.go index a2f3a346e4..30d2c30dee 100644 --- a/download/download.go +++ b/download/download.go @@ -13,8 +13,9 @@ import ( "path" "time" + "github.com/open-policy-agent/opa/sdk" + "github.com/pkg/errors" - "github.com/sirupsen/logrus" "github.com/open-policy-agent/opa/metrics" @@ -47,10 +48,10 @@ type Downloader struct { path string // path to use in bundle download request stop chan chan struct{} // used to signal plugin to stop running f func(context.Context, Update) // callback function invoked when download updates occur - logAttrs [][2]string // optional attributes to include in log messages etag string // HTTP Etag for caching purposes sizeLimitBytes *int64 // max bundle file size in bytes (passed to reader) bvc *bundle.VerificationConfig + logger sdk.Logger } // New returns a new Downloader that can be started. @@ -60,6 +61,7 @@ func New(config Config, client rest.Client, path string) *Downloader { client: client, path: path, stop: make(chan chan struct{}), + logger: client.Logger(), } } @@ -71,8 +73,8 @@ func (d *Downloader) WithCallback(f func(context.Context, Update)) *Downloader { // WithLogAttrs sets an optional set of key/value pair attributes to include in // log messages emitted by the downloader. -func (d *Downloader) WithLogAttrs(attrs [][2]string) *Downloader { - d.logAttrs = attrs +func (d *Downloader) WithLogAttrs(attrs map[string]interface{}) *Downloader { + d.logger = d.logger.WithFields(attrs) return d } @@ -123,7 +125,7 @@ func (d *Downloader) loop() { delay = util.DefaultBackoff(float64(minRetryDelay), float64(*d.config.Polling.MaxDelaySeconds), retry) } - d.logDebug("Waiting %v before next download/retry.", delay) + d.logger.Debug("Waiting %v before next download/retry.", delay) timer := time.NewTimer(delay) select { @@ -155,8 +157,7 @@ func (d *Downloader) oneShot(ctx context.Context) error { } func (d *Downloader) download(ctx context.Context, m metrics.Metrics) (*bundle.Bundle, string, error) { - - d.logDebug("Download starting.") + d.logger.Debug("Download starting.") resp, err := d.client.WithHeader("If-None-Match", d.etag).Do(ctx, "GET", d.path) if err != nil { @@ -168,7 +169,7 @@ func (d *Downloader) download(ctx context.Context, m metrics.Metrics) (*bundle.B switch resp.StatusCode { case http.StatusOK: if resp.Body != nil { - d.logDebug("Download in progress.") + d.logger.Debug("Download in progress.") m.Timer(metrics.RegoLoadBundles).Start() defer m.Timer(metrics.RegoLoadBundles).Stop() baseURL := path.Join(d.client.Config().URL, d.path) @@ -184,7 +185,7 @@ func (d *Downloader) download(ctx context.Context, m metrics.Metrics) (*bundle.B return &b, resp.Header.Get("ETag"), nil } - d.logDebug("Server replied with empty body.") + d.logger.Debug("Server replied with empty body.") return nil, "", nil case http.StatusNotModified: @@ -197,23 +198,3 @@ func (d *Downloader) download(ctx context.Context, m metrics.Metrics) (*bundle.B return nil, "", fmt.Errorf("server replied with HTTP %v", resp.StatusCode) } } - -func (d *Downloader) logError(fmt string, a ...interface{}) { - logrus.WithFields(d.logrusFields()).Errorf(fmt, a...) -} - -func (d *Downloader) logInfo(fmt string, a ...interface{}) { - logrus.WithFields(d.logrusFields()).Infof(fmt, a...) -} - -func (d *Downloader) logDebug(fmt string, a ...interface{}) { - logrus.WithFields(d.logrusFields()).Debugf(fmt, a...) -} - -func (d *Downloader) logrusFields() logrus.Fields { - flds := logrus.Fields{} - for i := range d.logAttrs { - flds[d.logAttrs[i][0]] = flds[d.logAttrs[i][1]] - } - return flds -} diff --git a/internal/config/config.go b/internal/config/config.go index 077b0d609a..ef80559603 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -13,6 +13,8 @@ import ( "regexp" "strings" + "github.com/open-policy-agent/opa/sdk" + "github.com/open-policy-agent/opa/keys" "github.com/ghodss/yaml" @@ -27,6 +29,7 @@ type ServiceOptions struct { Raw json.RawMessage AuthPlugin func(string) rest.HTTPAuthPlugin Keys map[string]*keys.Config + Logger sdk.Logger } // ParseServicesConfig returns a set of named service clients. The service @@ -42,7 +45,7 @@ func ParseServicesConfig(opts ServiceOptions) (map[string]rest.Client, error) { if err := util.Unmarshal(opts.Raw, &arr); err == nil { for _, s := range arr { - client, err := rest.New(s, opts.Keys, rest.AuthPluginLookup(opts.AuthPlugin)) + client, err := rest.New(s, opts.Keys, rest.AuthPluginLookup(opts.AuthPlugin), rest.Logger(opts.Logger)) if err != nil { return nil, err } @@ -50,7 +53,7 @@ func ParseServicesConfig(opts ServiceOptions) (map[string]rest.Client, error) { } } else if util.Unmarshal(opts.Raw, &obj) == nil { for k := range obj { - client, err := rest.New(obj[k], opts.Keys, rest.Name(k), rest.AuthPluginLookup(opts.AuthPlugin)) + client, err := rest.New(obj[k], opts.Keys, rest.Name(k), rest.AuthPluginLookup(opts.AuthPlugin), rest.Logger(opts.Logger)) if err != nil { return nil, err } diff --git a/plugins/bundle/config.go b/plugins/bundle/config.go index 197afaa730..b5c00abdb2 100644 --- a/plugins/bundle/config.go +++ b/plugins/bundle/config.go @@ -9,8 +9,6 @@ import ( "path" "strings" - "github.com/sirupsen/logrus" - "github.com/open-policy-agent/opa/bundle" "github.com/open-policy-agent/opa/download" "github.com/open-policy-agent/opa/keys" @@ -49,8 +47,6 @@ func ParseConfig(config []byte, services []string) (*Config, error) { }, } - logrus.Warn("Deprecated 'bundle' configuration specified. Use 'bundles' instead. See https://www.openpolicyagent.org/docs/latest/configuration/#bundles") - return &parsedConfig, nil } diff --git a/plugins/bundle/plugin.go b/plugins/bundle/plugin.go index 6a07db6926..186faa497e 100644 --- a/plugins/bundle/plugin.go +++ b/plugins/bundle/plugin.go @@ -17,7 +17,7 @@ import ( "sync" "time" - "github.com/sirupsen/logrus" + "github.com/open-policy-agent/opa/sdk" "github.com/open-policy-agent/opa/ast" "github.com/open-policy-agent/opa/bundle" @@ -37,6 +37,7 @@ type Plugin struct { listeners map[interface{}]func(Status) // listeners to send status updates to bulkListeners map[interface{}]func(map[string]*Status) // listeners to send aggregated status updates to downloaders map[string]*download.Downloader + logger sdk.Logger mtx sync.Mutex cfgMtx sync.Mutex legacyConfig bool @@ -60,6 +61,7 @@ func New(parsedConfig *Config, manager *plugins.Manager) *Plugin { downloaders: make(map[string]*download.Downloader), etags: make(map[string]string), ready: false, + logger: manager.Logger(), } manager.UpdatePluginStatus(Name, &plugins.Status{State: plugins.StateNotReady}) @@ -98,7 +100,8 @@ func (p *Plugin) Start(ctx context.Context) error { p.initDownloaders() for name, dl := range p.downloaders { - p.logInfo(name, "Starting bundle downloader.") + + p.log(name).Info("Starting bundle downloader.") dl.Start(ctx) } return nil @@ -109,7 +112,7 @@ func (p *Plugin) Stop(ctx context.Context) { p.mtx.Lock() defer p.mtx.Unlock() for name, dl := range p.downloaders { - p.logInfo(name, "Stopping bundle downloader.") + p.log(name).Info("Stopping bundle downloader.") dl.Stop(ctx) } } @@ -152,7 +155,7 @@ func (p *Plugin) Reconfigure(ctx context.Context, config interface{}) { // Cleanup existing downloaders that are deleted for name := range p.downloaders { if _, deleted := deletedBundles[name]; deleted { - p.logInfo(name, "Bundle downloader configuration removed. Stopping bundle downloader.") + p.log(name).Info("Bundle downloader configuration removed. Stopping bundle downloader.") delete(p.downloaders, name) delete(p.status, name) delete(p.etags, name) @@ -171,7 +174,7 @@ func (p *Plugin) Reconfigure(ctx context.Context, config interface{}) { } err := bundle.Deactivate(opts) if err != nil { - p.logError(fmt.Sprint(deletedBundles), "Failed to deactivate bundles: %s", err) + p.manager.Logger().Error(fmt.Sprint(deletedBundles), "Failed to deactivate bundles: %s", err) return err } return nil @@ -191,9 +194,9 @@ func (p *Plugin) Reconfigure(ctx context.Context, config interface{}) { if isNew || updated { if isNew { p.status[name] = &Status{Name: name} - p.logInfo(name, "New bundle downloader configuration added. Starting bundle downloader.") + p.log(name).Info("New bundle downloader configuration added. Starting bundle downloader.") } else { - p.logInfo(name, "Bundle downloader configuration changed. Restarting bundle downloader.") + p.log(name).Info("Bundle downloader configuration changed. Restarting bundle downloader.") } p.downloaders[name] = p.newDownloader(name, source) p.downloaders[name].Start(ctx) @@ -267,7 +270,7 @@ func (p *Plugin) loadAndActivateBundlesFromDisk(ctx context.Context) error { if p.persistBundle(name) { b, err := loadBundleFromDisk(p.bundlePersistPath, name, src) if err != nil { - p.logError(name, "Failed to load bundle from disk: %v", err) + p.log(name).Error("Failed to load bundle from disk: %v", err) return err } @@ -279,7 +282,7 @@ func (p *Plugin) loadAndActivateBundlesFromDisk(ctx context.Context) error { err = p.activate(ctx, name, b) if err != nil { - p.logError(name, "Bundle activation failed: %v", err) + p.log(name).Error("Bundle activation failed: %v", err) return err } @@ -288,7 +291,7 @@ func (p *Plugin) loadAndActivateBundlesFromDisk(ctx context.Context) error { p.checkPluginReadiness() - p.logDebug(name, "Bundle loaded from disk and activated successfully.") + p.log(name).Debug("Bundle loaded from disk and activated successfully.") } } return nil @@ -342,7 +345,7 @@ func (p *Plugin) process(ctx context.Context, name string, u download.Update) { p.status[name].SetRequest() if u.Error != nil { - p.logError(name, "Bundle download failed: %v", u.Error) + p.log(name).Error("Bundle download failed: %v", u.Error) p.status[name].SetError(u.Error) p.downloaders[name].ClearCache() return @@ -357,32 +360,32 @@ func (p *Plugin) process(ctx context.Context, name string, u download.Update) { defer p.status[name].Metrics.Timer(metrics.RegoLoadBundles).Stop() if err := p.activate(ctx, name, u.Bundle); err != nil { - p.logError(name, "Bundle activation failed: %v", err) + p.log(name).Error("Bundle activation failed: %v", err) p.status[name].SetError(err) p.downloaders[name].ClearCache() return } if p.persistBundle(name) { - p.logDebug(name, "Persisting bundle to disk in progress.") + p.log(name).Debug("Persisting bundle to disk in progress.") err := p.saveBundleToDisk(name, u.Bundle) if err != nil { - p.logError(name, "Persisting bundle to disk failed: %v", err) + p.log(name).Error("Persisting bundle to disk failed: %v", err) p.status[name].SetError(err) p.downloaders[name].ClearCache() return } - p.logDebug(name, "Bundle persisted to disk successfully at path %v.", filepath.Join(p.bundlePersistPath, name)) + p.log(name).Debug("Bundle persisted to disk successfully at path %v.", filepath.Join(p.bundlePersistPath, name)) } p.status[name].SetError(nil) p.status[name].SetActivateSuccess(u.Bundle.Manifest.Revision) if u.ETag != "" { - p.logInfo(name, "Bundle downloaded and activated successfully. Etag updated to %v.", u.ETag) + p.log(name).Info("Bundle downloaded and activated successfully. Etag updated to %v.", u.ETag) } else { - p.logInfo(name, "Bundle downloaded and activated successfully.") + p.log(name).Info("Bundle downloaded and activated successfully.") } p.etags[name] = u.ETag @@ -392,7 +395,7 @@ func (p *Plugin) process(ctx context.Context, name string, u download.Update) { } if etag, ok := p.etags[name]; ok && u.ETag == etag { - p.logDebug(name, "Bundle download skipped, server replied with not modified.") + p.log(name).Debug("Bundle download skipped, server replied with not modified.") p.status[name].SetError(nil) return } @@ -416,14 +419,14 @@ func (p *Plugin) checkPluginReadiness() { } func (p *Plugin) activate(ctx context.Context, name string, b *bundle.Bundle) error { - p.logDebug(name, "Bundle activation in progress. Opening storage transaction.") + p.log(name).Debug("Bundle activation in progress. Opening storage transaction.") params := storage.WriteParams params.Context = storage.NewContext() err := storage.Txn(ctx, p.manager.Store, params, func(txn storage.Transaction) error { - p.logDebug(name, "Opened storage transaction (%v).", txn.ID()) - defer p.logDebug(name, "Closing storage transaction (%v).", txn.ID()) + p.log(name).Debug("Opened storage transaction (%v).", txn.ID()) + defer p.log(name).Debug("Closing storage transaction (%v).", txn.ID()) // Compile the bundle modules with a new compiler and set it on the // transaction params for use by onCommit hooks. @@ -471,32 +474,6 @@ func (p *Plugin) persistBundle(name string) bool { return bundleSrc.Persist } -func (p *Plugin) logError(bundleName string, fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields(bundleName)).Errorf(fmt, a...) -} - -func (p *Plugin) logInfo(bundleName string, fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields(bundleName)).Infof(fmt, a...) -} - -func (p *Plugin) logDebug(bundleName string, fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields(bundleName)).Debugf(fmt, a...) -} - -func (p *Plugin) logWarn(bundleName string, fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields(bundleName)).Warnf(fmt, a...) -} - -func (p *Plugin) logrusFields(bundleName string) logrus.Fields { - - f := logrus.Fields{ - "plugin": Name, - "name": bundleName, - } - - return f -} - // configDelta will return a map of new bundle sources, updated bundle sources, and a set of deleted bundle names func (p *Plugin) configDelta(newConfig *Config) (map[string]*Source, map[string]*Source, map[string]struct{}) { deletedBundles := map[string]struct{}{} @@ -528,14 +505,14 @@ func (p *Plugin) saveBundleToDisk(name string, b *bundle.Bundle) error { saveErr := saveCurrentBundleToDisk(bundleDir, ".bundle.tar.gz.tmp", b) if saveErr != nil { - p.logWarn(name, "Failed to save new bundle to disk: %v", saveErr) + p.log(name).Error("Failed to save new bundle to disk: %v", saveErr) if err := os.Remove(tmpFile); err != nil { - p.logWarn(name, "Failed to remove temp file ('%s'): %v", tmpFile, err) + p.log(name).Warn("Failed to remove temp file ('%s'): %v", tmpFile, err) } if _, err := os.Stat(bundleFile); err == nil { - p.logWarn(name, "Older version of activated bundle persisted, ignoring error") + p.log(name).Warn("Older version of activated bundle persisted, ignoring error") return nil } return saveErr @@ -593,6 +570,13 @@ func loadBundleFromDisk(path, name string, src *Source) (*bundle.Bundle, error) } } +func (p *Plugin) log(name string) sdk.Logger { + if p.logger == nil { + p.logger = sdk.NewStandardLogger() + } + return p.logger.WithFields(map[string]interface{}{"name": name, "plugin": Name}) +} + func (p *Plugin) getBundlePersistPath() (string, error) { persistDir, err := p.manager.Config.GetPersistenceDirectory() if err != nil { diff --git a/plugins/bundle/plugin_test.go b/plugins/bundle/plugin_test.go index 1e4d810d44..fb3c5b201e 100644 --- a/plugins/bundle/plugin_test.go +++ b/plugins/bundle/plugin_test.go @@ -20,12 +20,11 @@ import ( "testing" "time" - "github.com/open-policy-agent/opa/keys" - "github.com/open-policy-agent/opa/ast" "github.com/open-policy-agent/opa/bundle" "github.com/open-policy-agent/opa/config" "github.com/open-policy-agent/opa/download" + "github.com/open-policy-agent/opa/keys" "github.com/open-policy-agent/opa/metrics" "github.com/open-policy-agent/opa/plugins" "github.com/open-policy-agent/opa/storage" @@ -50,7 +49,7 @@ func TestPluginOneShot(t *testing.T) { Manifest: bundle.Manifest{Revision: "quickbrownfaux"}, Data: util.MustUnmarshalJSON([]byte(`{"foo": {"bar": 1, "baz": "qux"}}`)).(map[string]interface{}), Modules: []bundle.ModuleFile{ - bundle.ModuleFile{ + { Path: "/foo/bar", Parsed: ast.MustParseModule(module), Raw: []byte(module), @@ -526,7 +525,12 @@ func TestPluginOneShotActivationConflictingRoots(t *testing.T) { func TestPluginOneShotActivationPrefixMatchingRoots(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleNames := []string{"test-bundle1", "test-bundle2"} for _, name := range bundleNames { @@ -680,7 +684,12 @@ func validateStatus(t *testing.T, actual Status, expected string, expectStatusEr func TestPluginListenerErrorClearedOn304(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleName := "test-bundle" plugin.status[bundleName] = &Status{Name: bundleName} plugin.downloaders[bundleName] = download.New(download.Config{}, plugin.manager.Client(""), bundleName) @@ -727,7 +736,12 @@ func TestPluginListenerErrorClearedOn304(t *testing.T) { func TestPluginBulkListener(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleNames := []string{ "b1", "b2", @@ -910,7 +924,12 @@ func TestPluginBulkListener(t *testing.T) { func TestPluginBulkListenerStatusCopyOnly(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleNames := []string{ "b1", "b2", @@ -962,7 +981,12 @@ func TestPluginActivateScopedBundle(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleName := "test-bundle" plugin.status[bundleName] = &Status{Name: bundleName} plugin.downloaders[bundleName] = download.New(download.Config{}, plugin.manager.Client(""), bundleName) @@ -1080,7 +1104,12 @@ func TestPluginSetCompilerOnContext(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleName := "test-bundle" plugin.status[bundleName] = &Status{Name: bundleName} plugin.downloaders[bundleName] = download.New(download.Config{}, plugin.manager.Client(""), bundleName) @@ -1340,7 +1369,12 @@ func TestPluginRequestVsDownloadTimestamp(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleName := "test-bundle" plugin.status[bundleName] = &Status{Name: bundleName} plugin.downloaders[bundleName] = download.New(download.Config{}, plugin.manager.Client(""), bundleName) @@ -1384,7 +1418,12 @@ func TestUpgradeLegacyBundleToMuiltiBundleSameBundle(t *testing.T) { ctx := context.Background() manager := getTestManager() - plugin := Plugin{manager: manager, status: map[string]*Status{}, etags: map[string]string{}, downloaders: map[string]*download.Downloader{}} + plugin := Plugin{ + manager: manager, + status: map[string]*Status{}, + etags: map[string]string{}, + downloaders: map[string]*download.Downloader{}, + } bundleName := "test-bundle" plugin.status[bundleName] = &Status{Name: bundleName} plugin.downloaders[bundleName] = download.New(download.Config{}, plugin.manager.Client(""), bundleName) diff --git a/plugins/discovery/discovery.go b/plugins/discovery/discovery.go index e068c559a4..6984b98b0f 100644 --- a/plugins/discovery/discovery.go +++ b/plugins/discovery/discovery.go @@ -11,7 +11,7 @@ import ( "fmt" "sync" - "github.com/sirupsen/logrus" + "github.com/open-policy-agent/opa/sdk" "github.com/open-policy-agent/opa/ast" bundleApi "github.com/open-policy-agent/opa/bundle" @@ -43,6 +43,7 @@ type Discovery struct { etag string // discovery bundle etag for caching purposes metrics metrics.Metrics readyOnce sync.Once + logger sdk.Logger } // Factories provides a set of factory functions to use for @@ -62,7 +63,6 @@ func Metrics(m metrics.Metrics) func(*Discovery) { // New returns a new discovery plugin. func New(manager *plugins.Manager, opts ...func(*Discovery)) (*Discovery, error) { - result := &Discovery{ manager: manager, } @@ -94,6 +94,8 @@ func New(manager *plugins.Manager, opts ...func(*Discovery)) (*Discovery, error) Name: *config.Name, } + result.logger = manager.Logger().WithFields(map[string]interface{}{"name": *config.Name, "plugin": Name}) + manager.UpdatePluginStatus(Name, &plugins.Status{State: plugins.StateNotReady}) return result, nil } @@ -136,7 +138,7 @@ func (c *Discovery) processUpdate(ctx context.Context, u download.Update) { c.status.SetRequest() if u.Error != nil { - c.logError("Discovery download failed: %v", u.Error) + c.logger.Error("Discovery download failed: %v", u.Error) c.status.SetError(u.Error) c.downloader.ClearCache() return @@ -148,7 +150,7 @@ func (c *Discovery) processUpdate(ctx context.Context, u download.Update) { c.status.LastSuccessfulDownload = c.status.LastSuccessfulRequest if err := c.reconfigure(ctx, u); err != nil { - c.logError("Discovery reconfiguration error occurred: %v", err) + c.logger.Error("Discovery reconfiguration error occurred: %v", err) c.status.SetError(err) c.downloader.ClearCache() return @@ -163,16 +165,16 @@ func (c *Discovery) processUpdate(ctx context.Context, u download.Update) { }) if u.ETag != "" { - c.logInfo("Discovery update processed successfully. Etag updated to %v.", u.ETag) + c.logger.Info("Discovery update processed successfully. Etag updated to %v.", u.ETag) } else { - c.logInfo("Discovery update processed successfully.") + c.logger.Info("Discovery update processed successfully.") } c.etag = u.ETag return } if u.ETag == c.etag { - c.logDebug("Discovery update skipped, server replied with not modified.") + c.logger.Debug("Discovery update skipped, server replied with not modified.") c.status.SetError(nil) return } @@ -198,25 +200,6 @@ func (c *Discovery) reconfigure(ctx context.Context, u download.Update) error { return nil } -func (c *Discovery) logError(fmt string, a ...interface{}) { - logrus.WithFields(c.logrusFields()).Errorf(fmt, a...) -} - -func (c *Discovery) logInfo(fmt string, a ...interface{}) { - logrus.WithFields(c.logrusFields()).Infof(fmt, a...) -} - -func (c *Discovery) logDebug(fmt string, a ...interface{}) { - logrus.WithFields(c.logrusFields()).Debugf(fmt, a...) -} - -func (c *Discovery) logrusFields() logrus.Fields { - return logrus.Fields{ - "name": *c.config.Name, - "plugin": "discovery", - } -} - func (c *Discovery) processBundle(ctx context.Context, b *bundleApi.Bundle) (*pluginSet, error) { config, err := evaluateBundle(ctx, c.manager.ID, c.manager.Info, b, c.config.query) @@ -233,6 +216,7 @@ func (c *Discovery) processBundle(ctx context.Context, b *bundleApi.Bundle) (*pl Raw: config.Services, AuthPlugin: c.manager.AuthPlugin, Keys: c.manager.PublicKeys(), + Logger: c.logger.WithFields(c.manager.Client(c.config.service).Logger().GetFields()), } services, err := cfg.ParseServicesConfig(opts) if err != nil { @@ -358,6 +342,8 @@ func getPluginSet(factories map[string]plugins.Factory, manager *plugins.Manager if err != nil { return nil, err } + } else { + manager.Logger().Warn("Deprecated 'bundle' configuration specified. Use 'bundles' instead. See https://www.openpolicyagent.org/docs/latest/configuration/#bundles") } decisionLogsConfig, err := logs.ParseConfig(config.DecisionLogs, manager.Services(), pluginNames) diff --git a/plugins/logs/plugin.go b/plugins/logs/plugin.go index fbffe7ec6b..fadc301d53 100644 --- a/plugins/logs/plugin.go +++ b/plugins/logs/plugin.go @@ -16,8 +16,9 @@ import ( "sync" "time" + "github.com/open-policy-agent/opa/sdk" + "github.com/pkg/errors" - "github.com/sirupsen/logrus" "github.com/open-policy-agent/opa/ast" "github.com/open-policy-agent/opa/internal/ref" @@ -334,6 +335,7 @@ type Plugin struct { reconfig chan reconfigure mask *rego.PreparedEvalQuery maskMutex sync.Mutex + logger sdk.Logger } type reconfigure struct { @@ -370,6 +372,7 @@ func New(parsedConfig *Config, manager *plugins.Manager) *Plugin { buffer: newLogBuffer(*parsedConfig.Reporting.BufferSizeLimitBytes), enc: newChunkEncoder(*parsedConfig.Reporting.UploadSizeLimitBytes), reconfig: make(chan reconfigure), + logger: manager.Logger().WithFields(map[string]interface{}{"plugin": Name}), } manager.RegisterCompilerTrigger(plugin.compilerUpdated) @@ -392,7 +395,7 @@ func Lookup(manager *plugins.Manager) *Plugin { // Start starts the plugin. func (p *Plugin) Start(ctx context.Context) error { - p.logInfo("Starting decision logger.") + p.logger.Info("Starting decision logger.") go p.loop() p.manager.UpdatePluginStatus(Name, &plugins.Status{State: plugins.StateOK}) return nil @@ -400,7 +403,7 @@ func (p *Plugin) Start(ctx context.Context) error { // Stop stops the plugin. func (p *Plugin) Stop(ctx context.Context) { - p.logInfo("Stopping decision logger.") + p.logger.Info("Stopping decision logger.") if _, ok := ctx.Deadline(); ok && p.config.Service != "" { p.flushDecisions(ctx) @@ -413,14 +416,14 @@ func (p *Plugin) Stop(ctx context.Context) { } func (p *Plugin) flushDecisions(ctx context.Context) { - p.logInfo("Flushing decision logs.") + p.logger.Info("Flushing decision logs.") done := make(chan bool) go func(ctx context.Context, done chan bool) { for ctx.Err() == nil { if _, err := p.oneShot(ctx); err != nil { - p.logError("Error flushing decisions: %s", err) + p.logger.Error("Error flushing decisions: %s", err) // Wait some before retrying, but skip incrementing interval since we are shutting down time.Sleep(1 * time.Second) } else { @@ -432,11 +435,11 @@ func (p *Plugin) flushDecisions(ctx context.Context) { select { case <-done: - p.logInfo("All decisions in buffer uploaded.") + p.logger.Info("All decisions in buffer uploaded.") case <-ctx.Done(): switch ctx.Err() { case context.DeadlineExceeded, context.Canceled: - p.logError("Plugin stopped with decisions possibly still in buffer.") + p.logger.Error("Plugin stopped with decisions possibly still in buffer.") } } } @@ -474,14 +477,14 @@ func (p *Plugin) Log(ctx context.Context, decision *server.Info) error { err := p.maskEvent(ctx, decision.Txn, &event) if err != nil { // TODO(tsandall): see note below about error handling. - p.logError("Log event masking failed: %v.", err) + p.logger.Error("Log event masking failed: %v.", err) return nil } if p.config.ConsoleLogs { err := p.logEvent(event) if err != nil { - p.logError("Failed to log to console: %v.", err) + p.logger.Error("Failed to log to console: %v.", err) } } @@ -502,7 +505,7 @@ func (p *Plugin) Log(ctx context.Context, decision *server.Info) error { // TODO(tsandall): revisit this now that we have an API that // can return an error. Should the default behaviour be to // fail-closed as we do for plugins? - p.logError("Log encoding failed: %v.", err) + p.logger.Error("Log encoding failed: %v.", err) return nil } @@ -550,11 +553,11 @@ func (p *Plugin) loop() { uploaded, err = p.oneShot(ctx) if err != nil { - p.logError("%v.", err) + p.logger.Error("%v.", err) } else if uploaded { - p.logInfo("Logs uploaded successfully.") + p.logger.Info("Logs uploaded successfully.") } else { - p.logInfo("Log upload skipped.") + p.logger.Info("Log upload skipped.") } } @@ -569,7 +572,7 @@ func (p *Plugin) loop() { } if p.config.Service != "" { - p.logDebug("Waiting %v before next upload/retry.", delay) + p.logger.Debug("Waiting %v before next upload/retry.", delay) } timer := time.NewTimer(delay) @@ -638,18 +641,18 @@ func (p *Plugin) reconfigure(config interface{}) { newConfig := config.(*Config) if reflect.DeepEqual(p.config, *newConfig) { - p.logDebug("Decision log uploader configuration unchanged.") + p.logger.Debug("Decision log uploader configuration unchanged.") return } - p.logInfo("Decision log uploader configuration changed.") + p.logger.Info("Decision log uploader configuration changed.") p.config = *newConfig } func (p *Plugin) bufferChunk(buffer *logBuffer, bs []byte) { dropped := buffer.Push(bs) if dropped > 0 { - p.logError("Dropped %v chunks from buffer. Reduce reporting interval or increase buffer size.", dropped) + p.logger.Error("Dropped %v chunks from buffer. Reduce reporting interval or increase buffer size.", dropped) } } @@ -707,7 +710,7 @@ func (p *Plugin) maskEvent(ctx context.Context, txn storage.Transaction, event * mRuleSet, err := newMaskRuleSet( rs[0].Expressions[0].Value, func(mRule *maskRule, err error) { - p.logError("mask rule skipped: %s: %s", mRule.String(), err.Error()) + p.logger.Error("mask rule skipped: %s: %s", mRule.String(), err.Error()) }, ) if err != nil { @@ -745,35 +748,17 @@ func uploadChunk(ctx context.Context, client rest.Client, partitionName string, } } -func (p *Plugin) logError(fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields()).Errorf(fmt, a...) -} - -func (p *Plugin) logInfo(fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields()).Infof(fmt, a...) -} - -func (p *Plugin) logDebug(fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields()).Debugf(fmt, a...) -} - -func (p *Plugin) logrusFields() logrus.Fields { - return logrus.Fields{ - "plugin": Name, - } -} - func (p *Plugin) logEvent(event EventV1) error { eventBuf, err := json.Marshal(&event) if err != nil { return err } - fields := logrus.Fields{} + fields := map[string]interface{}{} err = util.UnmarshalJSON(eventBuf, &fields) if err != nil { return err } - plugins.GetConsoleLogger().WithFields(fields).WithFields(logrus.Fields{ + plugins.GetConsoleLogger().WithFields(fields).WithFields(map[string]interface{}{ "type": "openpolicyagent.org/decision_logs", }).Info("Decision Log") return nil diff --git a/plugins/plugins.go b/plugins/plugins.go index 0513e62070..0a8c7da56f 100644 --- a/plugins/plugins.go +++ b/plugins/plugins.go @@ -11,6 +11,8 @@ import ( "sync" "time" + "github.com/open-policy-agent/opa/sdk" + "github.com/open-policy-agent/opa/keys" "github.com/sirupsen/logrus" @@ -156,6 +158,7 @@ type Manager struct { interQueryBuiltinCacheConfig *cache.Config gracefulShutdownPeriod int registeredCacheTriggers []func(*cache.Config) + logger sdk.Logger } type managerContextKey string @@ -292,6 +295,10 @@ func New(raw []byte, id string, store storage.Store, opts ...func(*Manager)) (*M f(m) } + if m.logger == nil { + m.logger = sdk.NewStandardLogger() + } + return m, nil } @@ -727,6 +734,11 @@ func (m *Manager) Services() []string { return s } +// Logger gets the logger implementation associated with this plugin manager +func (m *Manager) Logger() sdk.Logger { + return m.logger +} + // RegisterCacheTrigger accepts a func that receives new inter-query cache config generated by // a reconfigure of the plugin manager, so that it can be propagated to existing inter-query caches. func (m *Manager) RegisterCacheTrigger(trigger func(*cache.Config)) { diff --git a/plugins/rest/aws.go b/plugins/rest/aws.go index bbfe769de8..52a73345cf 100644 --- a/plugins/rest/aws.go +++ b/plugins/rest/aws.go @@ -19,7 +19,7 @@ import ( "strings" "time" - "github.com/sirupsen/logrus" + "github.com/open-policy-agent/opa/sdk" ) const ( @@ -61,7 +61,9 @@ type awsCredentialService interface { } // awsEnvironmentCredentialService represents an static environment-variable credential provider for AWS -type awsEnvironmentCredentialService struct{} +type awsEnvironmentCredentialService struct { + logger sdk.Logger +} func (cs *awsEnvironmentCredentialService) credentials() (awsCredentials, error) { var creds awsCredentials @@ -97,6 +99,7 @@ type awsMetadataCredentialService struct { expiration time.Time credServicePath string tokenPath string + logger sdk.Logger } func (cs *awsMetadataCredentialService) urlForMetadataService() (string, error) { @@ -148,11 +151,11 @@ func (cs *awsMetadataCredentialService) refreshFromService() error { // short circuit if a reasonable amount of time until credential expiration remains if time.Now().Add(time.Minute * 5).Before(cs.expiration) { - logrus.Debug("Credentials previously obtained from metadata service still valid.") + cs.logger.Debug("Credentials previously obtained from metadata service still valid.") return nil } - logrus.Debug("Obtaining credentials from metadata service.") + cs.logger.Debug("Obtaining credentials from metadata service.") metaDataURL, err := cs.urlForMetadataService() if err != nil { // configuration issue or missing ECS environment @@ -174,7 +177,7 @@ func (cs *awsMetadataCredentialService) refreshFromService() error { if err != nil { return errors.New("unable to construct metadata token HTTP request: " + err.Error()) } - body, err := doMetaDataRequestWithClient(tokenReq, client, "metadata token") + body, err := doMetaDataRequestWithClient(tokenReq, client, "metadata token", cs.logger) if err != nil { return err } @@ -182,7 +185,7 @@ func (cs *awsMetadataCredentialService) refreshFromService() error { req.Header.Set("X-aws-ec2-metadata-token", string(body)) } - body, err := doMetaDataRequestWithClient(req, client, "metadata") + body, err := doMetaDataRequestWithClient(req, client, "metadata", cs.logger) if err != nil { return err } @@ -226,6 +229,7 @@ type awsWebIdentityCredentialService struct { stsURL string creds awsCredentials expiration time.Time + logger sdk.Logger } func (cs *awsWebIdentityCredentialService) populateFromEnv() error { @@ -275,11 +279,11 @@ func (cs *awsWebIdentityCredentialService) refreshFromService() error { // short circuit if a reasonable amount of time until credential expiration remains if time.Now().Add(time.Minute * 5).Before(cs.expiration) { - logrus.Debug("Credentials previously obtained from sts service still valid.") + cs.logger.Debug("Credentials previously obtained from sts service still valid.") return nil } - logrus.Debugf("Obtaining credentials from sts for role %s.", cs.RoleArn) + cs.logger.Debug("Obtaining credentials from sts for role %s.", cs.RoleArn) var sessionName string if cs.SessionName == "" { @@ -312,7 +316,7 @@ func (cs *awsWebIdentityCredentialService) refreshFromService() error { return errors.New("unable to construct STS HTTP request: " + err.Error()) } - body, err := doMetaDataRequestWithClient(req, client, "STS") + body, err := doMetaDataRequestWithClient(req, client, "STS", cs.logger) if err != nil { return err } @@ -346,7 +350,7 @@ func isECS() bool { return isECS } -func doMetaDataRequestWithClient(req *http.Request, client *http.Client, desc string) ([]byte, error) { +func doMetaDataRequestWithClient(req *http.Request, client *http.Client, desc string, logger sdk.Logger) ([]byte, error) { // convenience function to get the body of an AWS EC2 metadata service request with // appropriate error-handling boilerplate and logging for this special case resp, err := client.Do(req) @@ -356,7 +360,7 @@ func doMetaDataRequestWithClient(req *http.Request, client *http.Client, desc st } defer resp.Body.Close() - logrus.WithFields(logrus.Fields{ + logger.WithFields(map[string]interface{}{ "url": req.URL.String(), "status": resp.Status, "headers": resp.Header, diff --git a/plugins/rest/aws_test.go b/plugins/rest/aws_test.go index db14d301e2..c9c6a6c728 100644 --- a/plugins/rest/aws_test.go +++ b/plugins/rest/aws_test.go @@ -14,6 +14,8 @@ import ( "strings" "testing" "time" + + "github.com/open-policy-agent/opa/sdk" ) // this is usually private; but we need it here @@ -106,14 +108,18 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_iam_role", RegionName: "us-east-1", credServicePath: "this is not a URL", // malformed - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } _, err := cs.credentials() assertErr("unsupported protocol scheme \"\"", err, t) // wrong path: no role set but no ECS URI in environment os.Unsetenv(ecsRelativePathEnvVar) cs = awsMetadataCredentialService{ - RegionName: "us-east-1"} + RegionName: "us-east-1", + logger: sdk.NewStandardLogger(), + } _, err = cs.credentials() assertErr("metadata endpoint cannot be determined from settings and environment", err, t) @@ -122,7 +128,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "not_my_iam_role", // not present RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } _, err = cs.credentials() assertErr("metadata HTTP request returned unexpected status: 404 Not Found", err, t) @@ -131,7 +139,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_bad_iam_role", // not good RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } _, err = cs.credentials() assertErr("failed to parse credential response from metadata service: invalid character 'T' looking for beginning of value", err, t) @@ -140,7 +150,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_iam_role", RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/missing_token"} // will 404 + tokenPath: ts.server.URL + "/latest/api/missing_token", + logger: sdk.NewStandardLogger(), + } // will 404 _, err = cs.credentials() assertErr("metadata token HTTP request returned unexpected status: 404 Not Found", err, t) @@ -149,7 +161,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_iam_role", RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/bad_token"} // not good + tokenPath: ts.server.URL + "/latest/api/bad_token", + logger: sdk.NewStandardLogger(), + } // not good _, err = cs.credentials() assertErr("metadata HTTP request returned unexpected status: 401 Unauthorized", err, t) @@ -164,7 +178,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_iam_role", RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } _, err = cs.credentials() assertErr("metadata service query did not succeed: Failure", err, t) @@ -179,7 +195,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_iam_role", RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } var creds awsCredentials creds, err = cs.credentials() @@ -203,7 +221,9 @@ func TestMetadataCredentialService(t *testing.T) { RoleName: "my_iam_role", RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } ts.payload = metadataPayload{ AccessKeyID: "MYAWSACCESSKEYGOESHERE", SecretAccessKey: "MYAWSSECRETACCESSKEYGOESHERE", @@ -247,7 +267,9 @@ func TestV4Signing(t *testing.T) { RoleName: "not_my_iam_role", // not present RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } req, _ := http.NewRequest("GET", "https://mybucket.s3.amazonaws.com/bundle.tar.gz", strings.NewReader("")) err := signV4(req, cs, time.Unix(1556129697, 0)) @@ -258,7 +280,9 @@ func TestV4Signing(t *testing.T) { RoleName: "my_iam_role", // not present RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } ts.payload = metadataPayload{ AccessKeyID: "MYAWSACCESSKEYGOESHERE", SecretAccessKey: "MYAWSSECRETACCESSKEYGOESHERE", @@ -293,7 +317,9 @@ func TestV4SigningCustomPort(t *testing.T) { RoleName: "my_iam_role", // not present RegionName: "us-east-1", credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/", - tokenPath: ts.server.URL + "/latest/api/token"} + tokenPath: ts.server.URL + "/latest/api/token", + logger: sdk.NewStandardLogger(), + } ts.payload = metadataPayload{ AccessKeyID: "MYAWSACCESSKEYGOESHERE", SecretAccessKey: "MYAWSSECRETACCESSKEYGOESHERE", @@ -385,6 +411,7 @@ func TestWebIdentityCredentialService(t *testing.T) { defer ts.stop() cs := awsWebIdentityCredentialService{ stsURL: ts.server.URL, + logger: sdk.NewStandardLogger(), } goodTokenFile, err := ioutil.TempFile(os.TempDir(), "opa-aws-test-") diff --git a/plugins/rest/rest.go b/plugins/rest/rest.go index 1ac3a9a090..c372fba044 100644 --- a/plugins/rest/rest.go +++ b/plugins/rest/rest.go @@ -15,12 +15,12 @@ import ( "reflect" "strings" + "github.com/open-policy-agent/opa/sdk" + "github.com/open-policy-agent/opa/keys" "github.com/open-policy-agent/opa/internal/version" - "github.com/sirupsen/logrus" - "github.com/open-policy-agent/opa/util" ) @@ -51,7 +51,8 @@ type Config struct { Plugin *string `json:"plugin,omitempty"` } `json:"credentials"` - keys map[string]*keys.Config + keys map[string]*keys.Config + logger sdk.Logger } // Equal returns true if this client config is equal to the other. @@ -108,6 +109,7 @@ type Client struct { config Config headers map[string]string authPluginLookup func(string) HTTPAuthPlugin + logger sdk.Logger } // Name returns an option that overrides the service name on the client. @@ -127,6 +129,13 @@ func AuthPluginLookup(l func(string) HTTPAuthPlugin) func(*Client) { } } +// Logger assigns a logger to the client +func Logger(l sdk.Logger) func(*Client) { + return func(c *Client) { + c.logger = l + } +} + // New returns a new Client for config. func New(config []byte, keys map[string]*keys.Config, opts ...func(*Client)) (Client, error) { var parsedConfig Config @@ -153,6 +162,11 @@ func New(config []byte, keys map[string]*keys.Config, opts ...func(*Client)) (Cl f(&client) } + if client.logger == nil { + client.logger = sdk.NewStandardLogger() + } + client.config.logger = client.logger + return client, nil } @@ -166,6 +180,11 @@ func (c Client) Config() *Config { return &c.config } +// Logger returns the logger assigned to the Client +func (c Client) Logger() sdk.Logger { + return c.logger +} + // WithHeader returns a shallow copy of the client with a header to include the // requests. func (c Client) WithHeader(k, v string) Client { @@ -249,7 +268,7 @@ func (c Client) Do(ctx context.Context, method, path string) (*http.Response, er return nil, err } - logrus.WithFields(logrus.Fields{ + c.logger.WithFields(map[string]interface{}{ "method": method, "url": url, "headers": req.Header, @@ -259,7 +278,7 @@ func (c Client) Do(ctx context.Context, method, path string) (*http.Response, er if resp != nil { // Only log for debug purposes. If an error occurred, the caller should handle // that. In the non-error case, the caller may not do anything. - logrus.WithFields(logrus.Fields{ + c.logger.WithFields(map[string]interface{}{ "method": method, "url": url, "status": resp.Status, diff --git a/plugins/rest/rest_auth.go b/plugins/rest/rest_auth.go index 901f61cd70..24c2fdecdd 100644 --- a/plugins/rest/rest_auth.go +++ b/plugins/rest/rest_auth.go @@ -25,8 +25,7 @@ import ( "github.com/open-policy-agent/opa/internal/jwx/jws" "github.com/open-policy-agent/opa/internal/uuid" "github.com/open-policy-agent/opa/keys" - - "github.com/sirupsen/logrus" + "github.com/open-policy-agent/opa/sdk" ) // DefaultTLSConfig defines standard TLS configurations based on the Config @@ -134,6 +133,7 @@ type oauth2ClientCredentialsAuthPlugin struct { signingKeyParsed interface{} tokenCache *oauth2Token tlsSkipVerify bool + logger sdk.Logger } type oauth2Token struct { @@ -226,6 +226,8 @@ func (ap *oauth2ClientCredentialsAuthPlugin) NewClient(c Config) (*http.Client, // Inherit skip verify from the "parent" settings. Should this be configurable on the credentials too? ap.tlsSkipVerify = c.AllowInsureTLS + ap.logger = c.logger + if !strings.HasPrefix(ap.TokenURL, "https://") { return nil, errors.New("token_url required to use https scheme") } @@ -319,7 +321,7 @@ func (ap *oauth2ClientCredentialsAuthPlugin) requestToken() (*oauth2Token, error func (ap *oauth2ClientCredentialsAuthPlugin) Prepare(req *http.Request) error { minTokenLifetime := float64(10) if ap.tokenCache == nil || ap.tokenCache.ExpiresAt.Sub(time.Now()).Seconds() < minTokenLifetime { - logrus.Debugf("Requesting token from token_url %v", ap.TokenURL) + ap.logger.Debug("Requesting token from token_url %v", ap.TokenURL) token, err := ap.requestToken() if err != nil { return err @@ -415,15 +417,20 @@ type awsSigningAuthPlugin struct { AWSEnvironmentCredentials *awsEnvironmentCredentialService `json:"environment_credentials,omitempty"` AWSMetadataCredentials *awsMetadataCredentialService `json:"metadata_credentials,omitempty"` AWSWebIdentityCredentials *awsWebIdentityCredentialService `json:"web_identity_credentials,omitempty"` + + logger sdk.Logger } func (ap *awsSigningAuthPlugin) awsCredentialService() awsCredentialService { if ap.AWSEnvironmentCredentials != nil { + ap.AWSEnvironmentCredentials.logger = ap.logger return ap.AWSEnvironmentCredentials } if ap.AWSWebIdentityCredentials != nil { + ap.AWSWebIdentityCredentials.logger = ap.logger return ap.AWSWebIdentityCredentials } + ap.AWSMetadataCredentials.logger = ap.logger return ap.AWSMetadataCredentials } @@ -456,7 +463,7 @@ func (ap *awsSigningAuthPlugin) NewClient(c Config) (*http.Client, error) { } func (ap *awsSigningAuthPlugin) Prepare(req *http.Request) error { - logrus.Debug("Signing request with AWS credentials.") + ap.logger.Debug("Signing request with AWS credentials.") err := signV4(req, ap.awsCredentialService(), time.Now()) return err } diff --git a/plugins/status/plugin.go b/plugins/status/plugin.go index 2cc1f0c622..144c56b1d9 100644 --- a/plugins/status/plugin.go +++ b/plugins/status/plugin.go @@ -12,6 +12,8 @@ import ( "net/http" "reflect" + "github.com/open-policy-agent/opa/sdk" + "github.com/pkg/errors" "github.com/sirupsen/logrus" @@ -47,6 +49,7 @@ type Plugin struct { metrics metrics.Metrics lastPluginStatuses map[string]*plugins.Status pluginStatusCh chan map[string]*plugins.Status + logger sdk.Logger } // Config contains configuration for the plugin. @@ -118,6 +121,7 @@ func New(parsedConfig *Config, manager *plugins.Manager) *Plugin { stop: make(chan chan struct{}), reconfig: make(chan interface{}), pluginStatusCh: make(chan map[string]*plugins.Status), + logger: manager.Logger().WithFields(map[string]interface{}{"plugin": Name}), } p.manager.UpdatePluginStatus(Name, &plugins.Status{State: plugins.StateNotReady}) @@ -144,7 +148,7 @@ func Lookup(manager *plugins.Manager) *Plugin { // Start starts the plugin. func (p *Plugin) Start(ctx context.Context) error { - p.logInfo("Starting status reporter.") + p.logger.Info("Starting status reporter.") go p.loop() @@ -161,7 +165,7 @@ func (p *Plugin) Start(ctx context.Context) error { // Stop stops the plugin. func (p *Plugin) Stop(ctx context.Context) { - p.logInfo("Stopping status reporter.") + p.logger.Info("Stopping status reporter.") p.manager.UnregisterPluginStatusListener(Name) done := make(chan struct{}) p.stop <- done @@ -205,33 +209,33 @@ func (p *Plugin) loop() { p.lastPluginStatuses = statuses err := p.oneShot(ctx) if err != nil { - p.logError("%v.", err) + p.logger.Error("%v.", err) } else { - p.logInfo("Status update sent successfully in response to plugin update.") + p.logger.Info("Status update sent successfully in response to plugin update.") } case statuses := <-p.bulkBundleCh: p.lastBundleStatuses = statuses err := p.oneShot(ctx) if err != nil { - p.logError("%v.", err) + p.logger.Error("%v.", err) } else { - p.logInfo("Status update sent successfully in response to bundle update.") + p.logger.Info("Status update sent successfully in response to bundle update.") } case status := <-p.bundleCh: p.lastBundleStatus = &status err := p.oneShot(ctx) if err != nil { - p.logError("%v.", err) + p.logger.Error("%v.", err) } else { - p.logInfo("Status update sent successfully in response to bundle update.") + p.logger.Info("Status update sent successfully in response to bundle update.") } case status := <-p.discoCh: p.lastDiscoStatus = &status err := p.oneShot(ctx) if err != nil { - p.logError("%v.", err) + p.logger.Error("%v.", err) } else { - p.logInfo("Status update sent successfully in response to discovery update.") + p.logger.Info("Status update sent successfully in response to discovery update.") } case newConfig := <-p.reconfig: @@ -262,7 +266,7 @@ func (p *Plugin) oneShot(ctx context.Context) error { if p.config.ConsoleLogs { err := p.logUpdate(req) if err != nil { - p.logError("Failed to log to console: %v.", err) + p.logger.Error("Failed to log to console: %v.", err) } } @@ -295,32 +299,14 @@ func (p *Plugin) reconfigure(config interface{}) { newConfig := config.(*Config) if reflect.DeepEqual(p.config, *newConfig) { - p.logDebug("Status reporter configuration unchanged.") + p.logger.Debug("Status reporter configuration unchanged.") return } - p.logInfo("Status reporter configuration changed.") + p.logger.Info("Status reporter configuration changed.") p.config = *newConfig } -func (p *Plugin) logError(fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields()).Errorf(fmt, a...) -} - -func (p *Plugin) logInfo(fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields()).Infof(fmt, a...) -} - -func (p *Plugin) logDebug(fmt string, a ...interface{}) { - logrus.WithFields(p.logrusFields()).Debugf(fmt, a...) -} - -func (p *Plugin) logrusFields() logrus.Fields { - return logrus.Fields{ - "plugin": Name, - } -} - func (p *Plugin) logUpdate(update *UpdateRequestV1) error { eventBuf, err := json.Marshal(&update) if err != nil { diff --git a/runtime/logging.go b/runtime/logging.go index f31402ea87..c2ac2265f8 100644 --- a/runtime/logging.go +++ b/runtime/logging.go @@ -60,7 +60,6 @@ func (h *LoggingHandler) ServeHTTP(w http.ResponseWriter, r *http.Request) { if loggingEnabled(logrus.DebugLevel) { var bs []byte - var err error if r.Body != nil { bs, r.Body, err = readBody(r.Body) } diff --git a/sdk/logging.go b/sdk/logging.go new file mode 100644 index 0000000000..bca6e88d6a --- /dev/null +++ b/sdk/logging.go @@ -0,0 +1,169 @@ +package sdk + +import ( + "github.com/sirupsen/logrus" +) + +// Level log level for Logger +type Level uint8 + +const ( + // Error error log level + Error Level = iota + // Warn warn log level + Warn + // Info info log level + Info + // Debug debug log level + Debug +) + +// Logger provides interface for OPA logger implementations +type Logger interface { + Debug(fmt string, a ...interface{}) + Info(fmt string, a ...interface{}) + Error(fmt string, a ...interface{}) + Warn(fmt string, a ...interface{}) + + WithFields(map[string]interface{}) Logger + GetFields() map[string]interface{} + + GetLevel() Level + SetLevel(Level) +} + +// StandardLogger is the default OPA logger +type StandardLogger struct { + logger *logrus.Logger + fields map[string]interface{} +} + +// NewStandardLogger instantiates new default OPA logger +func NewStandardLogger() *StandardLogger { + return &StandardLogger{ + logger: logrus.StandardLogger(), + } +} + +// WithFields provides additional fields to include in log output +func (l *StandardLogger) WithFields(fields map[string]interface{}) Logger { + cp := *l + cp.fields = fields + return &cp +} + +// GetFields returns additional fields of this logger +func (l *StandardLogger) GetFields() map[string]interface{} { + return l.fields +} + +// SetLevel sets the standard logger level. +func (l *StandardLogger) SetLevel(level Level) { + var logrusLevel logrus.Level + switch level { + case Error: + logrusLevel = logrus.ErrorLevel + case Warn: + logrusLevel = logrus.WarnLevel + case Info: + logrusLevel = logrus.InfoLevel + case Debug: + logrusLevel = logrus.DebugLevel + default: + l.Warn("unknown log level %v", level) + logrusLevel = logrus.InfoLevel + } + + l.logger.SetLevel(logrusLevel) +} + +// GetLevel returns the standard logger level. +func (l *StandardLogger) GetLevel() Level { + logrusLevel := l.logger.GetLevel() + + var level Level + switch logrusLevel { + case logrus.ErrorLevel: + level = Error + case logrus.WarnLevel: + level = Warn + case logrus.InfoLevel: + level = Info + case logrus.DebugLevel: + level = Debug + default: + l.Warn("unknown log level %v", logrusLevel) + level = Info + } + + return level +} + +// Debug logs at debug level +func (l *StandardLogger) Debug(fmt string, a ...interface{}) { + l.logger.WithFields(l.GetFields()).Debugf(fmt, a...) +} + +// Info logs at info level +func (l *StandardLogger) Info(fmt string, a ...interface{}) { + l.logger.WithFields(l.GetFields()).Infof(fmt, a...) +} + +// Error logs at error level +func (l *StandardLogger) Error(fmt string, a ...interface{}) { + l.logger.WithFields(l.GetFields()).Errorf(fmt, a...) +} + +// Warn logs at warn level +func (l *StandardLogger) Warn(fmt string, a ...interface{}) { + l.logger.WithFields(l.GetFields()).Errorf(fmt, a...) +} + +// NoOpLogger logging implementation that does nothing +type NoOpLogger struct { + level Level + fields map[string]interface{} +} + +// NewNoOpLogger instantiates new NoOpLogger +func NewNoOpLogger() *NoOpLogger { + return &NoOpLogger{ + level: Info, + } +} + +// WithFields provides additional fields to include in log output. +// Implemented here primarily to be able to switch between implementations without loss of data. +func (l *NoOpLogger) WithFields(fields map[string]interface{}) Logger { + cp := *l + cp.fields = fields + return &cp +} + +// GetFields returns additional fields of this logger +// Implemented here primarily to be able to switch between implementations without loss of data. +func (l *NoOpLogger) GetFields() map[string]interface{} { + return l.fields +} + +// Debug noop +func (*NoOpLogger) Debug(string, ...interface{}) {} + +// Info noop +func (*NoOpLogger) Info(string, ...interface{}) {} + +// Error noop +func (*NoOpLogger) Error(string, ...interface{}) {} + +// Warn noop +func (*NoOpLogger) Warn(string, ...interface{}) {} + +// SetLevel set log level +func (l *NoOpLogger) SetLevel(level Level) { + l.level = level +} + +// GetLevel get log level +func (l *NoOpLogger) GetLevel() Level { + return l.level +}