Plugins: Move logs from globals to fields (#42141)

* move logs from globals to fields

* fix test
pull/42149/head
Will Browne 4 years ago committed by GitHub
parent 0ab4afa2b7
commit 0921037f32
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
  1. 13
      pkg/plugins/manager/loader/finder/finder.go
  2. 8
      pkg/plugins/manager/loader/initializer/initializer.go
  3. 20
      pkg/plugins/manager/loader/initializer/initializer_test.go
  4. 33
      pkg/plugins/manager/loader/loader.go
  5. 20
      pkg/plugins/manager/loader/loader_test.go
  6. 22
      pkg/plugins/manager/signature/signature.go

@ -12,14 +12,13 @@ import (
"github.com/grafana/grafana/pkg/util" "github.com/grafana/grafana/pkg/util"
) )
var logger = log.New("plugin.finder")
type Finder struct { type Finder struct {
cfg *setting.Cfg cfg *setting.Cfg
log log.Logger
} }
func New(cfg *setting.Cfg) Finder { func New(cfg *setting.Cfg) Finder {
return Finder{cfg: cfg} return Finder{cfg: cfg, log: log.New("plugin.finder")}
} }
func (f *Finder) Find(pluginDirs []string) ([]string, error) { func (f *Finder) Find(pluginDirs []string) ([]string, error) {
@ -28,10 +27,10 @@ func (f *Finder) Find(pluginDirs []string) ([]string, error) {
for _, dir := range pluginDirs { for _, dir := range pluginDirs {
exists, err := fs.Exists(dir) exists, err := fs.Exists(dir)
if err != nil { if err != nil {
logger.Warn("Error occurred when checking if plugin directory exists", "dir", dir, "err", err) f.log.Warn("Error occurred when checking if plugin directory exists", "dir", dir, "err", err)
} }
if !exists { if !exists {
logger.Warn("Skipping finding plugins as directory does not exist", "dir", dir) f.log.Warn("Skipping finding plugins as directory does not exist", "dir", dir)
continue continue
} }
@ -76,11 +75,11 @@ func (f *Finder) getPluginJSONPaths(dir string) ([]string, error) {
return nil return nil
}); err != nil { }); err != nil {
if errors.Is(err, os.ErrNotExist) { if errors.Is(err, os.ErrNotExist) {
logger.Debug("Couldn't scan directory since it doesn't exist", "pluginDir", dir, "err", err) f.log.Debug("Couldn't scan directory since it doesn't exist", "pluginDir", dir, "err", err)
return []string{}, nil return []string{}, nil
} }
if errors.Is(err, os.ErrPermission) { if errors.Is(err, os.ErrPermission) {
logger.Debug("Couldn't scan directory due to lack of permissions", "pluginDir", dir, "err", err) f.log.Debug("Couldn't scan directory due to lack of permissions", "pluginDir", dir, "err", err)
return []string{}, nil return []string{}, nil
} }

@ -23,17 +23,17 @@ import (
"github.com/grafana/grafana/pkg/util" "github.com/grafana/grafana/pkg/util"
) )
var logger = log.New("plugin.initializer")
type Initializer struct { type Initializer struct {
cfg *setting.Cfg cfg *setting.Cfg
license models.Licensing license models.Licensing
log log.Logger
} }
func New(cfg *setting.Cfg, license models.Licensing) Initializer { func New(cfg *setting.Cfg, license models.Licensing) Initializer {
return Initializer{ return Initializer{
cfg: cfg, cfg: cfg,
license: license, license: license,
log: log.New("plugin.initializer"),
} }
} }
@ -80,7 +80,7 @@ func (i *Initializer) Initialize(p *plugins.Plugin) error {
} }
} }
pluginLog := logger.New("pluginID", p.ID) pluginLog := i.log.New("pluginID", p.ID)
p.SetLogger(pluginLog) p.SetLogger(pluginLog)
if p.Backend { if p.Backend {
@ -123,7 +123,7 @@ func (i *Initializer) InitializeWithFactory(p *plugins.Plugin, factory backendpl
} }
p.RegisterClient(f) p.RegisterClient(f)
} else { } else {
logger.Warn("Could not initialize core plugin process", "pluginID", p.ID) i.log.Warn("Could not initialize core plugin process", "pluginID", p.ID)
return fmt.Errorf("could not initialize plugin %s", p.ID) return fmt.Errorf("could not initialize plugin %s", p.ID)
} }

@ -5,6 +5,7 @@ import (
"path/filepath" "path/filepath"
"testing" "testing"
"github.com/inconshreveable/log15"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/grafana/grafana/pkg/infra/log" "github.com/grafana/grafana/pkg/infra/log"
@ -37,6 +38,7 @@ func TestInitializer_Initialize(t *testing.T) {
i := &Initializer{ i := &Initializer{
cfg: setting.NewCfg(), cfg: setting.NewCfg(),
log: &fakeLogger{},
} }
err := i.Initialize(p) err := i.Initialize(p)
@ -71,6 +73,7 @@ func TestInitializer_Initialize(t *testing.T) {
i := &Initializer{ i := &Initializer{
cfg: setting.NewCfg(), cfg: setting.NewCfg(),
log: fakeLogger{},
} }
err := i.Initialize(p) err := i.Initialize(p)
@ -117,6 +120,7 @@ func TestInitializer_Initialize(t *testing.T) {
cfg: &setting.Cfg{ cfg: &setting.Cfg{
AppSubURL: "appSubURL", AppSubURL: "appSubURL",
}, },
log: fakeLogger{},
} }
err := i.Initialize(p) err := i.Initialize(p)
@ -163,6 +167,7 @@ func TestInitializer_InitializeWithFactory(t *testing.T) {
cfg: &setting.Cfg{ cfg: &setting.Cfg{
AppSubURL: "appSubURL", AppSubURL: "appSubURL",
}, },
log: fakeLogger{},
} }
factoryInvoked := false factoryInvoked := false
@ -202,6 +207,7 @@ func TestInitializer_InitializeWithFactory(t *testing.T) {
cfg: &setting.Cfg{ cfg: &setting.Cfg{
AppSubURL: "appSubURL", AppSubURL: "appSubURL",
}, },
log: fakeLogger{},
} }
err := i.InitializeWithFactory(p, nil) err := i.InitializeWithFactory(p, nil)
@ -236,6 +242,7 @@ func TestInitializer_envVars(t *testing.T) {
}, },
}, },
license: licensing, license: licensing,
log: fakeLogger{},
} }
envVars := i.envVars(p) envVars := i.envVars(p)
@ -252,6 +259,7 @@ func TestInitializer_setPathsBasedOnApp(t *testing.T) {
t.Run("When setting paths based on core plugin on Windows", func(t *testing.T) { t.Run("When setting paths based on core plugin on Windows", func(t *testing.T) {
i := &Initializer{ i := &Initializer{
cfg: setting.NewCfg(), cfg: setting.NewCfg(),
log: fakeLogger{},
} }
child := &plugins.Plugin{ child := &plugins.Plugin{
@ -347,3 +355,15 @@ func (t *testLicensingService) Environment() map[string]string {
type testPlugin struct { type testPlugin struct {
backendplugin.Plugin backendplugin.Plugin
} }
type fakeLogger struct {
log.Logger
}
func (f fakeLogger) New(_ ...interface{}) log15.Logger {
return fakeLogger{}
}
func (f fakeLogger) Warn(_ string, _ ...interface{}) {
}

@ -21,7 +21,6 @@ import (
) )
var ( var (
logger = log.New("plugin.loader")
ErrInvalidPluginJSON = errors.New("did not find valid type or id properties in plugin.json") ErrInvalidPluginJSON = errors.New("did not find valid type or id properties in plugin.json")
ErrInvalidPluginJSONFilePath = errors.New("invalid plugin.json filepath was provided") ErrInvalidPluginJSONFilePath = errors.New("invalid plugin.json filepath was provided")
) )
@ -33,6 +32,7 @@ type Loader struct {
pluginFinder finder.Finder pluginFinder finder.Finder
pluginInitializer initializer.Initializer pluginInitializer initializer.Initializer
signatureValidator signature.Validator signatureValidator signature.Validator
log log.Logger
errs map[string]*plugins.SignatureError errs map[string]*plugins.SignatureError
} }
@ -48,13 +48,14 @@ func New(license models.Licensing, cfg *setting.Cfg, authorizer plugins.PluginLo
pluginInitializer: initializer.New(cfg, license), pluginInitializer: initializer.New(cfg, license),
signatureValidator: signature.NewValidator(authorizer), signatureValidator: signature.NewValidator(authorizer),
errs: make(map[string]*plugins.SignatureError), errs: make(map[string]*plugins.SignatureError),
log: log.New("plugin.loader"),
} }
} }
func (l *Loader) Load(paths []string, ignore map[string]struct{}) ([]*plugins.Plugin, error) { func (l *Loader) Load(paths []string, ignore map[string]struct{}) ([]*plugins.Plugin, error) {
pluginJSONPaths, err := l.pluginFinder.Find(paths) pluginJSONPaths, err := l.pluginFinder.Find(paths)
if err != nil { if err != nil {
logger.Error("plugin finder encountered an error", "err", err) l.log.Error("plugin finder encountered an error", "err", err)
} }
return l.loadPlugins(pluginJSONPaths, ignore) return l.loadPlugins(pluginJSONPaths, ignore)
@ -63,7 +64,7 @@ func (l *Loader) Load(paths []string, ignore map[string]struct{}) ([]*plugins.Pl
func (l *Loader) LoadWithFactory(path string, factory backendplugin.PluginFactoryFunc) (*plugins.Plugin, error) { func (l *Loader) LoadWithFactory(path string, factory backendplugin.PluginFactoryFunc) (*plugins.Plugin, error) {
p, err := l.load(path, map[string]struct{}{}) p, err := l.load(path, map[string]struct{}{})
if err != nil { if err != nil {
logger.Error("failed to load core plugin", "err", err) l.log.Error("failed to load core plugin", "err", err)
return nil, err return nil, err
} }
@ -75,7 +76,7 @@ func (l *Loader) LoadWithFactory(path string, factory backendplugin.PluginFactor
func (l *Loader) load(path string, ignore map[string]struct{}) (*plugins.Plugin, error) { func (l *Loader) load(path string, ignore map[string]struct{}) (*plugins.Plugin, error) {
pluginJSONPaths, err := l.pluginFinder.Find([]string{path}) pluginJSONPaths, err := l.pluginFinder.Find([]string{path})
if err != nil { if err != nil {
logger.Error("failed to find plugin", "err", err) l.log.Error("failed to find plugin", "err", err)
return nil, err return nil, err
} }
@ -98,24 +99,24 @@ func (l *Loader) loadPlugins(pluginJSONPaths []string, existingPlugins map[strin
for _, pluginJSONPath := range pluginJSONPaths { for _, pluginJSONPath := range pluginJSONPaths {
plugin, err := l.readPluginJSON(pluginJSONPath) plugin, err := l.readPluginJSON(pluginJSONPath)
if err != nil { if err != nil {
logger.Warn("Skipping plugin loading as it's plugin.json is invalid", "id", plugin.ID) l.log.Warn("Skipping plugin loading as it's plugin.json is invalid", "id", plugin.ID)
continue continue
} }
pluginJSONAbsPath, err := filepath.Abs(pluginJSONPath) pluginJSONAbsPath, err := filepath.Abs(pluginJSONPath)
if err != nil { if err != nil {
logger.Warn("Skipping plugin loading as full plugin.json path could not be calculated", "id", plugin.ID) l.log.Warn("Skipping plugin loading as full plugin.json path could not be calculated", "id", plugin.ID)
continue continue
} }
if _, dupe := foundPlugins[filepath.Dir(pluginJSONAbsPath)]; dupe { if _, dupe := foundPlugins[filepath.Dir(pluginJSONAbsPath)]; dupe {
logger.Warn("Skipping plugin loading as it's a duplicate", "id", plugin.ID) l.log.Warn("Skipping plugin loading as it's a duplicate", "id", plugin.ID)
continue continue
} }
foundPlugins[filepath.Dir(pluginJSONAbsPath)] = plugin foundPlugins[filepath.Dir(pluginJSONAbsPath)] = plugin
} }
foundPlugins.stripDuplicates(existingPlugins) foundPlugins.stripDuplicates(existingPlugins, l.log)
// calculate initial signature state // calculate initial signature state
loadedPlugins := make(map[string]*plugins.Plugin) loadedPlugins := make(map[string]*plugins.Plugin)
@ -126,9 +127,9 @@ func (l *Loader) loadPlugins(pluginJSONPaths []string, existingPlugins map[strin
Class: l.pluginClass(pluginDir), Class: l.pluginClass(pluginDir),
} }
sig, err := signature.Calculate(logger, plugin) sig, err := signature.Calculate(l.log, plugin)
if err != nil { if err != nil {
logger.Warn("Could not calculate plugin signature state", "pluginID", plugin.ID, "err", err) l.log.Warn("Could not calculate plugin signature state", "pluginID", plugin.ID, "err", err)
continue continue
} }
plugin.Signature = sig.Status plugin.Signature = sig.Status
@ -163,7 +164,7 @@ func (l *Loader) loadPlugins(pluginJSONPaths []string, existingPlugins map[strin
for _, plugin := range loadedPlugins { for _, plugin := range loadedPlugins {
signingError := l.signatureValidator.Validate(plugin) signingError := l.signatureValidator.Validate(plugin)
if signingError != nil { if signingError != nil {
logger.Warn("Skipping loading plugin due to problem with signature", l.log.Warn("Skipping loading plugin due to problem with signature",
"pluginID", plugin.ID, "status", signingError.SignatureStatus) "pluginID", plugin.ID, "status", signingError.SignatureStatus)
plugin.SignatureError = signingError plugin.SignatureError = signingError
l.errs[plugin.ID] = signingError l.errs[plugin.ID] = signingError
@ -180,7 +181,7 @@ func (l *Loader) loadPlugins(pluginJSONPaths []string, existingPlugins map[strin
if exists, err := fs.Exists(module); err != nil { if exists, err := fs.Exists(module); err != nil {
return nil, err return nil, err
} else if !exists { } else if !exists {
logger.Warn("Plugin missing module.js", l.log.Warn("Plugin missing module.js",
"pluginID", plugin.ID, "pluginID", plugin.ID,
"warning", "Missing module.js, If you loaded this plugin from git, make sure to compile it.", "warning", "Missing module.js, If you loaded this plugin from git, make sure to compile it.",
"path", module) "path", module)
@ -201,7 +202,7 @@ func (l *Loader) loadPlugins(pluginJSONPaths []string, existingPlugins map[strin
} }
func (l *Loader) readPluginJSON(pluginJSONPath string) (plugins.JSONData, error) { func (l *Loader) readPluginJSON(pluginJSONPath string) (plugins.JSONData, error) {
logger.Debug("Loading plugin", "path", pluginJSONPath) l.log.Debug("Loading plugin", "path", pluginJSONPath)
if !strings.EqualFold(filepath.Ext(pluginJSONPath), ".json") { if !strings.EqualFold(filepath.Ext(pluginJSONPath), ".json") {
return plugins.JSONData{}, ErrInvalidPluginJSONFilePath return plugins.JSONData{}, ErrInvalidPluginJSONFilePath
@ -221,7 +222,7 @@ func (l *Loader) readPluginJSON(pluginJSONPath string) (plugins.JSONData, error)
} }
if err := reader.Close(); err != nil { if err := reader.Close(); err != nil {
logger.Warn("Failed to close JSON file", "path", pluginJSONPath, "err", err) l.log.Warn("Failed to close JSON file", "path", pluginJSONPath, "err", err)
} }
if err := validatePluginJSON(plugin); err != nil { if err := validatePluginJSON(plugin); err != nil {
@ -283,11 +284,11 @@ func (l *Loader) pluginClass(pluginDir string) plugins.Class {
type foundPlugins map[string]plugins.JSONData type foundPlugins map[string]plugins.JSONData
// stripDuplicates will strip duplicate plugins or plugins that already exist // stripDuplicates will strip duplicate plugins or plugins that already exist
func (f *foundPlugins) stripDuplicates(existingPlugins map[string]struct{}) { func (f *foundPlugins) stripDuplicates(existingPlugins map[string]struct{}, log log.Logger) {
pluginsByID := make(map[string]struct{}) pluginsByID := make(map[string]struct{})
for path, scannedPlugin := range *f { for path, scannedPlugin := range *f {
if _, existing := existingPlugins[scannedPlugin.ID]; existing { if _, existing := existingPlugins[scannedPlugin.ID]; existing {
logger.Debug("Skipping plugin as it's already installed", "plugin", scannedPlugin.ID) log.Debug("Skipping plugin as it's already installed", "plugin", scannedPlugin.ID)
delete(*f, path) delete(*f, path)
continue continue
} }

@ -12,6 +12,7 @@ import (
"github.com/google/go-cmp/cmp/cmpopts" "github.com/google/go-cmp/cmp/cmpopts"
"github.com/stretchr/testify/assert" "github.com/stretchr/testify/assert"
"github.com/grafana/grafana/pkg/infra/log"
"github.com/grafana/grafana/pkg/plugins" "github.com/grafana/grafana/pkg/plugins"
"github.com/grafana/grafana/pkg/plugins/manager/loader/finder" "github.com/grafana/grafana/pkg/plugins/manager/loader/finder"
"github.com/grafana/grafana/pkg/plugins/manager/loader/initializer" "github.com/grafana/grafana/pkg/plugins/manager/loader/initializer"
@ -887,6 +888,7 @@ func newLoader(cfg *setting.Cfg) *Loader {
pluginInitializer: initializer.New(cfg, &fakeLicensingService{}), pluginInitializer: initializer.New(cfg, &fakeLicensingService{}),
signatureValidator: signature.NewValidator(&signature.UnsignedPluginAuthorizer{Cfg: cfg}), signatureValidator: signature.NewValidator(&signature.UnsignedPluginAuthorizer{Cfg: cfg}),
errs: make(map[string]*plugins.SignatureError), errs: make(map[string]*plugins.SignatureError),
log: &fakeLogger{},
} }
} }
@ -916,7 +918,7 @@ func (t *fakeLicensingService) ContentDeliveryPrefix() string {
return "" return ""
} }
func (t *fakeLicensingService) LicenseURL(showAdminLicensingPage bool) string { func (t *fakeLicensingService) LicenseURL(_ bool) string {
return "" return ""
} }
@ -927,3 +929,19 @@ func (t *fakeLicensingService) HasValidLicense() bool {
func (t *fakeLicensingService) Environment() map[string]string { func (t *fakeLicensingService) Environment() map[string]string {
return map[string]string{"GF_ENTERPRISE_LICENSE_TEXT": t.tokenRaw} return map[string]string{"GF_ENTERPRISE_LICENSE_TEXT": t.tokenRaw}
} }
type fakeLogger struct {
log.Logger
}
func (fl fakeLogger) Info(_ string, _ ...interface{}) {
}
func (fl fakeLogger) Debug(_ string, _ ...interface{}) {
}
func (fl fakeLogger) Warn(_ string, _ ...interface{}) {
}

@ -5,37 +5,37 @@ import (
"github.com/grafana/grafana/pkg/plugins" "github.com/grafana/grafana/pkg/plugins"
) )
var logger = log.New("plugin.signature.validator")
type Validator struct { type Validator struct {
authorizer plugins.PluginLoaderAuthorizer authorizer plugins.PluginLoaderAuthorizer
log log.Logger
} }
func NewValidator(authorizer plugins.PluginLoaderAuthorizer) Validator { func NewValidator(authorizer plugins.PluginLoaderAuthorizer) Validator {
return Validator{ return Validator{
authorizer: authorizer, authorizer: authorizer,
log: log.New("plugin.signature.validator"),
} }
} }
func (s *Validator) Validate(plugin *plugins.Plugin) *plugins.SignatureError { func (s *Validator) Validate(plugin *plugins.Plugin) *plugins.SignatureError {
if plugin.Signature == plugins.SignatureValid { if plugin.Signature == plugins.SignatureValid {
logger.Debug("Plugin has valid signature", "id", plugin.ID) s.log.Debug("Plugin has valid signature", "id", plugin.ID)
return nil return nil
} }
// If a plugin is nested within another, create links to each other to inherit signature details // If a plugin is nested within another, create links to each other to inherit signature details
if plugin.Parent != nil { if plugin.Parent != nil {
if plugin.IsCorePlugin() || plugin.Signature == plugins.SignatureInternal { if plugin.IsCorePlugin() || plugin.Signature == plugins.SignatureInternal {
logger.Debug("Not setting descendant plugin's signature to that of root since it's core or internal", s.log.Debug("Not setting descendant plugin's signature to that of root since it's core or internal",
"plugin", plugin.ID, "signature", plugin.Signature, "isCore", plugin.IsCorePlugin) "plugin", plugin.ID, "signature", plugin.Signature, "isCore", plugin.IsCorePlugin)
} else { } else {
logger.Debug("Setting descendant plugin's signature to that of root", "plugin", plugin.ID, s.log.Debug("Setting descendant plugin's signature to that of root", "plugin", plugin.ID,
"root", plugin.Parent.ID, "signature", plugin.Signature, "rootSignature", plugin.Parent.Signature) "root", plugin.Parent.ID, "signature", plugin.Signature, "rootSignature", plugin.Parent.Signature)
plugin.Signature = plugin.Parent.Signature plugin.Signature = plugin.Parent.Signature
plugin.SignatureType = plugin.Parent.SignatureType plugin.SignatureType = plugin.Parent.SignatureType
plugin.SignatureOrg = plugin.Parent.SignatureOrg plugin.SignatureOrg = plugin.Parent.SignatureOrg
if plugin.Signature == plugins.SignatureValid { if plugin.Signature == plugins.SignatureValid {
logger.Debug("Plugin has valid signature (inherited from root)", "id", plugin.ID) s.log.Debug("Plugin has valid signature (inherited from root)", "id", plugin.ID)
return nil return nil
} }
} }
@ -48,28 +48,28 @@ func (s *Validator) Validate(plugin *plugins.Plugin) *plugins.SignatureError {
switch plugin.Signature { switch plugin.Signature {
case plugins.SignatureUnsigned: case plugins.SignatureUnsigned:
if authorized := s.authorizer.CanLoadPlugin(plugin); !authorized { if authorized := s.authorizer.CanLoadPlugin(plugin); !authorized {
logger.Debug("Plugin is unsigned", "pluginID", plugin.ID) s.log.Debug("Plugin is unsigned", "pluginID", plugin.ID)
return &plugins.SignatureError{ return &plugins.SignatureError{
PluginID: plugin.ID, PluginID: plugin.ID,
SignatureStatus: plugins.SignatureUnsigned, SignatureStatus: plugins.SignatureUnsigned,
} }
} }
logger.Warn("Permitting unsigned plugin. This is not recommended", "pluginID", plugin.ID, "pluginDir", plugin.PluginDir) s.log.Warn("Permitting unsigned plugin. This is not recommended", "pluginID", plugin.ID, "pluginDir", plugin.PluginDir)
return nil return nil
case plugins.SignatureInvalid: case plugins.SignatureInvalid:
logger.Debug("Plugin has an invalid signature", "pluginID", plugin.ID) s.log.Debug("Plugin has an invalid signature", "pluginID", plugin.ID)
return &plugins.SignatureError{ return &plugins.SignatureError{
PluginID: plugin.ID, PluginID: plugin.ID,
SignatureStatus: plugins.SignatureInvalid, SignatureStatus: plugins.SignatureInvalid,
} }
case plugins.SignatureModified: case plugins.SignatureModified:
logger.Debug("Plugin has a modified signature", "pluginID", plugin.ID) s.log.Debug("Plugin has a modified signature", "pluginID", plugin.ID)
return &plugins.SignatureError{ return &plugins.SignatureError{
PluginID: plugin.ID, PluginID: plugin.ID,
SignatureStatus: plugins.SignatureModified, SignatureStatus: plugins.SignatureModified,
} }
default: default:
logger.Debug("Plugin has an unrecognized plugin signature state", "pluginID", plugin.ID, "signature", s.log.Debug("Plugin has an unrecognized plugin signature state", "pluginID", plugin.ID, "signature",
plugin.Signature) plugin.Signature)
return &plugins.SignatureError{ return &plugins.SignatureError{
PluginID: plugin.ID, PluginID: plugin.ID,

Loading…
Cancel
Save