ewilliams28/releases
1
0
Fork 0
mirror of https://github.com/open-policy-agent/opa.git synced 2026-08-12 19:32:48 -06:00
Code Issues Packages Projects Releases Wiki Activity

logging: Move logging infrastructure into separate package

Browse Source 
This commit moves the logging interface and implementations out of the
sdk package into the logging package.

This commit also updates the status and decision log plugins to use a
logger obtained from the plugin manager instead of going to the global
console logger in the plugins package. The latter change will be
important for SDK consumers. This change is backwards incompatible but
it's unlikely that anyone is relying on that export. The test for
console logger independence has also been moved into the plugins
package (from the status package.)

Fixes #3275

Co-authored-by: Torin Sandall <torinsandall@gmail.com>
Co-authored-by: Anders Eknert <anders@eknert.com>

Signed-off-by: Torin Sandall <torinsandall@gmail.com>
Signed-off-by: Anders Eknert <anders@eknert.com>
This commit is contained in:
Torin Sandall
2021-04-29 16:13:15 -04:00
parent c3db237f59
commit 3fcc875a55
21 changed files with 333 additions and 233 deletions
Download Patch File Download Diff File Expand all files Collapse all files
download/download.go
+3 -5
View File
@@ -15,13 +15,11 @@ import (
"sync"
"time"
"github.com/open-policy-agent/opa/sdk"
"github.com/pkg/errors"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/bundle"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins/rest"
"github.com/open-policy-agent/opa/util"
)
@@ -53,9 +51,9 @@ type Downloader struct {
etag string // HTTP Etag for caching purposes
sizeLimitBytes *int64 // max bundle file size in bytes (passed to reader)
bvc *bundle.VerificationConfig
logger sdk.Logger
respHdrTimeoutSec int64
wg sync.WaitGroup
logger logging.Logger
}
// New returns a new Downloader that can be started.
internal/config/config.go
+3 -5
View File
@@ -13,13 +13,11 @@ import (
"regexp"
"strings"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/keys"
"github.com/ghodss/yaml"
"github.com/open-policy-agent/opa/internal/strvals"
"github.com/open-policy-agent/opa/keys"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/plugins/rest"
"github.com/open-policy-agent/opa/util"
)
@@ -29,7 +27,7 @@ type ServiceOptions struct {
Raw json.RawMessage
AuthPlugin func(string) rest.HTTPAuthPlugin
Keys map[string]*keys.Config
Logger sdk.Logger
Logger logging.Logger
}
// ParseServicesConfig returns a set of named service clients. The service
sdk/logging.go → logging/logging.go
+6 -1
View File
@@ -1,4 +1,4 @@
package sdk
package logging
import (
"github.com/sirupsen/logrus"
@@ -45,6 +45,11 @@ func NewStandardLogger() *StandardLogger {
}
}
// SetFormatter sets the underlying logrus formatter.
func (l *StandardLogger) SetFormatter(formatter logrus.Formatter) {
l.logger.SetFormatter(formatter)
}
// WithFields provides additional fields to include in log output
func (l *StandardLogger) WithFields(fields map[string]interface{}) Logger {
cp := *l
sdk/logging_test.go → logging/logging_test.go
+1 -1
View File
@@ -1,4 +1,4 @@
package sdk
package logging
import (
"testing"
logging/test/test.go
+93
View File
@@ -0,0 +1,93 @@
package test
import (
"fmt"
"github.com/open-policy-agent/opa/logging"
)
// LogEntry represents a log message.
type LogEntry struct {
Level logging.Level
Fields map[string]interface{}
Message string
}
// Logger implementation that buffers messages for test purposes.
type Logger struct {
level logging.Level
fields map[string]interface{}
entries *[]LogEntry
}
// New instantiates new Logger.
func New() *Logger {
return &Logger{
level: logging.Info,
entries: &[]LogEntry{},
}
}
// 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 *Logger) WithFields(fields map[string]interface{}) logging.Logger {
cp := *l
flds := make(map[string]interface{})
for k, v := range cp.fields {
flds[k] = v
}
for k, v := range fields {
flds[k] = v
}
cp.fields = flds
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 *Logger) GetFields() map[string]interface{} {
return l.fields
}
// Debug buffers a log message.
func (l *Logger) Debug(f string, a ...interface{}) {
l.append(logging.Debug, f, a...)
}
// Info buffers a log message.
func (l *Logger) Info(f string, a ...interface{}) {
l.append(logging.Info, f, a...)
}
// Error buffers a log message.
func (l *Logger) Error(f string, a ...interface{}) {
l.append(logging.Error, f, a...)
}
// Warn buffers a log message.
func (l *Logger) Warn(f string, a ...interface{}) {
l.append(logging.Warn, f, a...)
}
// SetLevel set log level.
func (l *Logger) SetLevel(level logging.Level) {
l.level = level
}
// GetLevel get log level.
func (l *Logger) GetLevel() logging.Level {
return l.level
}
// Entries returns buffered log entries.
func (l *Logger) Entries() []LogEntry {
return *l.entries
}
func (l *Logger) append(lvl logging.Level, f string, a ...interface{}) {
*l.entries = append(*l.entries, LogEntry{
Level: lvl,
Fields: l.fields,
Message: fmt.Sprintf(f, a...),
})
}
plugins/bundle/plugin.go
+4 -5
View File
@@ -17,12 +17,11 @@ import (
"sync"
"time"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/ast"
"github.com/open-policy-agent/opa/bundle"
"github.com/open-policy-agent/opa/download"
bundleUtils "github.com/open-policy-agent/opa/internal/bundle"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/storage"
@@ -37,7 +36,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
logger logging.Logger
mtx sync.Mutex
cfgMtx sync.Mutex
legacyConfig bool
@@ -570,9 +569,9 @@ func loadBundleFromDisk(path, name string, src *Source) (*bundle.Bundle, error)
}
}
func (p *Plugin) log(name string) sdk.Logger {
func (p *Plugin) log(name string) logging.Logger {
if p.logger == nil {
p.logger = sdk.NewStandardLogger()
p.logger = logging.NewStandardLogger()
}
return p.logger.WithFields(map[string]interface{}{"name": name, "plugin": Name})
}
plugins/discovery/discovery.go
+2 -3
View File
@@ -11,14 +11,13 @@ import (
"fmt"
"sync"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/ast"
bundleApi "github.com/open-policy-agent/opa/bundle"
"github.com/open-policy-agent/opa/config"
"github.com/open-policy-agent/opa/download"
cfg "github.com/open-policy-agent/opa/internal/config"
"github.com/open-policy-agent/opa/keys"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/plugins/bundle"
@@ -43,7 +42,7 @@ type Discovery struct {
etag string // discovery bundle etag for caching purposes
metrics metrics.Metrics
readyOnce sync.Once
logger sdk.Logger
logger logging.Logger
}
// Factories provides a set of factory functions to use for
plugins/discovery/discovery_test.go
+7 -14
View File
@@ -16,8 +16,7 @@ import (
"testing"
"time"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
"github.com/open-policy-agent/opa/logging/test"
"github.com/open-policy-agent/opa/ast"
bundleApi "github.com/open-policy-agent/opa/bundle"
@@ -999,16 +998,10 @@ func TestStatusUpdatesTimestamp(t *testing.T) {
func TestStatusMetricsForLogDrops(t *testing.T) {
logLevel := logrus.GetLevel()
defer logrus.SetLevel(logLevel)
// Ensure that status messages are printed to console even with the standard logger configured to log errors only
logrus.SetLevel(logrus.ErrorLevel)
hook := test.NewLocal(plugins.GetConsoleLogger())
ctx := context.Background()
testLogger := test.New()
manager, err := plugins.New([]byte(`{
"services": {
"localhost": {
@@ -1016,7 +1009,7 @@ func TestStatusMetricsForLogDrops(t *testing.T) {
}
},
"discovery": {"name": "config"},
}`), "test-id", inmem.New())
}`), "test-id", inmem.New(), plugins.ConsoleLogger(testLogger))
if err != nil {
t.Fatal(err)
}
@@ -1095,7 +1088,7 @@ func TestStatusMetricsForLogDrops(t *testing.T) {
}
}`)})
entries := hook.AllEntries()
entries := testLogger.Entries()
if len(entries) == 0 {
t.Fatal("Expected log entries but got none")
}
@@ -1103,11 +1096,11 @@ func TestStatusMetricsForLogDrops(t *testing.T) {
// Pick the last entry as it should have the drop count
e := entries[len(entries)-1]
if _, ok := e.Data["metrics"]; !ok {
if _, ok := e.Fields["metrics"]; !ok {
t.Fatal("Expected metrics")
}
builtInMet := e.Data["metrics"].(map[string]interface{})["<built-in>"]
builtInMet := e.Fields["metrics"].(map[string]interface{})["<built-in>"]
dropCount := builtInMet.(map[string]interface{})["counter_decision_logs_dropped"]
actual, err := dropCount.(json.Number).Int64()
plugins/logs/plugin.go
+3 -5
View File
@@ -9,7 +9,6 @@ import (
"context"
"encoding/json"
"fmt"
"math"
"math/rand"
"net/http"
@@ -19,16 +18,15 @@ import (
"time"
"github.com/pkg/errors"
"golang.org/x/time/rate"
"github.com/open-policy-agent/opa/ast"
"github.com/open-policy-agent/opa/internal/ref"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/plugins/rest"
"github.com/open-policy-agent/opa/rego"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/server"
"github.com/open-policy-agent/opa/storage"
"github.com/open-policy-agent/opa/util"
@@ -345,9 +343,9 @@ type Plugin struct {
reconfig chan reconfigure
mask *rego.PreparedEvalQuery
maskMutex sync.Mutex
logger sdk.Logger
limiter *rate.Limiter
metrics metrics.Metrics
logger logging.Logger
}
type reconfigure struct {
@@ -809,7 +807,7 @@ func (p *Plugin) logEvent(event EventV1) error {
if err != nil {
return err
}
plugins.GetConsoleLogger().WithFields(fields).WithFields(map[string]interface{}{
p.manager.ConsoleLogger().WithFields(fields).WithFields(map[string]interface{}{
"type": "openpolicyagent.org/decision_logs",
}).Info("Decision Log")
return nil
plugins/logs/plugin_test.go
+56 -60
View File
@@ -20,6 +20,7 @@ import (
"time"
"github.com/open-policy-agent/opa/ast"
"github.com/open-policy-agent/opa/logging/test"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/plugins/bundle"
@@ -31,8 +32,6 @@ import (
"github.com/open-policy-agent/opa/topdown"
"github.com/open-policy-agent/opa/util"
"github.com/open-policy-agent/opa/version"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
)
func TestMain(m *testing.M) {
@@ -44,8 +43,6 @@ type testPlugin struct {
events []EventV1
}
type testPluginCustomizer func(c *Config)
func (p *testPlugin) Start(context.Context) error {
return nil
}
@@ -456,10 +453,7 @@ func logServerInfo(id string, input interface{}, result interface{}) *server.Inf
func TestPluginRequeBufferPreserved(t *testing.T) {
ctx := context.Background()
fixture := newTestFixture(t, func(c *Config) {
limit := int64(300)
c.Reporting.UploadSizeLimitBytes = &limit
})
fixture := newTestFixture(t, testFixtureOptions{ReportingUploadSizeLimitBytes: 300})
defer fixture.server.stop()
fixture.server.ch = make(chan []EventV1, 3)
@@ -499,12 +493,9 @@ func TestPluginRateLimitInt(t *testing.T) {
numDecisions := 1 // 1 decision per second
fixture := newTestFixture(t, func(c *Config) {
limit := float64(numDecisions)
c.Reporting.MaxDecisionsPerSecond = &limit
}, func(c *Config) {
limit := int64(300)
c.Reporting.UploadSizeLimitBytes = &limit
fixture := newTestFixture(t, testFixtureOptions{
ReportingMaxDecisionsPerSecond: float64(numDecisions),
ReportingUploadSizeLimitBytes: 300,
})
defer fixture.server.stop()
@@ -595,13 +586,9 @@ func TestPluginRateLimitFloat(t *testing.T) {
}
numDecisions := 0.1 // 0.1 decision per second ie. 1 decision per 10 seconds
fixture := newTestFixture(t, func(c *Config) {
limit := float64(numDecisions)
c.Reporting.MaxDecisionsPerSecond = &limit
}, func(c *Config) {
limit := int64(300)
c.Reporting.UploadSizeLimitBytes = &limit
fixture := newTestFixture(t, testFixtureOptions{
ReportingMaxDecisionsPerSecond: float64(numDecisions),
ReportingUploadSizeLimitBytes: 300,
})
defer fixture.server.stop()
@@ -696,12 +683,9 @@ func TestPluginRateLimitRequeue(t *testing.T) {
numDecisions := 100 // 100 decisions per second
fixture := newTestFixture(t, func(c *Config) {
limit := float64(numDecisions)
c.Reporting.MaxDecisionsPerSecond = &limit
}, func(c *Config) {
limit := int64(300)
c.Reporting.UploadSizeLimitBytes = &limit
fixture := newTestFixture(t, testFixtureOptions{
ReportingMaxDecisionsPerSecond: float64(numDecisions),
ReportingUploadSizeLimitBytes: 300,
})
defer fixture.server.stop()
@@ -751,13 +735,10 @@ func TestPluginRateLimitDropCountStatus(t *testing.T) {
}
numDecisions := 1 // 1 decision per second
fixture := newTestFixture(t, func(c *Config) {
limit := float64(numDecisions)
c.Reporting.MaxDecisionsPerSecond = &limit
}, func(c *Config) {
limit := int64(300)
c.Reporting.UploadSizeLimitBytes = &limit
fixture := newTestFixture(t, testFixtureOptions{
ConsoleLogger: test.New(),
ReportingMaxDecisionsPerSecond: float64(numDecisions),
ReportingUploadSizeLimitBytes: 300,
})
defer fixture.server.stop()
@@ -812,14 +793,6 @@ func TestPluginRateLimitDropCountStatus(t *testing.T) {
panic(err)
}
logLevel := logrus.GetLevel()
defer logrus.SetLevel(logLevel)
// Ensure that status messages are printed to console even with the standard logger configured to log errors only
logrus.SetLevel(logrus.ErrorLevel)
hook := test.NewLocal(plugins.GetConsoleLogger())
_ = fixture.plugin.Log(ctx, event2) // event 2 should not be written into the encoder as rate limit exceeded
_ = fixture.plugin.Log(ctx, event3) // event 3 should not be written into the encoder as rate limit exceeded
@@ -830,7 +803,7 @@ func TestPluginRateLimitDropCountStatus(t *testing.T) {
// Give the logger / console some time to process and print the events
time.Sleep(10 * time.Millisecond)
entries := hook.AllEntries()
entries := fixture.consoleLogger.Entries()
if len(entries) == 0 {
t.Fatal("Expected log entries but got none")
}
@@ -838,14 +811,14 @@ func TestPluginRateLimitDropCountStatus(t *testing.T) {
// Pick the last entry as it should have the drop count
e := entries[len(entries)-1]
if _, ok := e.Data["metrics"]; !ok {
if _, ok := e.Fields["metrics"]; !ok {
t.Fatal("Expected metrics")
}
exp := map[string]interface{}{"<built-in>": map[string]interface{}{"counter_decision_logs_dropped": json.Number("2")}}
if !reflect.DeepEqual(e.Data["metrics"], exp) {
t.Fatalf("Expected %v but got %v", exp, e.Data["metrics"])
if !reflect.DeepEqual(e.Fields["metrics"], exp) {
t.Fatalf("Expected %v but got %v", exp, e.Fields["metrics"])
}
}
@@ -1012,10 +985,9 @@ func TestPluginReconfigureUploadSizeLimit(t *testing.T) {
ctx := context.Background()
limit := int64(300)
fixture := newTestFixture(t, func(c *Config) {
c.Reporting.UploadSizeLimitBytes = &limit
fixture := newTestFixture(t, testFixtureOptions{
ReportingUploadSizeLimitBytes: limit,
})
defer fixture.server.stop()
if err := fixture.plugin.Start(ctx); err != nil {
@@ -1352,13 +1324,20 @@ func TestPluginMasking(t *testing.T) {
}
}
type testFixture struct {
manager *plugins.Manager
plugin *Plugin
server *testServer
type testFixtureOptions struct {
ConsoleLogger *test.Logger
ReportingUploadSizeLimitBytes int64
ReportingMaxDecisionsPerSecond float64
}
func newTestFixture(t *testing.T, options ...testPluginCustomizer) testFixture {
type testFixture struct {
manager *plugins.Manager
consoleLogger *test.Logger
plugin *Plugin
server *testServer
}
func newTestFixture(t *testing.T, opts ...testFixtureOptions) testFixture {
ts := testServer{
t: t,
@@ -1384,14 +1363,30 @@ func newTestFixture(t *testing.T, options ...testPluginCustomizer) testFixture {
}
]}`, ts.server.URL))
manager, err := plugins.New(managerConfig, "test-instance-id", inmem.New(), plugins.GracefulShutdownPeriod(10))
var options testFixtureOptions
if len(opts) > 0 {
options = opts[0]
}
manager, err := plugins.New(
managerConfig,
"test-instance-id",
inmem.New(),
plugins.GracefulShutdownPeriod(10),
plugins.ConsoleLogger(options.ConsoleLogger))
if err != nil {
t.Fatal(err)
}
config, _ := ParseConfig([]byte(`{"service": "example"}`), manager.Services(), nil)
for _, option := range options {
option(config)
if options.ReportingMaxDecisionsPerSecond != 0 {
config.Reporting.MaxDecisionsPerSecond = &options.ReportingMaxDecisionsPerSecond
}
if options.ReportingUploadSizeLimitBytes != 0 {
config.Reporting.UploadSizeLimitBytes = &options.ReportingUploadSizeLimitBytes
}
if s, ok := manager.PluginStatus()[Name]; ok {
@@ -1403,9 +1398,10 @@ func newTestFixture(t *testing.T, options ...testPluginCustomizer) testFixture {
ensurePluginState(t, p, plugins.StateNotReady)
return testFixture{
manager: manager,
plugin: p,
server: &ts,
manager: manager,
consoleLogger: options.ConsoleLogger,
plugin: p,
server: &ts,
}
}
plugins/plugins.go
+27 -20
View File
@@ -11,19 +11,15 @@ import (
"sync"
"time"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/keys"
"github.com/sirupsen/logrus"
"github.com/open-policy-agent/opa/ast"
"github.com/open-policy-agent/opa/bundle"
"github.com/open-policy-agent/opa/config"
bundleUtils "github.com/open-policy-agent/opa/internal/bundle"
cfg "github.com/open-policy-agent/opa/internal/config"
initload "github.com/open-policy-agent/opa/internal/runtime/init"
"github.com/open-policy-agent/opa/keys"
"github.com/open-policy-agent/opa/loader"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/plugins/rest"
"github.com/open-policy-agent/opa/resolver/wasm"
"github.com/open-policy-agent/opa/storage"
@@ -158,7 +154,8 @@ type Manager struct {
interQueryBuiltinCacheConfig *cache.Config
gracefulShutdownPeriod int
registeredCacheTriggers []func(*cache.Config)
logger sdk.Logger
logger logging.Logger
consoleLogger logging.Logger
}
type managerContextKey string
@@ -167,14 +164,6 @@ type managerWasmResolverKey string
const managerCompilerContextKey = managerContextKey("compiler")
const managerWasmResolverContextKey = managerWasmResolverKey("wasmResolvers")
// Dedicated logger for plugins logging to console independently of configured --log-level
var logrusConsole = logrus.New()
// GetConsoleLogger return plugin console logger
func GetConsoleLogger() *logrus.Logger {
return logrusConsole
}
// SetCompilerOnContext puts the compiler into the storage context. Calling this
// function before committing updated policies to storage allows the manager to
// skip parsing and compiling of modules. Instead, the manager will use the
@@ -250,13 +239,22 @@ func GracefulShutdownPeriod(gracefulShutdownPeriod int) func(*Manager) {
}
}
// Logger configures the passed logger on the plugin manager (useful to configure default fields)
func Logger(logger sdk.Logger) func(*Manager) {
// Logger configures the passed logger on the plugin manager (useful to
// configure default fields)
func Logger(logger logging.Logger) func(*Manager) {
return func(m *Manager) {
m.logger = logger
}
}
// ConsoleLogger sets the passed logger to be used by plugins that are
// configured with console logging enabled.
func ConsoleLogger(logger logging.Logger) func(*Manager) {
return func(m *Manager) {
m.consoleLogger = logger
}
}
// New creates a new Manager using config.
func New(raw []byte, id string, store storage.Store, opts ...func(*Manager)) (*Manager, error) {
@@ -287,7 +285,11 @@ func New(raw []byte, id string, store storage.Store, opts ...func(*Manager)) (*M
}
if m.logger == nil {
m.logger = sdk.NewStandardLogger()
m.logger = logging.NewStandardLogger()
}
if m.consoleLogger == nil {
m.consoleLogger = logging.NewStandardLogger()
}
serviceOpts := cfg.ServiceOptions{
@@ -743,11 +745,16 @@ func (m *Manager) Services() []string {
return s
}
// Logger gets the logger implementation associated with this plugin manager
func (m *Manager) Logger() sdk.Logger {
// Logger gets the standard logger for this plugin manager.
func (m *Manager) Logger() logging.Logger {
return m.logger
}
// ConsoleLogger gets the console logger for this plugin manager.
func (m *Manager) ConsoleLogger() logging.Logger {
return m.consoleLogger
}
// 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)) {
plugins/plugins_test.go
+36 -2
View File
@@ -11,9 +11,12 @@ import (
"reflect"
"testing"
"github.com/sirupsen/logrus"
"github.com/open-policy-agent/opa/internal/storage/mock"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/logging/test"
"github.com/open-policy-agent/opa/plugins/rest"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/storage/inmem"
"github.com/open-policy-agent/opa/topdown/cache"
)
@@ -296,7 +299,7 @@ func TestPluginManagerAuthPlugin(t *testing.T) {
func TestPluginManagerLogger(t *testing.T) {
logger := sdk.NewStandardLogger().WithFields(map[string]interface{}{"context": "myloggincontext"})
logger := logging.NewStandardLogger().WithFields(map[string]interface{}{"context": "myloggincontext"})
m, err := New([]byte(`{}`), "test", inmem.New(), Logger(logger))
if err != nil {
@@ -308,6 +311,37 @@ func TestPluginManagerLogger(t *testing.T) {
}
}
func TestPluginManagerConsoleLogger(t *testing.T) {
logLevel := logrus.GetLevel()
defer logrus.SetLevel(logLevel)
// Ensure that status messages are printed to console even with the standard logger configured to log errors only
logrus.SetLevel(logrus.ErrorLevel)
consoleLogger := test.New()
mgr, err := New([]byte(`{}`), "", inmem.New(), ConsoleLogger(consoleLogger))
if err != nil {
t.Fatal(err)
}
mgr.ConsoleLogger().WithFields(map[string]interface{}{"foo": "bar"}).Info("Some message")
entries := consoleLogger.Entries()
exp := []test.LogEntry{
{
Level: logging.Info,
Fields: map[string]interface{}{"foo": "bar"},
Message: "Some message",
},
}
if !reflect.DeepEqual(exp, entries) {
t.Fatalf("want %v but got %v", exp, entries)
}
}
type myAuthPluginMock struct{}
func (m *myAuthPluginMock) NewClient(c rest.Config) (*http.Client, error) {
plugins/rest/aws.go
+5 -5
View File
@@ -20,7 +20,7 @@ import (
"strings"
"time"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/logging"
)
const (
@@ -72,7 +72,7 @@ type awsCredentialService interface {
// awsEnvironmentCredentialService represents an static environment-variable credential provider for AWS
type awsEnvironmentCredentialService struct {
logger sdk.Logger
logger logging.Logger
}
func (cs *awsEnvironmentCredentialService) credentials() (awsCredentials, error) {
@@ -109,7 +109,7 @@ type awsMetadataCredentialService struct {
expiration time.Time
credServicePath string
tokenPath string
logger sdk.Logger
logger logging.Logger
}
func (cs *awsMetadataCredentialService) urlForMetadataService() (string, error) {
@@ -239,7 +239,7 @@ type awsWebIdentityCredentialService struct {
stsURL string
creds awsCredentials
expiration time.Time
logger sdk.Logger
logger logging.Logger
}
func (cs *awsWebIdentityCredentialService) populateFromEnv() error {
@@ -360,7 +360,7 @@ func isECS() bool {
return isECS
}
func doMetaDataRequestWithClient(req *http.Request, client *http.Client, desc string, logger sdk.Logger) ([]byte, error) {
func doMetaDataRequestWithClient(req *http.Request, client *http.Client, desc string, logger logging.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)
plugins/rest/aws_test.go
+18 -18
View File
@@ -15,7 +15,7 @@ import (
"testing"
"time"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/logging"
)
// this is usually private; but we need it here
@@ -109,7 +109,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: "this is not a URL", // malformed
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
_, err := cs.credentials()
assertErr("unsupported protocol scheme \"\"", err, t)
@@ -118,7 +118,7 @@ func TestMetadataCredentialService(t *testing.T) {
os.Unsetenv(ecsRelativePathEnvVar)
cs = awsMetadataCredentialService{
RegionName: "us-east-1",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
_, err = cs.credentials()
assertErr("metadata endpoint cannot be determined from settings and environment", err, t)
@@ -129,7 +129,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
_, err = cs.credentials()
assertErr("metadata HTTP request returned unexpected status: 404 Not Found", err, t)
@@ -140,7 +140,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
_, err = cs.credentials()
assertErr("failed to parse credential response from metadata service: invalid character 'T' looking for beginning of value", err, t)
@@ -151,7 +151,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/missing_token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
} // will 404
_, err = cs.credentials()
assertErr("metadata token HTTP request returned unexpected status: 404 Not Found", err, t)
@@ -162,7 +162,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/bad_token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
} // not good
_, err = cs.credentials()
assertErr("metadata HTTP request returned unexpected status: 401 Unauthorized", err, t)
@@ -179,7 +179,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
_, err = cs.credentials()
assertErr("metadata service query did not succeed: Failure", err, t)
@@ -196,7 +196,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
var creds awsCredentials
creds, err = cs.credentials()
@@ -222,7 +222,7 @@ func TestMetadataCredentialService(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -268,7 +268,7 @@ func TestV4Signing(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
req, _ := http.NewRequest("GET", "https://mybucket.s3.amazonaws.com/bundle.tar.gz", strings.NewReader(""))
err := signV4(req, "s3", cs, time.Unix(1556129697, 0))
@@ -281,7 +281,7 @@ func TestV4Signing(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -318,7 +318,7 @@ func TestV4SigningForApiGateway(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -358,7 +358,7 @@ func TestV4SigningOmitsIgnoredHeaders(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -401,7 +401,7 @@ func TestV4SigningCustomPort(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -438,7 +438,7 @@ func TestV4SigningDoesNotMutateBody(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -470,7 +470,7 @@ func TestV4SigningWithMultiValueHeaders(t *testing.T) {
RegionName: "us-east-1",
credServicePath: ts.server.URL + "/latest/meta-data/iam/security-credentials/",
tokenPath: ts.server.URL + "/latest/api/token",
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
ts.payload = metadataPayload{
AccessKeyID: "MYAWSACCESSKEYGOESHERE",
@@ -565,7 +565,7 @@ func TestWebIdentityCredentialService(t *testing.T) {
defer ts.stop()
cs := awsWebIdentityCredentialService{
stsURL: ts.server.URL,
logger: sdk.NewStandardLogger(),
logger: logging.NewStandardLogger(),
}
goodTokenFile, err := ioutil.TempFile(os.TempDir(), "opa-aws-test-")
plugins/rest/rest.go
+7 -10
View File
@@ -15,12 +15,9 @@ 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/open-policy-agent/opa/keys"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/util"
)
@@ -52,7 +49,7 @@ type Config struct {
} `json:"credentials"`
keys map[string]*keys.Config
logger sdk.Logger
logger logging.Logger
}
// Equal returns true if this client config is equal to the other.
@@ -111,7 +108,7 @@ type Client struct {
config Config
headers map[string]string
authPluginLookup func(string) HTTPAuthPlugin
logger sdk.Logger
logger logging.Logger
}
// Name returns an option that overrides the service name on the client.
@@ -132,7 +129,7 @@ func AuthPluginLookup(l func(string) HTTPAuthPlugin) func(*Client) {
}
// Logger assigns a logger to the client
func Logger(l sdk.Logger) func(*Client) {
func Logger(l logging.Logger) func(*Client) {
return func(c *Client) {
c.logger = l
}
@@ -165,7 +162,7 @@ func New(config []byte, keys map[string]*keys.Config, opts ...func(*Client)) (Cl
}
if client.logger == nil {
client.logger = sdk.NewStandardLogger()
client.logger = logging.NewStandardLogger()
}
client.config.logger = client.logger
@@ -189,7 +186,7 @@ func (c Client) SetResponseHeaderTimeout(timeout *int64) Client {
}
// Logger returns the logger assigned to the Client
func (c Client) Logger() sdk.Logger {
func (c Client) Logger() logging.Logger {
return c.logger
}
plugins/rest/rest_auth.go
+4 -5
View File
@@ -22,12 +22,11 @@ import (
"time"
"github.com/open-policy-agent/opa/internal/jwx/jwa"
"github.com/open-policy-agent/opa/internal/jwx/jws/sign"
"github.com/open-policy-agent/opa/internal/jwx/jws"
"github.com/open-policy-agent/opa/internal/jwx/jws/sign"
"github.com/open-policy-agent/opa/internal/uuid"
"github.com/open-policy-agent/opa/keys"
"github.com/open-policy-agent/opa/sdk"
"github.com/open-policy-agent/opa/logging"
)
const (
@@ -141,7 +140,7 @@ type oauth2ClientCredentialsAuthPlugin struct {
signingKeyParsed interface{}
tokenCache *oauth2Token
tlsSkipVerify bool
logger sdk.Logger
logger logging.Logger
}
type oauth2Token struct {
@@ -463,7 +462,7 @@ type awsSigningAuthPlugin struct {
AWSWebIdentityCredentials *awsWebIdentityCredentialService `json:"web_identity_credentials,omitempty"`
AWSService string `json:"service,omitempty"`
logger sdk.Logger
logger logging.Logger
}
func (ap *awsSigningAuthPlugin) awsCredentialService() awsCredentialService {
plugins/status/plugin.go
+3 -4
View File
@@ -12,11 +12,10 @@ import (
"net/http"
"reflect"
"github.com/open-policy-agent/opa/sdk"
"github.com/pkg/errors"
"github.com/sirupsen/logrus"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/plugins/bundle"
@@ -56,7 +55,7 @@ type Plugin struct {
metrics metrics.Metrics
lastPluginStatuses map[string]*plugins.Status
pluginStatusCh chan map[string]*plugins.Status
logger sdk.Logger
logger logging.Logger
}
// Config contains configuration for the plugin.
@@ -344,7 +343,7 @@ func (p *Plugin) logUpdate(update *UpdateRequestV1) error {
if err != nil {
return err
}
plugins.GetConsoleLogger().WithFields(fields).WithFields(logrus.Fields{
p.manager.ConsoleLogger().WithFields(fields).WithFields(logrus.Fields{
"type": "openpolicyagent.org/status",
}).Info("Status Log")
return nil
plugins/status/plugin_test.go
-39
View File
@@ -14,9 +14,6 @@ import (
"testing"
"time"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/plugins/bundle"
@@ -203,42 +200,6 @@ func TestPluginStartDiscovery(t *testing.T) {
}
}
func TestPluginConsoleLogging(t *testing.T) {
logLevel := logrus.GetLevel()
defer logrus.SetLevel(logLevel)
// Ensure that status messages are printed to console even with the standard logger configured to log errors only
logrus.SetLevel(logrus.ErrorLevel)
hook := test.NewLocal(plugins.GetConsoleLogger())
fixture := newTestFixture(t, nil, func(c *Config) {
c.ConsoleLogs = true
c.Service = ""
})
ctx := context.Background()
_ = fixture.plugin.Start(ctx)
defer fixture.plugin.Stop(ctx)
status := testStatus()
fixture.plugin.UpdateDiscoveryStatus(*status)
// Give the logger / console some time to process and print the events
time.Sleep(10 * time.Millisecond)
// Skip the first entry as it is about the plugin getting updated
e := hook.AllEntries()[1]
if e.Message != "Status Log" {
t.Fatal("Expected status log to console")
}
if _, ok := e.Data["discovery"]; !ok {
t.Fatal("Expected discovery status update")
}
}
func TestPluginBadAuth(t *testing.T) {
fixture := newTestFixture(t, nil)
ctx := context.Background()
runtime/runtime.go
+32 -11
View File
@@ -34,6 +34,7 @@ import (
initload "github.com/open-policy-agent/opa/internal/runtime/init"
"github.com/open-policy-agent/opa/internal/uuid"
"github.com/open-policy-agent/opa/loader"
"github.com/open-policy-agent/opa/logging"
"github.com/open-policy-agent/opa/metrics"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/plugins/discovery"
@@ -141,6 +142,9 @@ type Params struct {
// Logging configures the logging behaviour.
Logging LoggingConfig
// ConsoleLogger sets the logger implementation to use for console logs.
ConsoleLogger logging.Logger
// ConfigFile refers to the OPA configuration to load on startup.
ConfigFile string
@@ -246,7 +250,25 @@ func NewRuntime(ctx context.Context, params Params) (*Runtime, error) {
return nil, err
}
manager, err := plugins.New(config, params.ID, inmem.New(), plugins.Info(info), plugins.InitBundles(loaded.Bundles), plugins.InitFiles(loaded.Files), plugins.MaxErrors(params.ErrorLimit), plugins.GracefulShutdownPeriod(params.GracefulShutdownPeriod))
var consoleLogger logging.Logger
if params.ConsoleLogger == nil {
stdLogger := logging.NewStandardLogger()
stdLogger.SetFormatter(getFormatter(params.Logging.Format))
consoleLogger = stdLogger
} else {
consoleLogger = params.ConsoleLogger
}
manager, err := plugins.New(config,
params.ID,
inmem.New(),
plugins.Info(info),
plugins.InitBundles(loaded.Bundles),
plugins.InitFiles(loaded.Files),
plugins.MaxErrors(params.ErrorLimit),
plugins.GracefulShutdownPeriod(params.GracefulShutdownPeriod),
plugins.ConsoleLogger(consoleLogger))
if err != nil {
return nil, errors.Wrap(err, "config error")
}
@@ -728,23 +750,22 @@ func onReloadPrinter(output io.Writer) func(time.Duration, error) {
}
}
func setupLogging(config LoggingConfig) {
var formatter logrus.Formatter
switch config.Format {
func getFormatter(format string) logrus.Formatter {
switch format {
case "text":
formatter = &prettyFormatter{}
return &prettyFormatter{}
case "json-pretty":
formatter = &logrus.JSONFormatter{PrettyPrint: true}
return &logrus.JSONFormatter{PrettyPrint: true}
case "json":
fallthrough
default:
formatter = &logrus.JSONFormatter{}
return &logrus.JSONFormatter{}
}
logrus.SetFormatter(formatter)
// While the plugin console logger logs independently of the configured --log-level,
// it should follow the configured --log-format
plugins.GetConsoleLogger().SetFormatter(formatter)
}
func setupLogging(config LoggingConfig) {
formatter := getFormatter(config.Format)
logrus.SetFormatter(formatter)
lvl := logrus.InfoLevel
if config.Level != "" {
test/e2e/logs/console/console_decision_logger_test.go
+13 -12
View File
@@ -11,10 +11,7 @@ import (
"strings"
"testing"
"github.com/sirupsen/logrus"
"github.com/sirupsen/logrus/hooks/test"
"github.com/open-policy-agent/opa/plugins"
"github.com/open-policy-agent/opa/logging/test"
"github.com/open-policy-agent/opa/runtime"
"github.com/open-policy-agent/opa/test/e2e"
)
@@ -30,6 +27,8 @@ func TestMain(m *testing.M) {
}
// Ensure decisions are logged regardless of regular log level
testServerParams.Logging = runtime.LoggingConfig{Level: "error"}
consoleLogger := test.New()
testServerParams.ConsoleLogger = consoleLogger
var err error
testRuntime, err = e2e.NewTestRuntime(testServerParams)
@@ -37,13 +36,13 @@ func TestMain(m *testing.M) {
os.Exit(1)
}
testRuntime.ConsoleLogger = consoleLogger
os.Exit(testRuntime.RunTests(m))
}
func TestConsoleDecisionLogWithInput(t *testing.T) {
// Setup a test hook on the console logger (what the console decision logger uses)
hook := test.NewLocal(plugins.GetConsoleLogger())
policy := `
package test
@@ -102,19 +101,21 @@ func TestConsoleDecisionLogWithInput(t *testing.T) {
}},
}
var entry *logrus.Entry
for _, e := range hook.AllEntries() {
if e.Message == "Decision Log" {
entry = e
var entry test.LogEntry
var found bool
for _, entry = range testRuntime.ConsoleLogger.Entries() {
if entry.Message == "Decision Log" {
found = true
}
}
if entry == nil {
t.Fatalf("Did not find 'Decision Log' event in captured logrus entries")
if !found {
t.Fatalf("Did not find 'Decision Log' event in captured log entries")
}
// Ensure expected fields exist
for fieldName, rawField := range entry.Data {
for fieldName, rawField := range entry.Fields {
if fd, ok := expectedFields[fieldName]; ok {
if fieldValue, ok := rawField.(string); ok && fd.match != nil {
fd.match(t, fieldValue)
test/e2e/testing.go
+10 -8
View File
@@ -22,6 +22,7 @@ import (
"github.com/sirupsen/logrus"
"github.com/open-policy-agent/opa/logging/test"
"github.com/open-policy-agent/opa/runtime"
"github.com/open-policy-agent/opa/server/types"
"github.com/open-policy-agent/opa/util"
@@ -53,14 +54,15 @@ func NewAPIServerTestParams() runtime.Params {
// TestRuntime holds metadata and provides helper methods
// to interact with the runtime being tested.
type TestRuntime struct {
Params runtime.Params
Runtime *runtime.Runtime
Ctx context.Context
Cancel context.CancelFunc
Client *http.Client
url string
diagURL string
urlMtx *sync.Mutex
Params runtime.Params
Runtime *runtime.Runtime
Ctx context.Context
Cancel context.CancelFunc
Client *http.Client
ConsoleLogger *test.Logger
url string
diagURL string
urlMtx *sync.Mutex
}
// NewTestRuntime returns a new TestRuntime which