From 9b17cd44dce468fd73ebcb76e81e6f1945503c27 Mon Sep 17 00:00:00 2001 From: Andres Martinez Gotor Date: Tue, 6 May 2025 13:58:29 +0200 Subject: [PATCH] Advisor: Use contextual logger (#104979) --- apps/advisor/pkg/app/app.go | 29 ++++++++-------- .../pkg/app/checks/authchecks/check.go | 3 -- .../authchecks/list_format_validation.go | 3 +- .../authchecks/list_format_validation_test.go | 3 +- .../pkg/app/checks/datasourcecheck/check.go | 20 ++++------- .../app/checks/datasourcecheck/check_test.go | 11 ++---- apps/advisor/pkg/app/checks/ifaces.go | 3 +- .../pkg/app/checks/plugincheck/check.go | 14 ++++---- .../pkg/app/checks/plugincheck/check_test.go | 3 +- .../pkg/app/checkscheduler/checkscheduler.go | 34 +++++++++---------- .../app/checkscheduler/checkscheduler_test.go | 30 ++++++++-------- .../checktyperegisterer.go | 33 ++++++++++-------- .../checktyperegisterer_test.go | 6 ++-- apps/advisor/pkg/app/utils.go | 14 ++++---- apps/advisor/pkg/app/utils_test.go | 19 ++++++----- 15 files changed, 109 insertions(+), 116 deletions(-) diff --git a/apps/advisor/pkg/app/app.go b/apps/advisor/pkg/app/app.go index 5ce2128131a..a68c564093a 100644 --- a/apps/advisor/pkg/app/app.go +++ b/apps/advisor/pkg/app/app.go @@ -6,6 +6,7 @@ import ( "github.com/grafana/grafana-app-sdk/app" "github.com/grafana/grafana-app-sdk/k8s" + "github.com/grafana/grafana-app-sdk/logging" "github.com/grafana/grafana-app-sdk/resource" "github.com/grafana/grafana-app-sdk/simple" advisorv0alpha1 "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" @@ -14,9 +15,7 @@ import ( "github.com/grafana/grafana/apps/advisor/pkg/app/checkscheduler" "github.com/grafana/grafana/apps/advisor/pkg/app/checktyperegisterer" "github.com/grafana/grafana/pkg/apimachinery/identity" - "github.com/grafana/grafana/pkg/infra/log" "k8s.io/apimachinery/pkg/runtime/schema" - "k8s.io/klog/v2" ) func New(cfg app.Config) (app.App, error) { @@ -26,7 +25,7 @@ func New(cfg app.Config) (app.App, error) { return nil, fmt.Errorf("invalid config type") } checkRegistry := specificConfig.CheckRegistry - log := log.New("advisor.app") + log := logging.DefaultLogger.With("app", "advisor.app") // Prepare storage client clientGenerator := k8s.NewClientRegistry(cfg.KubeConfig, k8s.ClientConfig{}) @@ -46,7 +45,7 @@ func New(cfg app.Config) (app.App, error) { KubeConfig: cfg.KubeConfig, InformerConfig: simple.AppInformerConfig{ ErrorHandler: func(ctx context.Context, err error) { - klog.ErrorS(err, "Informer processing error") + log.WithContext(ctx).Error("Informer processing error", "error", err) }, }, ManagedKinds: []simple.AppManagedKind{ @@ -61,31 +60,33 @@ func New(cfg app.Config) (app.App, error) { } if req.Action == resource.AdmissionActionCreate { go func() { - log.Debug("Processing check", "namespace", req.Object.GetNamespace()) + logger := log.WithContext(ctx).With("check", check.ID()) + logger.Debug("Processing check", "namespace", req.Object.GetNamespace()) requester, err := identity.GetRequester(ctx) if err != nil { - log.Error("Error getting requester", "error", err) + logger.Error("Error getting requester", "error", err) return } ctx = identity.WithRequester(context.Background(), requester) - err = processCheck(ctx, client, req.Object, check) + err = processCheck(ctx, logger, client, req.Object, check) if err != nil { - log.Error("Error processing check", "error", err) + logger.Error("Error processing check", "error", err) } }() } if req.Action == resource.AdmissionActionUpdate { go func() { - log.Debug("Updating check", "namespace", req.Object.GetNamespace(), "name", req.Object.GetName()) + logger := log.WithContext(ctx).With("check", check.ID()) + logger.Debug("Updating check", "namespace", req.Object.GetNamespace(), "name", req.Object.GetName()) requester, err := identity.GetRequester(ctx) if err != nil { - log.Error("Error getting requester", "error", err) + logger.Error("Error getting requester", "error", err) return } ctx = identity.WithRequester(context.Background(), requester) - err = processCheckRetry(ctx, client, req.Object, check) + err = processCheckRetry(ctx, logger, client, req.Object, check) if err != nil { - log.Error("Error processing check retry", "error", err) + logger.Error("Error processing check retry", "error", err) } }() } @@ -111,14 +112,14 @@ func New(cfg app.Config) (app.App, error) { } // Save check types as resources - ctr, err := checktyperegisterer.New(cfg) + ctr, err := checktyperegisterer.New(cfg, log) if err != nil { return nil, err } a.AddRunnable(ctr) // Start scheduler - csch, err := checkscheduler.New(cfg) + csch, err := checkscheduler.New(cfg, log) if err != nil { return nil, err } diff --git a/apps/advisor/pkg/app/checks/authchecks/check.go b/apps/advisor/pkg/app/checks/authchecks/check.go index 9cbb2801c02..69513bfed90 100644 --- a/apps/advisor/pkg/app/checks/authchecks/check.go +++ b/apps/advisor/pkg/app/checks/authchecks/check.go @@ -5,7 +5,6 @@ import ( "fmt" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" - "github.com/grafana/grafana/pkg/infra/log" "github.com/grafana/grafana/pkg/services/ssosettings" ) @@ -17,13 +16,11 @@ var _ checks.Check = (*check)(nil) type check struct { ssoSettingsService ssosettings.Service - log log.Logger } func New(ssoSettingsService ssosettings.Service) checks.Check { return &check{ ssoSettingsService: ssoSettingsService, - log: log.New("advisor.ssosettingcheck"), } } diff --git a/apps/advisor/pkg/app/checks/authchecks/list_format_validation.go b/apps/advisor/pkg/app/checks/authchecks/list_format_validation.go index 304d478a6a7..076286935aa 100644 --- a/apps/advisor/pkg/app/checks/authchecks/list_format_validation.go +++ b/apps/advisor/pkg/app/checks/authchecks/list_format_validation.go @@ -5,6 +5,7 @@ import ( "fmt" "strings" + "github.com/grafana/grafana-app-sdk/logging" advisor "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" "github.com/grafana/grafana/pkg/services/login" @@ -47,7 +48,7 @@ func (s *listFormatValidation) Resolution() string { return "Configure the relevant SSO setting using a valid format, like space-separated (\"opt1 opt2\"), comma-separated values (\"opt1, opt2\") or JSON array format ([\"opt1\", \"opt2\"])." } -func (s *listFormatValidation) Run(ctx context.Context, _ *advisor.CheckSpec, objToCheck any) (*advisor.CheckReportFailure, error) { +func (s *listFormatValidation) Run(ctx context.Context, log logging.Logger, _ *advisor.CheckSpec, objToCheck any) (*advisor.CheckReportFailure, error) { setting, ok := objToCheck.(*models.SSOSettings) if !ok { return nil, fmt.Errorf("invalid item type %T", objToCheck) diff --git a/apps/advisor/pkg/app/checks/authchecks/list_format_validation_test.go b/apps/advisor/pkg/app/checks/authchecks/list_format_validation_test.go index 62460fde219..c850b6c058c 100644 --- a/apps/advisor/pkg/app/checks/authchecks/list_format_validation_test.go +++ b/apps/advisor/pkg/app/checks/authchecks/list_format_validation_test.go @@ -6,6 +6,7 @@ import ( "strings" "testing" + "github.com/grafana/grafana-app-sdk/logging" advisor "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" "github.com/grafana/grafana/pkg/services/login" @@ -195,7 +196,7 @@ func TestListFormatValidation_Run(t *testing.T) { for _, tt := range tests { t.Run(tt.name, func(t *testing.T) { - failure, err := validator.Run(ctx, spec, tt.objToCheck) + failure, err := validator.Run(ctx, logging.DefaultLogger, spec, tt.objToCheck) if tt.expectedError != "" { require.Error(t, err) diff --git a/apps/advisor/pkg/app/checks/datasourcecheck/check.go b/apps/advisor/pkg/app/checks/datasourcecheck/check.go index 64d34c3bfad..df1223043f4 100644 --- a/apps/advisor/pkg/app/checks/datasourcecheck/check.go +++ b/apps/advisor/pkg/app/checks/datasourcecheck/check.go @@ -5,11 +5,11 @@ import ( "errors" "fmt" + "github.com/grafana/grafana-app-sdk/logging" "github.com/grafana/grafana-plugin-sdk-go/backend" advisor "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" "github.com/grafana/grafana/pkg/apimachinery/identity" - "github.com/grafana/grafana/pkg/infra/log" "github.com/grafana/grafana/pkg/plugins" "github.com/grafana/grafana/pkg/plugins/repo" "github.com/grafana/grafana/pkg/services/datasources" @@ -30,7 +30,6 @@ type check struct { PluginContextProvider pluginContextProvider PluginClient plugins.Client PluginRepo repo.Service - log log.Logger } func New( @@ -46,7 +45,6 @@ func New( PluginContextProvider: pluginContextProvider, PluginClient: pluginClient, PluginRepo: pluginRepo, - log: log.New("advisor.datasourcecheck"), } } @@ -83,12 +81,10 @@ func (c *check) Steps() []checks.Step { &healthCheckStep{ PluginContextProvider: c.PluginContextProvider, PluginClient: c.PluginClient, - log: c.log, }, &missingPluginStep{ PluginStore: c.PluginStore, PluginRepo: c.PluginRepo, - log: c.log, }, } } @@ -112,7 +108,7 @@ func (s *uidValidationStep) Resolution() string { "target=_blank>documentation for more information or delete the data source and create a new one." } -func (s *uidValidationStep) Run(ctx context.Context, obj *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { +func (s *uidValidationStep) Run(ctx context.Context, log logging.Logger, obj *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { ds, ok := i.(*datasources.DataSource) if !ok { return nil, fmt.Errorf("invalid item type %T", i) @@ -134,7 +130,6 @@ func (s *uidValidationStep) Run(ctx context.Context, obj *advisor.CheckSpec, i a type healthCheckStep struct { PluginContextProvider pluginContextProvider PluginClient plugins.Client - log log.Logger } func (s *healthCheckStep) Title() string { @@ -153,7 +148,7 @@ func (s *healthCheckStep) ID() string { return HealthCheckStepID } -func (s *healthCheckStep) Run(ctx context.Context, obj *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { +func (s *healthCheckStep) Run(ctx context.Context, log logging.Logger, obj *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { ds, ok := i.(*datasources.DataSource) if !ok { return nil, fmt.Errorf("invalid item type %T", i) @@ -171,7 +166,7 @@ func (s *healthCheckStep) Run(ctx context.Context, obj *advisor.CheckSpec, i any return nil, nil } // Unable to check health check - s.log.Error("Failed to get plugin context", "datasource_uid", ds.UID, "error", err) + log.Error("Failed to get plugin context", "datasource_uid", ds.UID, "error", err) return nil, nil } req := &backend.CheckHealthRequest{ @@ -181,13 +176,13 @@ func (s *healthCheckStep) Run(ctx context.Context, obj *advisor.CheckSpec, i any resp, err := s.PluginClient.CheckHealth(ctx, req) if err != nil || resp.Status != backend.HealthStatusOk { if err != nil { - s.log.Debug("Failed to check health", "datasource_uid", ds.UID, "error", err) + log.Debug("Failed to check health", "datasource_uid", ds.UID, "error", err) if errors.Is(err, plugins.ErrMethodNotImplemented) || errors.Is(err, plugins.ErrPluginUnavailable) { // The plugin does not support backend health checks return nil, nil } } else { - s.log.Debug("Failed to check health", "datasource_uid", ds.UID, "status", resp.Status, "message", resp.Message) + log.Debug("Failed to check health", "datasource_uid", ds.UID, "status", resp.Status, "message", resp.Message) } return checks.NewCheckReportFailure( advisor.CheckReportFailureSeverityHigh, @@ -208,7 +203,6 @@ func (s *healthCheckStep) Run(ctx context.Context, obj *advisor.CheckSpec, i any type missingPluginStep struct { PluginStore pluginstore.Store PluginRepo repo.Service - log log.Logger } func (s *missingPluginStep) Title() string { @@ -227,7 +221,7 @@ func (s *missingPluginStep) ID() string { return MissingPluginStepID } -func (s *missingPluginStep) Run(ctx context.Context, obj *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { +func (s *missingPluginStep) Run(ctx context.Context, log logging.Logger, obj *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { ds, ok := i.(*datasources.DataSource) if !ok { return nil, fmt.Errorf("invalid item type %T", i) diff --git a/apps/advisor/pkg/app/checks/datasourcecheck/check_test.go b/apps/advisor/pkg/app/checks/datasourcecheck/check_test.go index 7c538da83f7..b1a47b9bcc6 100644 --- a/apps/advisor/pkg/app/checks/datasourcecheck/check_test.go +++ b/apps/advisor/pkg/app/checks/datasourcecheck/check_test.go @@ -5,10 +5,10 @@ import ( "errors" "testing" + "github.com/grafana/grafana-app-sdk/logging" "github.com/grafana/grafana-plugin-sdk-go/backend" advisor "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/pkg/apimachinery/identity" - "github.com/grafana/grafana/pkg/infra/log" "github.com/grafana/grafana/pkg/plugins" "github.com/grafana/grafana/pkg/plugins/repo" "github.com/grafana/grafana/pkg/services/datasources" @@ -28,7 +28,7 @@ func runChecks(check *check) ([]advisor.CheckReportFailure, error) { failures := []advisor.CheckReportFailure{} for _, step := range check.Steps() { for _, item := range items { - stepFailures, err := step.Run(ctx, &advisor.CheckSpec{}, item) + stepFailures, err := step.Run(ctx, logging.DefaultLogger, &advisor.CheckSpec{}, item) if err != nil { return nil, err } @@ -60,7 +60,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) @@ -85,7 +84,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) @@ -111,7 +109,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) @@ -136,7 +133,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) @@ -160,7 +156,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) @@ -185,7 +180,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) @@ -211,7 +205,6 @@ func TestCheck_Run(t *testing.T) { PluginClient: mockPluginClient, PluginRepo: mockPluginRepo, PluginStore: mockPluginStore, - log: log.New("advisor.datasourcecheck"), } failures, err := runChecks(check) diff --git a/apps/advisor/pkg/app/checks/ifaces.go b/apps/advisor/pkg/app/checks/ifaces.go index 0dfd13e4f61..3e9bdda2d57 100644 --- a/apps/advisor/pkg/app/checks/ifaces.go +++ b/apps/advisor/pkg/app/checks/ifaces.go @@ -3,6 +3,7 @@ package checks import ( "context" + "github.com/grafana/grafana-app-sdk/logging" advisorv0alpha1 "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" ) @@ -29,5 +30,5 @@ type Step interface { // Explains the action that needs to be taken to resolve the issue Resolution() string // Run executes the step for an item and returns a report - Run(ctx context.Context, obj *advisorv0alpha1.CheckSpec, item any) (*advisorv0alpha1.CheckReportFailure, error) + Run(ctx context.Context, log logging.Logger, obj *advisorv0alpha1.CheckSpec, item any) (*advisorv0alpha1.CheckReportFailure, error) } diff --git a/apps/advisor/pkg/app/checks/plugincheck/check.go b/apps/advisor/pkg/app/checks/plugincheck/check.go index b5d6edf09fe..94338c7245d 100644 --- a/apps/advisor/pkg/app/checks/plugincheck/check.go +++ b/apps/advisor/pkg/app/checks/plugincheck/check.go @@ -7,10 +7,10 @@ import ( "slices" "github.com/Masterminds/semver/v3" + "github.com/grafana/grafana-app-sdk/logging" advisor "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" "github.com/grafana/grafana/pkg/cmd/grafana-cli/services" - "github.com/grafana/grafana/pkg/infra/log" "github.com/grafana/grafana/pkg/plugins/repo" "github.com/grafana/grafana/pkg/services/pluginsintegration/managedplugins" "github.com/grafana/grafana/pkg/services/pluginsintegration/plugininstaller" @@ -79,7 +79,6 @@ func (c *check) Steps() []checks.Step { PluginPreinstall: c.PluginPreinstall, ManagedPlugins: c.ManagedPlugins, ProvisionedPlugins: c.ProvisionedPlugins, - log: log.New("advisor.check.plugin.update"), }, } } @@ -105,7 +104,7 @@ func (s *deprecationStep) ID() string { return DeprecationStepID } -func (s *deprecationStep) Run(ctx context.Context, _ *advisor.CheckSpec, it any) (*advisor.CheckReportFailure, error) { +func (s *deprecationStep) Run(ctx context.Context, log logging.Logger, _ *advisor.CheckSpec, it any) (*advisor.CheckReportFailure, error) { p, ok := it.(pluginstore.Plugin) if !ok { return nil, fmt.Errorf("invalid item type %T", it) @@ -145,7 +144,6 @@ type updateStep struct { ManagedPlugins managedplugins.Manager ProvisionedPlugins provisionedplugins.Manager provisionedPlugins []string - log log.Logger } func (s *updateStep) Title() string { @@ -164,7 +162,7 @@ func (s *updateStep) ID() string { return UpdateStepID } -func (s *updateStep) Run(ctx context.Context, _ *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { +func (s *updateStep) Run(ctx context.Context, log logging.Logger, _ *advisor.CheckSpec, i any) (*advisor.CheckReportFailure, error) { p, ok := i.(pluginstore.Plugin) if !ok { return nil, fmt.Errorf("invalid item type %T", i) @@ -172,19 +170,19 @@ func (s *updateStep) Run(ctx context.Context, _ *advisor.CheckSpec, i any) (*adv // Skip if it's a core plugin if p.IsCorePlugin() { - s.log.Debug("Skipping core plugin", "plugin", p.ID) + log.Debug("Skipping core plugin", "plugin", p.ID) return nil, nil } // Skip if it's managed or pinned if s.isManaged(ctx, p.ID) || s.PluginPreinstall.IsPinned(p.ID) { - s.log.Debug("Skipping managed or pinned plugin", "plugin", p.ID) + log.Debug("Skipping managed or pinned plugin", "plugin", p.ID) return nil, nil } // Skip if it's provisioned if s.isProvisioned(ctx, p.ID) { - s.log.Debug("Skipping provisioned plugin", "plugin", p.ID) + log.Debug("Skipping provisioned plugin", "plugin", p.ID) return nil, nil } diff --git a/apps/advisor/pkg/app/checks/plugincheck/check_test.go b/apps/advisor/pkg/app/checks/plugincheck/check_test.go index 34fd0b8e544..5095ac2f08a 100644 --- a/apps/advisor/pkg/app/checks/plugincheck/check_test.go +++ b/apps/advisor/pkg/app/checks/plugincheck/check_test.go @@ -4,6 +4,7 @@ import ( "context" "testing" + "github.com/grafana/grafana-app-sdk/logging" advisor "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/pkg/plugins" "github.com/grafana/grafana/pkg/plugins/repo" @@ -169,7 +170,7 @@ func TestRun(t *testing.T) { failures := []advisor.CheckReportFailure{} for _, step := range check.Steps() { for _, item := range items { - stepFailures, err := step.Run(context.Background(), &advisor.CheckSpec{}, item) + stepFailures, err := step.Run(context.Background(), logging.DefaultLogger, &advisor.CheckSpec{}, item) assert.NoError(t, err) if stepFailures != nil { failures = append(failures, *stepFailures) diff --git a/apps/advisor/pkg/app/checkscheduler/checkscheduler.go b/apps/advisor/pkg/app/checkscheduler/checkscheduler.go index 053a964259b..8e2bfc1cb23 100644 --- a/apps/advisor/pkg/app/checkscheduler/checkscheduler.go +++ b/apps/advisor/pkg/app/checkscheduler/checkscheduler.go @@ -9,14 +9,13 @@ import ( "github.com/grafana/grafana-app-sdk/app" "github.com/grafana/grafana-app-sdk/k8s" + "github.com/grafana/grafana-app-sdk/logging" "github.com/grafana/grafana-app-sdk/resource" "github.com/grafana/grafana-plugin-sdk-go/backend/gtime" advisorv0alpha1 "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checkregistry" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" - "github.com/grafana/grafana/pkg/infra/log" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" - "k8s.io/klog/v2" ) const defaultEvaluationInterval = 24 * time.Hour @@ -31,11 +30,11 @@ type Runner struct { evaluationInterval time.Duration maxHistory int namespace string - log log.Logger + log logging.Logger } // NewRunner creates a new Runner. -func New(cfg app.Config) (app.Runnable, error) { +func New(cfg app.Config, log logging.Logger) (app.Runnable, error) { // Read config specificConfig, ok := cfg.SpecificConfig.(checkregistry.AdvisorAppConfig) if !ok { @@ -68,14 +67,15 @@ func New(cfg app.Config) (app.Runnable, error) { evaluationInterval: evalInterval, maxHistory: maxHistory, namespace: namespace, - log: log.New("advisor.checkscheduler"), + log: log.With("runner", "advisor.checkscheduler"), }, nil } func (r *Runner) Run(ctx context.Context) error { lastCreated, err := r.checkLastCreated(ctx) + logger := r.log.WithContext(ctx) if err != nil { - r.log.Error("Error getting last check creation time", "error", err) + logger.Error("Error getting last check creation time", "error", err) // Wait for interval to create the next scheduled check lastCreated = time.Now() } else { @@ -83,7 +83,7 @@ func (r *Runner) Run(ctx context.Context) error { if lastCreated.IsZero() { err = r.createChecks(ctx) if err != nil { - klog.Error("Error creating new check reports", "error", err) + logger.Error("Error creating new check reports", "error", err) } else { lastCreated = time.Now() } @@ -103,12 +103,12 @@ func (r *Runner) Run(ctx context.Context) error { case <-ticker.C: err = r.createChecks(ctx) if err != nil { - klog.Error("Error creating new check reports", "error", err) + logger.Error("Error creating new check reports", "error", err) } - err = r.cleanupChecks(ctx) + err = r.cleanupChecks(ctx, logger) if err != nil { - klog.Error("Error cleaning up old check reports", "error", err) + logger.Error("Error cleaning up old check reports", "error", err) } if nextSendInterval != r.evaluationInterval { @@ -116,7 +116,7 @@ func (r *Runner) Run(ctx context.Context) error { } ticker.Reset(nextSendInterval) case <-ctx.Done(): - r.markUnprocessedChecksAsErrored(ctx) + r.markUnprocessedChecksAsErrored(ctx, logger) return ctx.Err() } } @@ -163,7 +163,7 @@ func (r *Runner) createChecks(ctx context.Context) error { } // cleanupChecks deletes the olders checks if the number of checks exceeds the limit. -func (r *Runner) cleanupChecks(ctx context.Context) error { +func (r *Runner) cleanupChecks(ctx context.Context, logger logging.Logger) error { list, err := r.client.List(ctx, r.namespace, resource.ListOptions{Limit: -1}) if err != nil { return err @@ -175,7 +175,7 @@ func (r *Runner) cleanupChecks(ctx context.Context) error { labels := check.GetLabels() checkType, ok := labels[checks.TypeLabel] if !ok { - klog.Error("Check type not found in labels", "check", check) + logger.Error("Check type not found in labels", "check", check) continue } checksByType[checkType] = append(checksByType[checkType], check) @@ -230,19 +230,19 @@ func getMaxHistory(pluginConfig map[string]string) (int, error) { return maxHistory, nil } -func (r *Runner) markUnprocessedChecksAsErrored(ctx context.Context) { +func (r *Runner) markUnprocessedChecksAsErrored(ctx context.Context, log logging.Logger) { list, err := r.client.List(ctx, r.namespace, resource.ListOptions{}) if err != nil { - r.log.Error("Error getting checks", "error", err) + log.Error("Error getting checks", "error", err) return } for _, check := range list.GetItems() { if checks.GetStatusAnnotation(check) == "" { - r.log.Error("Check is unprocessed", "check", check.GetStaticMetadata().Identifier()) + log.Error("Check is unprocessed", "check", check.GetStaticMetadata().Identifier()) err := checks.SetStatusAnnotation(ctx, r.client, check, checks.StatusAnnotationError) if err != nil { - r.log.Error("Error setting check status to error", "error", err) + log.Error("Error setting check status to error", "error", err) } } } diff --git a/apps/advisor/pkg/app/checkscheduler/checkscheduler_test.go b/apps/advisor/pkg/app/checkscheduler/checkscheduler_test.go index 16ff33102d6..03b7c18783d 100644 --- a/apps/advisor/pkg/app/checkscheduler/checkscheduler_test.go +++ b/apps/advisor/pkg/app/checkscheduler/checkscheduler_test.go @@ -8,10 +8,10 @@ import ( "testing" "time" + "github.com/grafana/grafana-app-sdk/logging" "github.com/grafana/grafana-app-sdk/resource" advisorv0alpha1 "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" - "github.com/grafana/grafana/pkg/infra/log" "github.com/stretchr/testify/assert" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" ) @@ -31,7 +31,7 @@ func TestRunner_Run(t *testing.T) { runner := &Runner{ checkRegistry: mockCheckService, client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, evaluationInterval: 1 * time.Hour, } @@ -51,7 +51,7 @@ func TestRunner_checkLastCreated_ErrorOnList(t *testing.T) { runner := &Runner{ client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } lastCreated, err := runner.checkLastCreated(context.Background()) @@ -76,7 +76,7 @@ func TestRunner_createChecks_ErrorOnCreate(t *testing.T) { runner := &Runner{ checkRegistry: mockCheckService, client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } err := runner.createChecks(context.Background()) @@ -100,7 +100,7 @@ func TestRunner_createChecks_Success(t *testing.T) { runner := &Runner{ checkRegistry: mockCheckService, client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } err := runner.createChecks(context.Background()) @@ -116,10 +116,10 @@ func TestRunner_cleanupChecks_ErrorOnList(t *testing.T) { runner := &Runner{ client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } - err := runner.cleanupChecks(context.Background()) + err := runner.cleanupChecks(context.Background(), logging.DefaultLogger) assert.Error(t, err) } @@ -137,10 +137,10 @@ func TestRunner_cleanupChecks_WithinMax(t *testing.T) { runner := &Runner{ client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } - err := runner.cleanupChecks(context.Background()) + err := runner.cleanupChecks(context.Background(), logging.DefaultLogger) assert.NoError(t, err) } @@ -167,9 +167,9 @@ func TestRunner_cleanupChecks_ErrorOnDelete(t *testing.T) { runner := &Runner{ client: mockClient, maxHistory: defaultMaxHistory, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } - err := runner.cleanupChecks(context.Background()) + err := runner.cleanupChecks(context.Background(), logging.DefaultLogger) assert.ErrorContains(t, err, "delete error") } @@ -203,9 +203,9 @@ func TestRunner_cleanupChecks_Success(t *testing.T) { runner := &Runner{ client: mockClient, maxHistory: defaultMaxHistory, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } - err := runner.cleanupChecks(context.Background()) + err := runner.cleanupChecks(context.Background(), logging.DefaultLogger) assert.NoError(t, err) assert.Equal(t, []string{"check-0"}, itemsDeleted) } @@ -274,9 +274,9 @@ func Test_markUnprocessedChecksAsErrored(t *testing.T) { } runner := &Runner{ client: mockClient, - log: log.NewNopLogger(), + log: logging.DefaultLogger, } - runner.markUnprocessedChecksAsErrored(context.Background()) + runner.markUnprocessedChecksAsErrored(context.Background(), logging.DefaultLogger) assert.Equal(t, "check-1", identifier.Name) assert.Equal(t, "/metadata/annotations", patchOperation.Path) expectedAnnotations := map[string]string{ diff --git a/apps/advisor/pkg/app/checktyperegisterer/checktyperegisterer.go b/apps/advisor/pkg/app/checktyperegisterer/checktyperegisterer.go index f8c7e222368..5487616319a 100644 --- a/apps/advisor/pkg/app/checktyperegisterer/checktyperegisterer.go +++ b/apps/advisor/pkg/app/checktyperegisterer/checktyperegisterer.go @@ -7,11 +7,11 @@ import ( "github.com/grafana/grafana-app-sdk/app" "github.com/grafana/grafana-app-sdk/k8s" + "github.com/grafana/grafana-app-sdk/logging" "github.com/grafana/grafana-app-sdk/resource" advisorv0alpha1 "github.com/grafana/grafana/apps/advisor/pkg/apis/advisor/v0alpha1" "github.com/grafana/grafana/apps/advisor/pkg/app/checkregistry" "github.com/grafana/grafana/apps/advisor/pkg/app/checks" - "github.com/grafana/grafana/pkg/infra/log" "k8s.io/apimachinery/pkg/api/errors" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" ) @@ -23,13 +23,13 @@ type Runner struct { checkRegistry checkregistry.CheckService client resource.Client namespace string - log log.Logger + log logging.Logger retryAttempts int retryDelay time.Duration } // NewRunner creates a new Runner. -func New(cfg app.Config) (app.Runnable, error) { +func New(cfg app.Config, log logging.Logger) (app.Runnable, error) { // Read config specificConfig, ok := cfg.SpecificConfig.(checkregistry.AdvisorAppConfig) if !ok { @@ -52,33 +52,34 @@ func New(cfg app.Config) (app.Runnable, error) { checkRegistry: checkRegistry, client: client, namespace: namespace, - log: log.New("advisor.checktyperegisterer"), - retryAttempts: 3, - retryDelay: time.Second * 5, + log: log.With("runner", "advisor.checktyperegisterer"), + retryAttempts: 5, + retryDelay: time.Second * 10, }, nil } -func (r *Runner) createOrUpdate(ctx context.Context, obj resource.Object) error { +func (r *Runner) createOrUpdate(ctx context.Context, log logging.Logger, obj resource.Object) error { id := obj.GetStaticMetadata().Identifier() _, err := r.client.Create(ctx, id, obj, resource.CreateOptions{}) if err != nil { if errors.IsAlreadyExists(err) { // Already exists, update - r.log.Debug("Check type already exists, updating", "identifier", id) + log.Debug("Check type already exists, updating", "identifier", id) _, err = r.client.Update(ctx, id, obj, resource.UpdateOptions{}) if err != nil { // Ignore the error, it's probably due to a race condition - r.log.Error("Error updating check type", "error", err) + log.Error("Error updating check type", "error", err) } return nil } return err } - r.log.Debug("Check type registered successfully", "identifier", id) + log.Debug("Check type registered successfully", "identifier", id) return nil } func (r *Runner) Run(ctx context.Context) error { + logger := r.log.WithContext(ctx) for _, t := range r.checkRegistry.Checks() { steps := t.Steps() stepTypes := make([]advisorv0alpha1.CheckTypeStep, len(steps)) @@ -105,17 +106,19 @@ func (r *Runner) Run(ctx context.Context) error { }, } for i := 0; i < r.retryAttempts; i++ { - err := r.createOrUpdate(ctx, obj) + err := r.createOrUpdate(ctx, logger, obj) if err != nil { - r.log.Error("Error creating check type, retrying", "error", err, "attempt", i+1) + logger.Error("Error creating check type, retrying", "error", err, "attempt", i+1) if i == r.retryAttempts-1 { - r.log.Error("Unable to register check type") + logger.Error("Unable to register check type") } else { - time.Sleep(r.retryDelay) + // Calculate exponential backoff delay: baseDelay * 2^attempt + delay := r.retryDelay * time.Duration(1<