diff --git a/cmd/main.go b/cmd/main.go index 266dd012d..e112f0c3f 100644 --- a/cmd/main.go +++ b/cmd/main.go @@ -174,8 +174,6 @@ func main() { slog.String("log_format", logCfg.Format), slog.Bool("log_add_source", logCfg.AddSource)) - _ = logger // logger is available for future use - // Logging setup (existing zap logger for controller-runtime compatibility) ctrl.SetLogger(zap.New(zap.UseFlagOptions(&opts))) @@ -202,6 +200,7 @@ func main() { if err = (&intController.ClusterManagerReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { fmt.Printf(" error - %v", err) setupLog.Error(err, "unable to create controller", "controller", "ClusterManager ") @@ -211,6 +210,7 @@ func main() { if err = (&intController.ClusterMasterReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "ClusterMaster") os.Exit(1) @@ -218,6 +218,7 @@ func main() { if err = (&intController.IndexerClusterReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "IndexerCluster") os.Exit(1) @@ -225,6 +226,7 @@ func main() { if err = (&intController.LicenseMasterReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "LicenseMaster") os.Exit(1) @@ -232,6 +234,7 @@ func main() { if err = (&intController.LicenseManagerReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "LicenseManager") os.Exit(1) @@ -239,6 +242,7 @@ func main() { if err = (&intController.MonitoringConsoleReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "MonitoringConsole") os.Exit(1) @@ -246,6 +250,7 @@ func main() { if err = (&intController.SearchHeadClusterReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "SearchHeadCluster") os.Exit(1) @@ -253,6 +258,7 @@ func main() { if err = (&intController.StandaloneReconciler{ Client: mgr.GetClient(), Scheme: mgr.GetScheme(), + Logger: logger, }).SetupWithManager(mgr); err != nil { setupLog.Error(err, "unable to create controller", "controller", "Standalone") os.Exit(1) diff --git a/internal/controller/clustermanager_controller.go b/internal/controller/clustermanager_controller.go index f149bf129..b8f73550b 100644 --- a/internal/controller/clustermanager_controller.go +++ b/internal/controller/clustermanager_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" metrics "github.com/splunk/splunk-operator/pkg/splunk/client/metrics" @@ -43,6 +45,7 @@ import ( type ClusterManagerReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=clustermanagers,verbs=get;list;watch;create;update;patch;delete @@ -75,6 +78,8 @@ func (r *ClusterManagerReconciler) Reconcile(ctx context.Context, req ctrl.Reque metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "ClusterManager")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "ClusterManager") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("clustermanager", req.NamespacedName) @@ -117,6 +122,7 @@ var ApplyClusterManager = func(ctx context.Context, client client.Client, instan } func (r *ClusterManagerReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "ClusterManager") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApi.ClusterManager{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/clustermaster_controller.go b/internal/controller/clustermaster_controller.go index 9f261f85b..4595bc7af 100644 --- a/internal/controller/clustermaster_controller.go +++ b/internal/controller/clustermaster_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" @@ -44,6 +46,7 @@ import ( type ClusterMasterReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=clustermasters,verbs=get;list;watch;create;update;patch;delete @@ -76,6 +79,8 @@ func (r *ClusterMasterReconciler) Reconcile(ctx context.Context, req ctrl.Reques metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "ClusterMaster")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "ClusterMaster") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("clustermaster", req.NamespacedName) @@ -119,6 +124,7 @@ var ApplyClusterMaster = func(ctx context.Context, client client.Client, instanc // SetupWithManager sets up the controller with the Manager. func (r *ClusterMasterReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "ClusterMaster") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApiV3.ClusterMaster{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/indexercluster_controller.go b/internal/controller/indexercluster_controller.go index bc9a6c9f5..4d7f9c663 100644 --- a/internal/controller/indexercluster_controller.go +++ b/internal/controller/indexercluster_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" @@ -44,6 +46,7 @@ import ( type IndexerClusterReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=indexerclusters,verbs=get;list;watch;create;update;patch;delete @@ -75,6 +78,8 @@ func (r *IndexerClusterReconciler) Reconcile(ctx context.Context, req ctrl.Reque metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "IndexerCluster")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "IndexerCluster") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("indexercluster", req.NamespacedName) @@ -122,6 +127,7 @@ var ApplyIndexerCluster = func(ctx context.Context, client client.Client, instan // SetupWithManager sets up the controller with the Manager. func (r *IndexerClusterReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "IndexerCluster") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApi.IndexerCluster{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/licensemanager_controller.go b/internal/controller/licensemanager_controller.go index cb749a736..c0465cede 100644 --- a/internal/controller/licensemanager_controller.go +++ b/internal/controller/licensemanager_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" metrics "github.com/splunk/splunk-operator/pkg/splunk/client/metrics" @@ -43,6 +45,7 @@ import ( type LicenseManagerReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=licensemanagers,verbs=get;list;watch;create;update;patch;delete @@ -74,6 +77,8 @@ func (r *LicenseManagerReconciler) Reconcile(ctx context.Context, req ctrl.Reque metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "LicenseManager")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "LicenseManager") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("licensemanager", req.NamespacedName) @@ -117,6 +122,7 @@ var ApplyLicenseManager = func(ctx context.Context, client client.Client, instan // SetupWithManager sets up the controller with the Manager. func (r *LicenseManagerReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "LicenseManager") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApi.LicenseManager{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/licensemaster_controller.go b/internal/controller/licensemaster_controller.go index 717632e33..4d85e8186 100644 --- a/internal/controller/licensemaster_controller.go +++ b/internal/controller/licensemaster_controller.go @@ -18,9 +18,11 @@ package controller import ( "context" + "log/slog" "time" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" @@ -44,6 +46,7 @@ import ( type LicenseMasterReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=licensemasters,verbs=get;list;watch;create;update;patch;delete @@ -75,6 +78,8 @@ func (r *LicenseMasterReconciler) Reconcile(ctx context.Context, req ctrl.Reques metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "LicenseMaster")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "LicenseMaster") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("licensemaster", req.NamespacedName) @@ -118,6 +123,7 @@ var ApplyLicenseMaster = func(ctx context.Context, client client.Client, instanc // SetupWithManager sets up the controller with the Manager. func (r *LicenseMasterReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "LicenseMaster") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApiV3.LicenseMaster{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/monitoringconsole_controller.go b/internal/controller/monitoringconsole_controller.go index 3767fcac2..30b6af8fa 100644 --- a/internal/controller/monitoringconsole_controller.go +++ b/internal/controller/monitoringconsole_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" @@ -44,6 +46,7 @@ import ( type MonitoringConsoleReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=monitoringconsoles,verbs=get;list;watch;create;update;patch;delete @@ -74,6 +77,9 @@ type MonitoringConsoleReconciler struct { func (r *MonitoringConsoleReconciler) Reconcile(ctx context.Context, req ctrl.Request) (ctrl.Result, error) { metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "MonitoringConsole")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "MonitoringConsole") + + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("monitoringconsole", req.NamespacedName) @@ -117,6 +123,7 @@ var ApplyMonitoringConsole = func(ctx context.Context, client client.Client, ins // SetupWithManager sets up the controller with the Manager. func (r *MonitoringConsoleReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "MonitoringConsole") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApi.MonitoringConsole{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/searchheadcluster_controller.go b/internal/controller/searchheadcluster_controller.go index 53d50fab9..2aeac4e92 100644 --- a/internal/controller/searchheadcluster_controller.go +++ b/internal/controller/searchheadcluster_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" "github.com/pkg/errors" metrics "github.com/splunk/splunk-operator/pkg/splunk/client/metrics" @@ -43,6 +45,7 @@ import ( type SearchHeadClusterReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=searchheadclusters,verbs=get;list;watch;create;update;patch;delete @@ -74,6 +77,8 @@ func (r *SearchHeadClusterReconciler) Reconcile(ctx context.Context, req ctrl.Re metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "SearchHeadCluster")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "SearchHeadCluster") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("searchheadcluster", req.NamespacedName) @@ -117,6 +122,7 @@ var ApplySearchHeadCluster = func(ctx context.Context, client client.Client, ins // SetupWithManager sets up the controller with the Manager. func (r *SearchHeadClusterReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "SearchHeadCluster") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApi.SearchHeadCluster{}). WithEventFilter(predicate.Or( diff --git a/internal/controller/standalone_controller.go b/internal/controller/standalone_controller.go index 93e85b7f0..38b3896cb 100644 --- a/internal/controller/standalone_controller.go +++ b/internal/controller/standalone_controller.go @@ -18,10 +18,12 @@ package controller import ( "context" + "log/slog" "time" enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/splunk/splunk-operator/internal/controller/common" + "github.com/splunk/splunk-operator/pkg/logging" appsv1 "k8s.io/api/apps/v1" corev1 "k8s.io/api/core/v1" @@ -48,6 +50,7 @@ const ( type StandaloneReconciler struct { client.Client Scheme *runtime.Scheme + Logger *slog.Logger } //+kubebuilder:rbac:groups=enterprise.splunk.com,resources=standalones,verbs=get;list;watch;create;update;patch;delete @@ -79,6 +82,8 @@ func (r *StandaloneReconciler) Reconcile(ctx context.Context, req ctrl.Request) metrics.ReconcileCounters.With(metrics.GetPrometheusLabels(req, "Standalone")).Inc() defer recordInstrumentionData(time.Now(), req, "controller", "Standalone") + ctx = logging.WithLogger(ctx, r.Logger.With("name", req.Name, "namespace", req.Namespace)) + reqLogger := log.FromContext(ctx) reqLogger = reqLogger.WithValues("standalone", req.NamespacedName) @@ -122,6 +127,7 @@ var ApplyStandalone = func(ctx context.Context, client client.Client, instance * // SetupWithManager sets up the controller with the Manager. func (r *StandaloneReconciler) SetupWithManager(mgr ctrl.Manager) error { + r.Logger = r.Logger.With("controller", "Standalone") return ctrl.NewControllerManagedBy(mgr). For(&enterpriseApi.Standalone{}). WithEventFilter(predicate.Or( diff --git a/pkg/splunk/enterprise/afwscheduler.go b/pkg/splunk/enterprise/afwscheduler.go index 2dd2fd667..f7fce87ec 100644 --- a/pkg/splunk/enterprise/afwscheduler.go +++ b/pkg/splunk/enterprise/afwscheduler.go @@ -27,12 +27,12 @@ import ( enterpriseApi "github.com/splunk/splunk-operator/api/v4" "github.com/pkg/errors" + "github.com/splunk/splunk-operator/pkg/logging" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" splutil "github.com/splunk/splunk-operator/pkg/splunk/util" appsv1 "k8s.io/api/apps/v1" "k8s.io/apimachinery/pkg/types" - "sigs.k8s.io/controller-runtime/pkg/log" ) var appPhaseInfoStatuses = map[enterpriseApi.AppPhaseStatusType]bool{ @@ -66,8 +66,7 @@ func isFanOutApplicableToCR(cr splcommon.MetaObject) bool { func (ppln *AppInstallPipeline) createAndAddPipelineWorker(ctx context.Context, phase enterpriseApi.AppPhaseType, appDeployInfo *enterpriseApi.AppDeploymentInfo, appSrcName string, podName string, appFrameworkConfig *enterpriseApi.AppFrameworkSpec, client splcommon.ControllerClient, cr splcommon.MetaObject, statefulSet *appsv1.StatefulSet) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("createAndAddPipelineWorker").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "createAndAddPipelineWorker") worker := &PipelineWorker{ appDeployInfo: appDeployInfo, @@ -80,7 +79,7 @@ func (ppln *AppInstallPipeline) createAndAddPipelineWorker(ctx context.Context, fanOut: isFanOutApplicableToCR(cr), } - scopedLog.Info("Created new worker", "Pod name", worker.targetPodName, "App name", appDeployInfo.AppName, "digest", appDeployInfo.ObjectHash, "phase", appDeployInfo.PhaseInfo.Phase, "fan out", worker.fanOut) + logger.InfoContext(ctx, "Created new worker", "Pod name", worker.targetPodName, "App name", appDeployInfo.AppName, "digest", appDeployInfo.ObjectHash, "phase", appDeployInfo.PhaseInfo.Phase, "fan out", worker.fanOut) ppln.addWorkersToPipelinePhase(ctx, phase, worker) } @@ -162,10 +161,7 @@ func getTelAppNameExtension(crKind string) (string, error) { var addTelApp = func(ctx context.Context, podExecClient splutil.PodExecClientImpl, replicas int32, cr splcommon.MetaObject) error { var err error - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("addTelApp").WithValues( - "name", cr.GetObjectMeta().GetName(), - "namespace", cr.GetObjectMeta().GetNamespace()) + logger := logging.FromContext(ctx).With("func", "addTelApp") // Create pod exec client crKind := cr.GetObjectKind().GroupVersionKind().Kind @@ -198,13 +194,13 @@ var addTelApp = func(ctx context.Context, podExecClient splutil.PodExecClientImp // Run the commands on Splunk pods err = runCustomCommandOnSplunkPods(ctx, cr, replicas, command1, podExecClient) if err != nil { - scopedLog.Error(err, "unable to run command on splunk pod") + logger.ErrorContext(ctx, "unable to run command on splunk pod", "error", err) return err } err = runCustomCommandOnSplunkPods(ctx, cr, replicas, command2, podExecClient) if err != nil { - scopedLog.Error(err, "unable to run command on splunk pod") + logger.ErrorContext(ctx, "unable to run command on splunk pod", "error", err) return err } @@ -234,11 +230,10 @@ func canAppScopeHaveInstallWorker(scope string) bool { // addWorkersToPipelinePhase adds a worker to a given pipeline phase func (ppln *AppInstallPipeline) addWorkersToPipelinePhase(ctx context.Context, phaseID enterpriseApi.AppPhaseType, workers ...*PipelineWorker) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("addWorkersToPipelinePhase").WithValues("phase", phaseID) + logger := logging.FromContext(ctx).With("func", "addWorkersToPipelinePhase", "phase", phaseID) for _, worker := range workers { - scopedLog.Info("Adding worker", "name", worker.cr.GetName(), "namespace", worker.cr.GetNamespace(), "Pod name", worker.targetPodName, "App name", worker.appDeployInfo.AppName, "digest", worker.appDeployInfo.ObjectHash) + logger.InfoContext(ctx, "Adding worker", "name", worker.cr.GetName(), "namespace", worker.cr.GetNamespace(), "Pod name", worker.targetPodName, "App name", worker.appDeployInfo.AppName, "digest", worker.appDeployInfo.ObjectHash) } ppln.pplnPhases[phaseID].mutex.Lock() ppln.pplnPhases[phaseID].q = append(ppln.pplnPhases[phaseID].q, workers...) @@ -247,8 +242,7 @@ func (ppln *AppInstallPipeline) addWorkersToPipelinePhase(ctx context.Context, p // deleteWorkerFromPipelinePhase deletes a given worker from a pipeline phase func (ppln *AppInstallPipeline) deleteWorkerFromPipelinePhase(ctx context.Context, phaseID enterpriseApi.AppPhaseType, worker *PipelineWorker) bool { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("deleteWorkerFromPipelinePhase").WithValues("phase", phaseID) + logger := logging.FromContext(ctx).With("func", "deleteWorkerFromPipelinePhase", "phase", phaseID) ppln.pplnPhases[phaseID].mutex.Lock() defer ppln.pplnPhases[phaseID].mutex.Unlock() @@ -261,7 +255,7 @@ func (ppln *AppInstallPipeline) deleteWorkerFromPipelinePhase(ctx context.Contex phaseQ = phaseQ[:len(phaseQ)-1] ppln.pplnPhases[phaseID].q = phaseQ - scopedLog.Info("Deleted worker", "name", worker.cr.GetName(), "namespace", worker.cr.GetNamespace(), "Pod name", worker.targetPodName, "phase", phaseID, "App name", worker.appDeployInfo.AppName, "digest", worker.appDeployInfo.ObjectHash) + logger.InfoContext(ctx, "Deleted worker", "name", worker.cr.GetName(), "namespace", worker.cr.GetNamespace(), "Pod name", worker.targetPodName, "phase", phaseID, "App name", worker.appDeployInfo.AppName, "digest", worker.appDeployInfo.ObjectHash) return true } } @@ -302,8 +296,7 @@ func createFanOutWorker(seedWorker *PipelineWorker, ordinalIdx int) *PipelineWor // In the case of Standalone CR with multiple replicas, Fan-out `replicas` number of new workers func (ppln *AppInstallPipeline) transitionWorkerPhase(ctx context.Context, worker *PipelineWorker, currentPhase, nextPhase enterpriseApi.AppPhaseType) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("transitionWorkerPhase").WithValues("name", worker.cr.GetName(), "namespace", worker.cr.GetNamespace(), "App name", worker.appDeployInfo.AppName, "digest", worker.appDeployInfo.ObjectHash, "pod name", worker.targetPodName, "current Phase", currentPhase, "next phase", nextPhase) + logger := logging.FromContext(ctx).With("func", "transitionWorkerPhase", "App name", worker.appDeployInfo.AppName, "current Phase", currentPhase, "next phase", nextPhase) var replicaCount int32 if worker.sts != nil { @@ -324,14 +317,14 @@ func (ppln *AppInstallPipeline) transitionWorkerPhase(ctx context.Context, worke // without affecting other pods. appDeployInfo := worker.appDeployInfo if worker.fanOut { - scopedLog.Info("Fan-out transition") + logger.InfoContext(ctx, "Fan-out transition") if currentPhase == enterpriseApi.PhaseDownload { // On a reconcile entry, processing the Standalone CR right after loading the appDeployContext from the CR status var podCopyWorkers, installWorkers []*PipelineWorker // Seems like the download just finished. Allocate Phase info if len(appDeployInfo.AuxPhaseInfo) == 0 { - scopedLog.Info("Just finished the download phase") + logger.InfoContext(ctx, "Just finished the download phase") // Create Phase info for all the statefulset Pods. appDeployInfo.AuxPhaseInfo = make([]enterpriseApi.PhaseInfo, replicaCount) @@ -344,10 +337,10 @@ func (ppln *AppInstallPipeline) transitionWorkerPhase(ctx context.Context, worke podCopyWorkers[podID] = createFanOutWorker(worker, podID) setContextForNewPhase(&appDeployInfo.AuxPhaseInfo[podID], enterpriseApi.PhasePodCopy) - scopedLog.Info("Created a new fan-out pod copy worker", "pod name", worker.targetPodName) + logger.InfoContext(ctx, "Created a new fan-out pod copy worker", "pod name", worker.targetPodName) } } else { - scopedLog.Info("Installation was already in progress for replica members") + logger.InfoContext(ctx, "Installation was already in progress for replica members") for podID := range appDeployInfo.AuxPhaseInfo { phaseInfo := &appDeployInfo.AuxPhaseInfo[podID] @@ -363,7 +356,7 @@ func (ppln *AppInstallPipeline) transitionWorkerPhase(ctx context.Context, worke } else if phaseInfo.Phase == enterpriseApi.PhasePodCopy { podCopyWorkers = append(podCopyWorkers, newWorker) } else { - scopedLog.Error(nil, "invalid phase info detected", "phase", phaseInfo.Phase, "phase status", phaseInfo.Status) + logger.ErrorContext(ctx, "invalid phase info detected", "phase", phaseInfo.Phase, "phase status", phaseInfo.Status) } } } @@ -371,11 +364,11 @@ func (ppln *AppInstallPipeline) transitionWorkerPhase(ctx context.Context, worke ppln.addWorkersToPipelinePhase(ctx, enterpriseApi.PhasePodCopy, podCopyWorkers...) ppln.addWorkersToPipelinePhase(ctx, enterpriseApi.PhaseInstall, installWorkers...) } else { - scopedLog.Error(nil, "Invalid phase detected") + logger.ErrorContext(ctx, "Invalid phase detected") } } else { - scopedLog.Info("Simple transition") + logger.InfoContext(ctx, "Simple transition") var phaseInfo *enterpriseApi.PhaseInfo if isFanOutApplicableToCR(worker.cr) { @@ -391,7 +384,7 @@ func (ppln *AppInstallPipeline) transitionWorkerPhase(ctx context.Context, worke // We have already moved the worker(s) to the required queue. // Now, safely delete the worker from the current phase queue - scopedLog.Info("Deleted worker", "phase", currentPhase) + logger.InfoContext(ctx, "Deleted worker", "phase", currentPhase) ppln.deleteWorkerFromPipelinePhase(ctx, currentPhase, worker) } @@ -417,13 +410,11 @@ func needToUseAuxPhaseInfo(worker *PipelineWorker, phaseType enterpriseApi.AppPh // getPhaseInfoByPhaseType gives the phase info suitable for a given phase func getPhaseInfoByPhaseType(ctx context.Context, worker *PipelineWorker, phaseType enterpriseApi.AppPhaseType) *enterpriseApi.PhaseInfo { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getPhaseInfoFromWorker") - if needToUseAuxPhaseInfo(worker, phaseType) { podID, err := getOrdinalValFromPodName(worker.targetPodName) if err != nil { - scopedLog.Error(err, "unable to get the pod Id", "pod name", worker.targetPodName) + logger := logging.FromContext(ctx).With("func", "getPhaseInfoByPhaseType") + logger.ErrorContext(ctx, "unable to get the pod Id", "pod name", worker.targetPodName, "error", err) return nil } @@ -435,17 +426,13 @@ func getPhaseInfoByPhaseType(ctx context.Context, worker *PipelineWorker, phaseT // updatePplnWorkerPhaseInfo updates the in-memory PhaseInfo(specifically status and retryCount) func updatePplnWorkerPhaseInfo(ctx context.Context, appDeployInfo *enterpriseApi.AppDeploymentInfo, failCount uint32, statusType enterpriseApi.AppPhaseStatusType) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("updatePplnWorkerPhaseInfo").WithValues("appName", appDeployInfo.AppName) - - scopedLog.Info("changing the status", "old status", appPhaseStatusAsStr(appDeployInfo.PhaseInfo.Status), "new status", appPhaseStatusAsStr(statusType)) + logger := logging.FromContext(ctx).With("func", "updatePplnWorkerPhaseInfo") + logger.InfoContext(ctx, "changing the status", "appName", appDeployInfo.AppName, "old status", appPhaseStatusAsStr(appDeployInfo.PhaseInfo.Status), "new status", appPhaseStatusAsStr(statusType)) appDeployInfo.PhaseInfo.FailCount = failCount appDeployInfo.PhaseInfo.Status = statusType } func (downloadWorker *PipelineWorker) createDownloadDirOnOperator(ctx context.Context) (string, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("createDownloadDirOnOperator").WithValues("appSrcName", downloadWorker.appSrcName, "appName", downloadWorker.appDeployInfo.AppName) scope := getAppSrcScope(ctx, downloadWorker.afwConfig, downloadWorker.appSrcName) kind := downloadWorker.cr.GetObjectKind().GroupVersionKind().Kind @@ -459,7 +446,8 @@ func (downloadWorker *PipelineWorker) createDownloadDirOnOperator(ctx context.Co // create the sub-directories on the volume for downloading scoped apps err := createAppDownloadDir(ctx, localPath) if err != nil { - scopedLog.Error(err, "unable to create app download directory on operator") + logger := logging.FromContext(ctx).With("func", "createDownloadDirOnOperator") + logger.ErrorContext(ctx, "unable to create app download directory on operator", "appSrcName", downloadWorker.appSrcName, "appName", downloadWorker.appDeployInfo.AppName, "error", err) } return localPath, err } @@ -477,8 +465,7 @@ func (downloadWorker *PipelineWorker) download(ctx context.Context, pplnPhase *P splunkCR := downloadWorker.cr appSrcName := downloadWorker.appSrcName - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("PipelineWorker.Download()").WithValues("name", splunkCR.GetName(), "namespace", splunkCR.GetNamespace(), "App name", downloadWorker.appDeployInfo.AppName, "objectHash", downloadWorker.appDeployInfo.ObjectHash) + logger := logging.FromContext(ctx).With("func", "download", "App name", downloadWorker.appDeployInfo.AppName) appDeployInfo := downloadWorker.appDeployInfo appName := appDeployInfo.AppName @@ -486,7 +473,7 @@ func (downloadWorker *PipelineWorker) download(ctx context.Context, pplnPhase *P localFile := getLocalAppFileName(ctx, localPath, appName, appDeployInfo.ObjectHash) remoteFile, err := getRemoteObjectKey(ctx, splunkCR, downloadWorker.afwConfig, appSrcName, appName) if err != nil { - scopedLog.Error(err, "unable to get remote object key", "appName", appName) + logger.ErrorContext(ctx, "unable to get remote object key", "appName", appName, "error", err) // increment the retry count and mark this app as download pending updatePplnWorkerPhaseInfo(ctx, appDeployInfo, appDeployInfo.PhaseInfo.FailCount+1, enterpriseApi.AppPkgDownloadPending) @@ -496,12 +483,12 @@ func (downloadWorker *PipelineWorker) download(ctx context.Context, pplnPhase *P // download the app from remote storage err = remoteDataClientMgr.DownloadApp(ctx, remoteFile, localFile, appDeployInfo.ObjectHash) if err != nil { - scopedLog.Error(err, "unable to download app", "appName", appName) + logger.ErrorContext(ctx, "unable to download app", "appName", appName, "error", err) // remove the local file err = os.RemoveAll(localFile) if err != nil { - scopedLog.Error(err, "unable to remove local file from operator") + logger.ErrorContext(ctx, "unable to remove local file from operator", "error", err) } // increment the retry count and mark this app as download pending @@ -512,14 +499,13 @@ func (downloadWorker *PipelineWorker) download(ctx context.Context, pplnPhase *P // download is successfull, update the state and reset the retry count updatePplnWorkerPhaseInfo(ctx, appDeployInfo, 0, enterpriseApi.AppPkgDownloadComplete) - scopedLog.Info("Finished downloading app") + logger.InfoContext(ctx, "Finished downloading app") } // downloadWorkerHandler schedules the download workers to download app/s func (pplnPhase *PipelinePhase) downloadWorkerHandler(ctx context.Context, ppln *AppInstallPipeline, maxWorkers uint64, scheduleDownloadsWaiter *sync.WaitGroup) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("downloadWorkerHandler") + logger := logging.FromContext(ctx).With("func", "downloadWorkerHandler") // derive a counting semaphore from the channel to represent worker run pool var downloadWorkersRunPool = make(chan struct{}, maxWorkers) @@ -533,13 +519,13 @@ downloadWork: case downloadWorker, ok := <-pplnPhase.msgChannel: // if channel is closed, then just break from here as we have nothing to read if !ok { - scopedLog.Info("msgChannel is closed by downloadPhaseManager, hence nothing to read.") + logger.InfoContext(ctx, "msgChannel is closed by downloadPhaseManager, hence nothing to read.") break downloadWork } // do not redownload the app if it is already downloaded if isAppAlreadyDownloaded(ctx, downloadWorker) { - scopedLog.Info("app is already downloaded on operator pod, hence skipping it.", "appSrcName", downloadWorker.appSrcName, "appName", downloadWorker.appDeployInfo.AppName) + logger.InfoContext(ctx, "app is already downloaded on operator pod, hence skipping it.", "appSrcName", downloadWorker.appSrcName, "appName", downloadWorker.appDeployInfo.AppName) // update the state to be download complete updatePplnWorkerPhaseInfo(ctx, downloadWorker.appDeployInfo, 0, enterpriseApi.AppPkgDownloadComplete) <-downloadWorkersRunPool @@ -550,7 +536,7 @@ downloadWork: err := reserveStorage(downloadWorker.appDeployInfo.Size) if err != nil { - scopedLog.Error(err, "insufficient storage for the app pkg download. appSrcName: %s, app name: %s, app size: %d Bytes", downloadWorker.appSrcName, downloadWorker.appDeployInfo.AppName, downloadWorker.appDeployInfo.Size) + logger.ErrorContext(ctx, "insufficient storage for the app pkg download", "appSrcName", downloadWorker.appSrcName, "appName", downloadWorker.appDeployInfo.AppName, "appSize", downloadWorker.appDeployInfo.Size, "error", err) // setting isActive to false here so that downloadPhaseManager can take care of it. downloadWorker.isActive = false <-downloadWorkersRunPool @@ -565,7 +551,7 @@ downloadWork: // create the sub-directories on the volume for downloading scoped apps localPath, err := downloadWorker.createDownloadDirOnOperator(ctx) if err != nil { - scopedLog.Error(err, "unable to create download directory on operator", "appSrcName", downloadWorker.appSrcName, "appName", appDeployInfo.AppName) + logger.ErrorContext(ctx, "unable to create download directory on operator", "appSrcName", downloadWorker.appSrcName, "appName", appDeployInfo.AppName, "error", err) // increment the retry count and mark this app as download pending updatePplnWorkerPhaseInfo(ctx, appDeployInfo, appDeployInfo.PhaseInfo.FailCount+1, enterpriseApi.AppPkgDownloadPending) @@ -577,7 +563,7 @@ downloadWork: // get the remoteDataClientMgr instance remoteDataClientMgr, err := getRemoteDataClientMgr(ctx, downloadWorker.client, downloadWorker.cr, downloadWorker.afwConfig, downloadWorker.appSrcName) if err != nil { - scopedLog.Error(err, "unable to get remote data client manager") + logger.ErrorContext(ctx, "unable to get remote data client manager", "error", err) // increment the retry count and mark this app as download error updatePplnWorkerPhaseInfo(ctx, appDeployInfo, appDeployInfo.PhaseInfo.FailCount+1, enterpriseApi.AppPkgDownloadError) @@ -596,7 +582,7 @@ downloadWork: } default: // All the workers are busy, check after one second - scopedLog.Info("All the workers are busy, we will check again after one second") + logger.DebugContext(ctx, "All the workers are busy, we will check again after one second") time.Sleep(1 * time.Second) } @@ -615,26 +601,24 @@ downloadWork: // 2. wait for the handler to finish all its work // 3. mark the phase as done/complete func (ppln *AppInstallPipeline) shutdownPipelinePhase(ctx context.Context, phaseManager string, pplnPhase *PipelinePhase, perPhaseWaiter *sync.WaitGroup) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName(phaseManager) + logger := logging.FromContext(ctx).With("func", phaseManager) // close the msgChannel close(pplnPhase.msgChannel) // wait for the handler code to finish its work - scopedLog.Info("Waiting for the workers to finish") + logger.InfoContext(ctx, "Waiting for the workers to finish") perPhaseWaiter.Wait() // mark the phase as done/complete - scopedLog.Info("All the workers finished") + logger.InfoContext(ctx, "All the workers finished") ppln.phaseWaiter.Done() } // downloadPhaseManager creates download phase manager for the install pipeline func (ppln *AppInstallPipeline) downloadPhaseManager(ctx context.Context) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("downloadPhaseManager") - scopedLog.Info("Starting Download phase manager") + logger := logging.FromContext(ctx).With("func", "downloadPhaseManager") + logger.InfoContext(ctx, "Starting Download phase manager") pplnPhase := ppln.pplnPhases[enterpriseApi.PhaseDownload] @@ -654,7 +638,7 @@ downloadPhase: select { case _, channelOpen := <-ppln.sigTerm: if !channelOpen { - scopedLog.Info("Received the termination request from the scheduler") + logger.InfoContext(ctx, "Received the termination request from the scheduler") break downloadPhase } @@ -671,7 +655,7 @@ downloadPhase: downloadWorker.waiter = &pplnPhase.workerWaiter select { case pplnPhase.msgChannel <- downloadWorker: - scopedLog.Info("Download worker got a run slot", "name", downloadWorker.cr.GetName(), "namespace", downloadWorker.cr.GetNamespace(), "App name", downloadWorker.appDeployInfo.AppName, "digest", downloadWorker.appDeployInfo.ObjectHash) + logger.InfoContext(ctx, "Download worker got a run slot", "name", downloadWorker.cr.GetName(), "namespace", downloadWorker.cr.GetNamespace(), "App name", downloadWorker.appDeployInfo.AppName, "digest", downloadWorker.appDeployInfo.ObjectHash) downloadWorker.isActive = true default: downloadWorker.waiter = nil @@ -686,8 +670,7 @@ downloadPhase: // markWorkerPhaseInstallationComplete marks the worker phase as app package installation complete func markWorkerPhaseInstallationComplete(ctx context.Context, phaseInfo *enterpriseApi.PhaseInfo, worker *PipelineWorker) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("markWorkerPhaseInstallationComplete") + logger := logging.FromContext(ctx).With("func", "markWorkerPhaseInstallationComplete") // Set auxphase info status for fanout CRs and phaseinfo status for others phaseInfo.Status = enterpriseApi.AppPkgInstallComplete @@ -697,7 +680,7 @@ func markWorkerPhaseInstallationComplete(ctx context.Context, phaseInfo *enterpr // phaseinfo as install complete if isFanOutApplicableToCR(worker.cr) { if isAppInstallationCompleteOnAllReplicas(worker.appDeployInfo.AuxPhaseInfo) { - scopedLog.Info("app pkg installed on all the pods", "app pkg", worker.appDeployInfo.AppName) + logger.InfoContext(ctx, "app pkg installed on all the pods", "app pkg", worker.appDeployInfo.AppName) worker.appDeployInfo.PhaseInfo.Phase = enterpriseApi.PhaseInstall worker.appDeployInfo.PhaseInfo.Status = enterpriseApi.AppPkgInstallComplete @@ -711,8 +694,7 @@ func markWorkerPhaseInstallationComplete(ctx context.Context, phaseInfo *enterpr func installApp(rctx context.Context, localCtx *localScopePlaybookContext, cr splcommon.MetaObject, phaseInfo *enterpriseApi.PhaseInfo) error { worker := localCtx.worker - reqLogger := log.FromContext(rctx) - scopedLog := reqLogger.WithName("installApp").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) + logger := logging.FromContext(rctx).With("func", "installApp", "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) // if the app name is app1.tgz and hash is "abcd1234", then appPkgFileName is app1.tgz_abcd1234 appPkgFileName := getAppPackageName(worker) @@ -721,7 +703,7 @@ func installApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp appPkgPathOnPod := filepath.Join(appBktMnt, worker.appSrcName, appPkgFileName) if !checkIfFileExistsOnPod(rctx, cr, appPkgPathOnPod, localCtx.podExecClient) { - scopedLog.Error(nil, "app pkg missing on Pod", "app pkg path", appPkgPathOnPod) + logger.ErrorContext(rctx, "app pkg missing on Pod", "app pkg path", appPkgPathOnPod) phaseInfo.Status = enterpriseApi.AppPkgMissingOnPodError return fmt.Errorf("app pkg missing on Pod. app pkg path: %s", appPkgPathOnPod) @@ -730,10 +712,10 @@ func installApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp if worker.appDeployInfo.AppPackageTopFolder == "" { appTopFolder, err := getAppTopFolderFromPackage(rctx, cr, appPkgPathOnPod, localCtx.podExecClient) if err != nil { - scopedLog.Error(err, "local scoped app package install failed while getting name of installed app") + logger.ErrorContext(rctx, "local scoped app package install failed while getting name of installed app", "error", err) return err } - scopedLog.Info("app top folder", "name", appTopFolder) + logger.InfoContext(rctx, "app top folder", "name", appTopFolder) worker.appDeployInfo.AppPackageTopFolder = appTopFolder } @@ -747,16 +729,16 @@ func installApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp // we can come to this block if post installation failed // e.g. es post installation failed but es app was already installed - scopedLog.Info("Check if app is already installed ", "name", worker.appDeployInfo.AppPackageTopFolder) + logger.InfoContext(rctx, "Check if app is already installed", "name", worker.appDeployInfo.AppPackageTopFolder) appInstalled, err := isAppAlreadyInstalled(rctx, cr, localCtx.podExecClient, worker.appDeployInfo.AppPackageTopFolder) if err != nil { - scopedLog.Error(err, "local scoped app package install failed while checking if app is already installed") + logger.ErrorContext(rctx, "local scoped app package install failed while checking if app is already installed", "error", err) return err } if appInstalled { - scopedLog.Info("Not reinstalling app as it is already installed.") + logger.InfoContext(rctx, "Not reinstalling app as it is already installed.") return nil } @@ -770,13 +752,13 @@ func installApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp // TODO(patrykw-splunk): remove this once we have confirm that we are not using stderr for error detection at all // Log stderr content for debugging but don't use it for error detection if stdErr != "" { - scopedLog.Info("App install command stderr output (informational only)", "stderr", stdErr) + logger.InfoContext(rctx, "App install command stderr output (informational only)", "stderr", stdErr) } // Check only the actual command execution error, not stderr content if err != nil { phaseInfo.FailCount++ - scopedLog.Error(err, "local scoped app package install failed", "stdout", stdOut, "stderr", stdErr, "app pkg path", appPkgPathOnPod, "failCount", phaseInfo.FailCount) + logger.ErrorContext(rctx, "local scoped app package install failed", "stdout", stdOut, "stderr", stdErr, "app pkg path", appPkgPathOnPod, "failCount", phaseInfo.FailCount, "error", err) return fmt.Errorf("local scoped app package install failed. stdOut: %s, stdErr: %s, app pkg path: %s, failCount: %d", stdOut, stdErr, appPkgPathOnPod, phaseInfo.FailCount) } @@ -787,10 +769,9 @@ func installApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp // the installed app name is supposed to be same as // name of top folder (AppTopFolder) func isAppAlreadyInstalled(ctx context.Context, cr splcommon.MetaObject, podExecClient splutil.PodExecClientImpl, appTopFolder string) (bool, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("isAppAlreadyInstalled").WithValues("podName", podExecClient.GetTargetPodName(), "namespace", cr.GetNamespace()).WithValues("AppTopFolder", appTopFolder) + logger := logging.FromContext(ctx).With("func", "isAppAlreadyInstalled", "AppTopFolder", appTopFolder) - scopedLog.Info("check app's installation state") + logger.DebugContext(ctx, "check app's installation state") command := fmt.Sprintf("/opt/splunk/bin/splunk list app %s -auth admin:`cat /mnt/splunk-secrets/password`| grep ENABLED", appTopFolder) @@ -808,7 +789,7 @@ func isAppAlreadyInstalled(ctx context.Context, cr splcommon.MetaObject, podExec // Log any other stderr content for debugging but don't use it for error detection if stdErr != "" { - scopedLog.Info("Command stderr output (informational only)", "stderr", stdErr) + logger.InfoContext(ctx, "Command stderr output (informational only)", "stderr", stdErr) } // Now check the actual command result @@ -820,7 +801,7 @@ func isAppAlreadyInstalled(ctx context.Context, cr splcommon.MetaObject, podExec // Check for grep exit code 1 (pattern not found) if strings.Contains(errMsg, "exit status 1") || strings.Contains(errMsg, "command terminated with exit code 1") { // grep exit code 1 means "ENABLED" pattern not found - app exists but is not enabled - scopedLog.Info("App not enabled - grep pattern not found", "stdout", stdOut, "stderr", stdErr) + logger.InfoContext(ctx, "App not enabled - grep pattern not found", "stdout", stdOut, "stderr", stdErr) return false, nil } @@ -835,22 +816,21 @@ func isAppAlreadyInstalled(ctx context.Context, cr splcommon.MetaObject, podExec return false, fmt.Errorf("command succeeded but no output received, command: %s", command) } - scopedLog.Info("App installation state check successful - app is enabled", "appStatus", strings.TrimSpace(stdOut)) + logger.InfoContext(ctx, "App installation state check successful - app is enabled", "appStatus", strings.TrimSpace(stdOut)) return true, nil } // get the name of top folder from the package. // this name is later used as installed app name func getAppTopFolderFromPackage(rctx context.Context, cr splcommon.MetaObject, appPkgPathOnPod string, podExecClient splutil.PodExecClientImpl) (string, error) { - reqLogger := log.FromContext(rctx) - scopedLog := reqLogger.WithName("getAppTopFolderFromPackage").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "appPkgPathOnPod", appPkgPathOnPod) + logger := logging.FromContext(rctx).With("func", "getAppTopFolderFromPackage", "appPkgPathOnPod", appPkgPathOnPod) command := fmt.Sprintf("tar tf %s|head -1|cut -d/ -f1", appPkgPathOnPod) streamOptions := splutil.NewStreamOptionsObject(command) stdOut, stdErr, err := podExecClient.RunPodExecCommand(rctx, streamOptions, []string{"/bin/sh"}) - scopedLog.Info("Pod exec result", "stdOut", stdOut) + logger.InfoContext(rctx, "Pod exec result", "stdOut", stdOut) if stdErr != "" || err != nil { // CSPL-2598 - Log warnings/errors. @@ -861,7 +841,7 @@ func getAppTopFolderFromPackage(rctx context.Context, cr splcommon.MetaObject, a // The onus falls on the user to make sure the app packages are tarred appropriately // to avoid the re-installation cycles as it is prudent to continue // to the install step for harmless warnings - scopedLog.Error(err, "error in tar contents list, but app installation will continue", "stdOut", stdOut, "stdErr", stdErr, "command", command, "appPkgPathOnPod", appPkgPathOnPod) + logger.ErrorContext(rctx, "error in tar contents list, but app installation will continue", "stdOut", stdOut, "stdErr", stdErr, "command", command, "error", err) if stdOut == "" { return "Empty app package name, could not get installed app name", err } @@ -876,8 +856,7 @@ func getAppTopFolderFromPackage(rctx context.Context, cr splcommon.MetaObject, a func cleanupApp(rctx context.Context, localCtx *localScopePlaybookContext, cr splcommon.MetaObject, phaseInfo *enterpriseApi.PhaseInfo) error { worker := localCtx.worker - reqLogger := log.FromContext(rctx) - scopedLog := reqLogger.WithName("cleanupApp").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) + logger := logging.FromContext(rctx).With("func", "cleanupApp", "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) // if the app name is app1.tgz and hash is "abcd1234", then appPkgFileName is app1.tgz_abcd1234 appPkgFileName := getAppPackageName(worker) @@ -890,10 +869,10 @@ func cleanupApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp streamOptions := splutil.NewStreamOptionsObject(command) stdOut, stdErr, err := localCtx.podExecClient.RunPodExecCommand(rctx, streamOptions, []string{"/bin/sh"}) if stdErr != "" || err != nil { - scopedLog.Error(err, "app pkg deletion failed", "stdout", stdOut, "stderr", stdErr, "app pkg path", appPkgPathOnPod) + logger.ErrorContext(rctx, "app pkg deletion failed", "stdout", stdOut, "stderr", stdErr, "app pkg path", appPkgPathOnPod, "error", err) return fmt.Errorf("app pkg deletion failed. stdOut: %s, stdErr: %s, app pkg path: %s", stdOut, stdErr, appPkgPathOnPod) } - scopedLog.Info("App package deleted from target pod", "command", command) + logger.InfoContext(rctx, "App package deleted from target pod", "command", command) // Try to remove the app package from the Operator Pod tryAppPkgCleanupFromOperatorPod(rctx, worker) @@ -905,8 +884,7 @@ func cleanupApp(rctx context.Context, localCtx *localScopePlaybookContext, cr sp func (localCtx *localScopePlaybookContext) runPlaybook(rctx context.Context) error { worker := localCtx.worker cr := worker.cr - reqLogger := log.FromContext(rctx) - scopedLog := reqLogger.WithName("localScopePlaybookContext.runPlaybook").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) + logger := logging.FromContext(rctx).With("func", "runPlaybook", "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) defer func() { <-localCtx.sem @@ -920,7 +898,7 @@ func (localCtx *localScopePlaybookContext) runPlaybook(rctx context.Context) err // Call the API to install an app err := installApp(rctx, localCtx, cr, phaseInfo) if err != nil { - scopedLog.Error(err, "app package installation error") + logger.ErrorContext(rctx, "app package installation error", "error", err) return fmt.Errorf("app pkg installation failed. error %s", err.Error()) } @@ -930,7 +908,7 @@ func (localCtx *localScopePlaybookContext) runPlaybook(rctx context.Context) err // Call the API to cleanup the app err = cleanupApp(rctx, localCtx, cr, phaseInfo) if err != nil { - scopedLog.Error(err, "app package cleanup error") + logger.ErrorContext(rctx, "app package cleanup error", "error", err) return fmt.Errorf("app pkg cleanup failed. error %s", err.Error()) } @@ -939,9 +917,7 @@ func (localCtx *localScopePlaybookContext) runPlaybook(rctx context.Context) err // extractClusterScopedAppOnPod untars the given app package to the bundle push location func extractClusterScopedAppOnPod(ctx context.Context, worker *PipelineWorker, appSrcScope string, appPkgPathOnPod, appPkgLocalPath string, podExecClient splutil.PodExecClientImpl) error { - cr := worker.cr - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("extractClusterScopedAppOnPod").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "app name", worker.appDeployInfo.AppName) + logger := logging.FromContext(ctx).With("func", "extractClusterScopedAppOnPod", "app name", worker.appDeployInfo.AppName) var stdOut, stdErr string var err error @@ -949,7 +925,7 @@ func extractClusterScopedAppOnPod(ctx context.Context, worker *PipelineWorker, a clusterAppsPath := getClusterScopedAppsLocOnPod(worker.cr) if clusterAppsPath == "" { // This should never happen - scopedLog.Error(nil, "could not find the cluster scoped apps location on the Pod") + logger.ErrorContext(ctx, "could not find the cluster scoped apps location on the Pod") return err } @@ -976,8 +952,7 @@ func extractClusterScopedAppOnPod(ctx context.Context, worker *PipelineWorker, a // runPodCopyWorker runs one pod copy worker func runPodCopyWorker(ctx context.Context, worker *PipelineWorker, ch chan struct{}) { cr := worker.cr - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("runPodCopyWorker").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "app name", worker.appDeployInfo.AppName, "pod", worker.targetPodName) + logger := logging.FromContext(ctx).With("func", "runPodCopyWorker", "app name", worker.appDeployInfo.AppName, "pod", worker.targetPodName) defer func() { <-ch worker.isActive = false @@ -996,7 +971,7 @@ func runPodCopyWorker(ctx context.Context, worker *PipelineWorker, ch chan struc _, err := os.Stat(appPkgLocalPath) if err != nil { // Move the worker to download phase - scopedLog.Error(err, "app package is missing", "pod name", worker.targetPodName) + logger.ErrorContext(ctx, "app package is missing", "pod name", worker.targetPodName, "error", err) phaseInfo.Status = enterpriseApi.AppPkgMissingFromOperator return } @@ -1006,7 +981,7 @@ func runPodCopyWorker(ctx context.Context, worker *PipelineWorker, ch chan struc stdOut, stdErr, err := CopyFileToPod(ctx, worker.client, cr.GetNamespace(), appPkgLocalPath, appPkgPathOnPod, podExecClient) if err != nil { phaseInfo.FailCount++ - scopedLog.Error(err, "app package pod copy failed", "stdout", stdOut, "stderr", stdErr, "failCount", phaseInfo.FailCount) + logger.ErrorContext(ctx, "app package pod copy failed", "stdout", stdOut, "stderr", stdErr, "failCount", phaseInfo.FailCount, "error", err) return } @@ -1014,19 +989,18 @@ func runPodCopyWorker(ctx context.Context, worker *PipelineWorker, ch chan struc err = extractClusterScopedAppOnPod(ctx, worker, appSrcScope, appPkgPathOnPod, appPkgLocalPath, podExecClient) if err != nil { phaseInfo.FailCount++ - scopedLog.Error(err, "extracting the app package on pod failed", "failCount", phaseInfo.FailCount) + logger.ErrorContext(ctx, "extracting the app package on pod failed", "failCount", phaseInfo.FailCount, "error", err) return } } - scopedLog.Info("podCopy complete", "app pkg path", appPkgPathOnPod) + logger.InfoContext(ctx, "podCopy complete", "app pkg path", appPkgPathOnPod) phaseInfo.Status = enterpriseApi.AppPkgPodCopyComplete } // podCopyWorkerHandler fetches and runs the pod copy workers func (pplnPhase *PipelinePhase) podCopyWorkerHandler(ctx context.Context, handlerWaiter *sync.WaitGroup, numPodCopyRunners int) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("podCopyWorkerHandler") + logger := logging.FromContext(ctx).With("func", "podCopyWorkerHandler") defer handlerWaiter.Done() // Using the channel, derive a counting semaphore called podCopyRunPool that represents worker run pool @@ -1044,7 +1018,7 @@ podCopyHandler: case worker, channelOpen := <-pplnPhase.msgChannel: if !channelOpen { // Channel is closed, so, do not handle any more workers - scopedLog.Info("worker channel closed") + logger.InfoContext(ctx, "worker channel closed") break podCopyHandler } @@ -1053,7 +1027,7 @@ podCopyHandler: go runPodCopyWorker(ctx, worker, podCopyWorkerPool) } else { /// This should never happen - scopedLog.Error(nil, "invalid worker reference") + logger.ErrorContext(ctx, "invalid worker reference") <-podCopyWorkerPool } @@ -1069,16 +1043,15 @@ podCopyHandler: } // Wait for all the workers to finish - scopedLog.Info("Waiting for all the workers to finish") + logger.InfoContext(ctx, "Waiting for all the workers to finish") pplnPhase.workerWaiter.Wait() - scopedLog.Info("All the workers finished") + logger.InfoContext(ctx, "All the workers finished") } // podCopyPhaseManager creates pod copy phase manager for the install pipeline func (ppln *AppInstallPipeline) podCopyPhaseManager(ctx context.Context) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("podCopyPhaseManager") - scopedLog.Info("Starting Pod copy phase manager") + logger := logging.FromContext(ctx).With("func", "podCopyPhaseManager") + logger.InfoContext(ctx, "Starting Pod copy phase manager") var handlerWaiter sync.WaitGroup pplnPhase := ppln.pplnPhases[enterpriseApi.PhasePodCopy] @@ -1098,7 +1071,7 @@ podCopyPhase: select { case _, channelOpen := <-ppln.sigTerm: if !channelOpen { - scopedLog.Info("Received the termination request from the scheduler") + logger.InfoContext(ctx, "Received the termination request from the scheduler") break podCopyPhase } @@ -1122,7 +1095,7 @@ podCopyPhase: podCopyWorker.waiter = &pplnPhase.workerWaiter select { case pplnPhase.msgChannel <- podCopyWorker: - scopedLog.Info("Pod copy worker got a run slot", "name", podCopyWorker.cr.GetName(), "namespace", podCopyWorker.cr.GetNamespace(), "pod name", podCopyWorker.targetPodName, "App name", podCopyWorker.appDeployInfo.AppName, "digest", podCopyWorker.appDeployInfo.ObjectHash) + logger.InfoContext(ctx, "Pod copy worker got a run slot", "name", podCopyWorker.cr.GetName(), "namespace", podCopyWorker.cr.GetNamespace(), "pod name", podCopyWorker.targetPodName, "App name", podCopyWorker.appDeployInfo.AppName, "digest", podCopyWorker.appDeployInfo.ObjectHash) podCopyWorker.isActive = true default: podCopyWorker.waiter = nil @@ -1137,11 +1110,10 @@ podCopyPhase: // getInstallSlotForPod tries to allocate a local scoped install slot for a pod func getInstallSlotForPod(ctx context.Context, installTracker []chan struct{}, podName string) bool { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getInstallSlotForPod") + logger := logging.FromContext(ctx).With("func", "getInstallSlotForPod") podID, err := getOrdinalValFromPodName(podName) if err != nil { - scopedLog.Error(err, "unable to derive podId for podname", podName) + logger.ErrorContext(ctx, "unable to derive podId for podname", "podName", podName, "error", err) return false } @@ -1155,18 +1127,17 @@ func getInstallSlotForPod(ctx context.Context, installTracker []chan struct{}, p // freeInstallSlotForPod frees up an install slot for a pod func freeInstallSlotForPod(ctx context.Context, installTracker []chan struct{}, podName string) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("freeInstallSlotForPod") + logger := logging.FromContext(ctx).With("func", "freeInstallSlotForPod") podID, err := getOrdinalValFromPodName(podName) if err != nil { - scopedLog.Error(err, "unable to derive podId for podname", podName) + logger.ErrorContext(ctx, "unable to derive podId for podname", "podName", podName, "error", err) return } select { case <-installTracker[podID]: default: - scopedLog.Error(nil, "trying to free an install slot without even allocating it") + logger.ErrorContext(ctx, "trying to free an install slot without even allocating it") } } @@ -1215,8 +1186,7 @@ func tryAppPkgCleanupFromOperatorPod(ctx context.Context, installWorker *Pipelin // installWorkerHandler fetches and runs the install workers // local scope installs are handled first, then the cluster scoped apps are considered for bundle push func (pplnPhase *PipelinePhase) installWorkerHandler(ctx context.Context, ppln *AppInstallPipeline, handlerWaiter *sync.WaitGroup, installTracker []chan struct{}) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("installWorkerHandler") + logger := logging.FromContext(ctx).With("func", "installWorkerHandler") defer handlerWaiter.Done() installHandler: @@ -1225,7 +1195,7 @@ installHandler: case installWorker, channelOpen := <-pplnPhase.msgChannel: if !channelOpen { // Channel is closed, so, do not handle any more workers - scopedLog.Info("worker channel closed") + logger.InfoContext(ctx, "worker channel closed") break installHandler } @@ -1237,7 +1207,7 @@ installHandler: // Get app source spec appSrcSpec, err := getAppSrcSpec(installWorker.afwConfig.AppSources, installWorker.appSrcName) if err != nil { - scopedLog.Error(err, "getting app source spec failed while installing app app src name %s", installWorker.appSrcName) + logger.ErrorContext(ctx, "getting app source spec failed while installing app", "appSrcName", installWorker.appSrcName, "error", err) } // Get app source scope @@ -1256,11 +1226,11 @@ installHandler: go iwctx.runPlaybook(ctx) } else { <-installTracker[podID] - scopedLog.Error(nil, "unable to get install worker context. app name %s", installWorker.appDeployInfo.AppName) + logger.ErrorContext(ctx, "unable to get install worker context", "app name", installWorker.appDeployInfo.AppName) } } else { // This should never happen - scopedLog.Error(nil, "invalid worker reference") + logger.ErrorContext(ctx, "invalid worker reference") } default: @@ -1280,7 +1250,7 @@ installHandler: if ctxt != nil { ctxt.runPlaybook(ctx) } else { - scopedLog.Error(nil, "unable to get the cluster scoped playbook context, kind: %s, name: %s", ppln.cr.GroupVersionKind().Kind, ppln.cr.GetName()) + logger.ErrorContext(ctx, "unable to get the cluster scoped playbook context", "kind", ppln.cr.GroupVersionKind().Kind, "name", ppln.cr.GetName()) } } else { break @@ -1291,16 +1261,15 @@ installHandler: } // Wait for all the workers to finish - scopedLog.Info("Waiting for all the workers to finish") + logger.InfoContext(ctx, "Waiting for all the workers to finish") pplnPhase.workerWaiter.Wait() - scopedLog.Info("All the workers finished") + logger.InfoContext(ctx, "All the workers finished") } // installPhaseManager creates install phase manager for the afw installation pipeline func (ppln *AppInstallPipeline) installPhaseManager(ctx context.Context) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("installPhaseManager") - scopedLog.Info("Starting Install phase manager") + logger := logging.FromContext(ctx).With("func", "installPhaseManager") + logger.InfoContext(ctx, "Starting Install phase manager") var handlerWaiter sync.WaitGroup @@ -1333,7 +1302,7 @@ installPhase: select { case _, channelOpen := <-ppln.sigTerm: if !channelOpen { - scopedLog.Info("Received the termination request from the scheduler") + logger.InfoContext(ctx, "Received the termination request from the scheduler") break installPhase } @@ -1343,7 +1312,7 @@ installPhase: // Cluster scope has only bundle push no workers to install appScope := getAppSrcScope(ctx, installWorker.afwConfig, installWorker.appSrcName) if !canAppScopeHaveInstallWorker(appScope) { - scopedLog.Error(nil, "Install worker with incorrect scope", "name", installWorker.cr.GetName(), "namespace", installWorker.cr.GetNamespace(), "pod name", installWorker.targetPodName, "App name", installWorker.appDeployInfo.AppName, "digest", installWorker.appDeployInfo.ObjectHash, "scope", appScope) + logger.ErrorContext(ctx, "Install worker with incorrect scope", "name", installWorker.cr.GetName(), "namespace", installWorker.cr.GetNamespace(), "pod name", installWorker.targetPodName, "App name", installWorker.appDeployInfo.AppName, "digest", installWorker.appDeployInfo.ObjectHash, "scope", appScope) continue } @@ -1353,7 +1322,7 @@ installPhase: // For fanout CRs, also update the main PhaseInfo to reflect the failure if isFanOutApplicableToCR(installWorker.cr) { - scopedLog.Info("Max retries reached for fanout CR - updating main phase info", "app", installWorker.appDeployInfo.AppName, "failCount", phaseInfo.FailCount) + logger.InfoContext(ctx, "Max retries reached for fanout CR - updating main phase info", "app", installWorker.appDeployInfo.AppName, "failCount", phaseInfo.FailCount) installWorker.appDeployInfo.PhaseInfo.Phase = enterpriseApi.PhaseInstall installWorker.appDeployInfo.PhaseInfo.Status = enterpriseApi.AppPkgInstallError installWorker.appDeployInfo.DeployStatus = enterpriseApi.DeployStatusError @@ -1369,7 +1338,7 @@ installPhase: installWorker.waiter = &pplnPhase.workerWaiter select { case pplnPhase.msgChannel <- installWorker: - scopedLog.Info("Install worker got a run slot", "name", installWorker.cr.GetName(), "namespace", installWorker.cr.GetNamespace(), "pod name", installWorker.targetPodName, "App name", installWorker.appDeployInfo.AppName, "digest", installWorker.appDeployInfo.ObjectHash) + logger.InfoContext(ctx, "Install worker got a run slot", "name", installWorker.cr.GetName(), "namespace", installWorker.cr.GetNamespace(), "pod name", installWorker.targetPodName, "App name", installWorker.appDeployInfo.AppName, "digest", installWorker.appDeployInfo.ObjectHash) // Always set the isActive in Phase manager itself, to avoid any delay in the install handler, otherwise it can // cause running the same playbook multiple times. @@ -1415,22 +1384,21 @@ func isPhaseStatusComplete(phaseInfo *enterpriseApi.PhaseInfo) bool { // validatePhaseInfo validates if phase and status in phaseInfo is valid func validatePhaseInfo(ctx context.Context, phaseInfo *enterpriseApi.PhaseInfo) bool { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("validatePhaseInfo").WithValues("phaseInfo", phaseInfo) + logger := logging.FromContext(ctx).With("func", "validatePhaseInfo") // Check for phase in phaseInfo phases := string( - enterpriseApi.PhaseDownload + - enterpriseApi.PhasePodCopy + - enterpriseApi.PhaseInstall) + enterpriseApi.PhaseDownload) + string( + enterpriseApi.PhasePodCopy) + string( + enterpriseApi.PhaseInstall) if !strings.Contains(phases, string(phaseInfo.Phase)) { - scopedLog.Error(nil, "Invalid phase in PhaseInfo", "phase", string(phaseInfo.Phase)) + logger.ErrorContext(ctx, "Invalid phase in PhaseInfo", "phase", string(phaseInfo.Phase)) return false } if ok := appPhaseInfoStatuses[phaseInfo.Status]; !ok { - scopedLog.Error(nil, "Invalid status in PhaseInfo", "phase", string(phaseInfo.Phase), "status", phaseInfo.Status) + logger.ErrorContext(ctx, "Invalid status in PhaseInfo", "phase", string(phaseInfo.Phase), "status", phaseInfo.Status) return false } return true @@ -1513,25 +1481,21 @@ func initAppInstallPipeline(ctx context.Context, appDeployContext *enterpriseApi // deleteAppPkgFromOperator removes the app pkg from the Operator Pod func deleteAppPkgFromOperator(ctx context.Context, worker *PipelineWorker) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("deleteAppPkgFromOperator").WithValues("name", worker.cr.GetName(), "namespace", worker.cr.GetNamespace(), "app pkg", worker.appDeployInfo.AppName) + logger := logging.FromContext(ctx).With("func", "deleteAppPkgFromOperator", "app pkg", worker.appDeployInfo.AppName) appPkgLocalPath := getAppPackageLocalPath(ctx, worker) err := os.Remove(appPkgLocalPath) if err != nil { - // Issue is local, so just log an error msg and return - // ToDo: sgontla: For any transient errors, handle the clean-up at the end of the install - scopedLog.Error(err, "failed to delete app pkg from Operator", "app pkg path", appPkgLocalPath) + logger.ErrorContext(ctx, "failed to delete app pkg from Operator", "app pkg path", appPkgLocalPath, "error", err) return } - scopedLog.Info("Deleted app package from the operator", "App package path", appPkgLocalPath) + logger.InfoContext(ctx, "Deleted app package from the operator", "App package path", appPkgLocalPath) releaseStorage(worker.appDeployInfo.Size) } func afwGetReleventStatefulsetByKind(ctx context.Context, cr splcommon.MetaObject, client splcommon.ControllerClient) *appsv1.StatefulSet { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getReleventStatefulsetByKind").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "afwGetReleventStatefulsetByKind") var instanceID InstanceType switch cr.GetObjectKind().GroupVersionKind().Kind { @@ -1557,7 +1521,7 @@ func afwGetReleventStatefulsetByKind(ctx context.Context, cr splcommon.MetaObjec namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: statefulsetName} sts, err := splctrl.GetStatefulSetByName(ctx, client, namespacedName) if err != nil { - scopedLog.Error(err, "Unable to get the stateful set") + logger.ErrorContext(ctx, "Unable to get the stateful set", "error", err) } return sts @@ -1609,8 +1573,7 @@ func getLocalScopePlaybookContext(ctx context.Context, installWorker *PipelineWo // getInsallWorkerPlaybookContext returns the playbook context for install workers i.e either local // or premiumApps scope for now func getInsallWorkerPlaybookContext(ctx context.Context, worker *PipelineWorker, sem chan struct{}, podExecClient splutil.PodExecClientImpl, appSrcSpec *enterpriseApi.AppSourceSpec, appSrcScope string, ppln *AppInstallPipeline) PlaybookImpl { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getInsallWorkerPlaybookContext").WithValues("crName", ppln.cr.GetName(), "namespace", ppln.cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "getInsallWorkerPlaybookContext") // Since local app context is needed for premiumAppContext we retrieve it for both cases localCtx := getLocalScopePlaybookContext(ctx, worker, sem, podExecClient) @@ -1621,7 +1584,7 @@ func getInsallWorkerPlaybookContext(ctx context.Context, worker *PipelineWorker, } // Invalid scope - scopedLog.Error(nil, "Install workers can have only local or premium apps scope", "appSrcScope", appSrcScope) + logger.ErrorContext(ctx, "Install workers can have only local or premium apps scope", "appSrcScope", appSrcScope) return nil } @@ -1656,8 +1619,7 @@ func (shcPlaybookContext *SHCPlaybookContext) removeSHCBundlePushStatusFile(ctx // isBundlePushComplete checks whether the SHC bundle push is complete or still pending func (shcPlaybookContext *SHCPlaybookContext) isBundlePushComplete(ctx context.Context) (bool, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("isBundlePushComplete").WithValues("crName", shcPlaybookContext.cr.GetName(), "namespace", shcPlaybookContext.cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "isBundlePushComplete") cmd := fmt.Sprintf("cat %s", shcBundlePushStatusCheckFile) streamOptions := splutil.NewStreamOptionsObject(cmd) @@ -1680,12 +1642,12 @@ func (shcPlaybookContext *SHCPlaybookContext) isBundlePushComplete(ctx context.C // 1. stdOut is empty, which means bundle push is still in progress // 2. stdOut has some other string other than the bundle push success message if stdOut == "" { - scopedLog.Info("SHC Bundle Push is still in progress") + logger.InfoContext(ctx, "SHC Bundle Push is still in progress") return false, nil } else if !strings.Contains(stdOut, shcBundlePushCompleteStr) { // this means there was an error in bundle push command err = fmt.Errorf("there was an error in applying SHC Bundle, err=\"%v\"", stdOut) - scopedLog.Error(err, "SHC Bundle push status file reported an error while applying bundle") + logger.ErrorContext(ctx, "SHC Bundle push status file reported an error while applying bundle", "error", err) // reset the bundle push state to Pending, so that we retry again. setBundlePushState(ctx, shcPlaybookContext.afwPipeline, enterpriseApi.BundlePushPending) @@ -1701,7 +1663,7 @@ func (shcPlaybookContext *SHCPlaybookContext) isBundlePushComplete(ctx context.C // now that bundle push is complete, remove the status file err = shcPlaybookContext.removeSHCBundlePushStatusFile(ctx) if err != nil { - scopedLog.Error(err, "removing SHC Bundle Push status file failed, will retry again.") + logger.ErrorContext(ctx, "removing SHC Bundle Push status file failed, will retry again.", "error", err) // reset the state to BundlePushInProgress so that we can check the status of file again. setBundlePushState(ctx, shcPlaybookContext.afwPipeline, enterpriseApi.BundlePushInProgress) @@ -1715,17 +1677,14 @@ func (shcPlaybookContext *SHCPlaybookContext) isBundlePushComplete(ctx context.C // triggerBundlePush triggers the bundle push operation for SHC func (shcPlaybookContext *SHCPlaybookContext) triggerBundlePush(ctx context.Context) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("shcPlaybookContext.triggerBundlePush()").WithValues( - "shcCaptainUrl", shcPlaybookContext.searchHeadCaptainURL, - "cr", shcPlaybookContext.cr.GetName()) + logger := logging.FromContext(ctx).With("func", "triggerBundlePush") // Reduce the liveness probe level shcPlaybookContext.setLivenessProbeLevel(ctx, livenessProbeLevelOne) // Trigger bundle push cmd := fmt.Sprintf(applySHCBundleCmdStr, shcPlaybookContext.searchHeadCaptainURL, shcBundlePushStatusCheckFile) - scopedLog.Info("Triggering bundle push", "command", cmd) + logger.InfoContext(ctx, "Triggering bundle push", "command", cmd) streamOptions := splutil.NewStreamOptionsObject(cmd) stdOut, stdErr, err := shcPlaybookContext.podExecClient.RunPodExecCommand(ctx, streamOptions, []string{"/bin/sh"}) if err != nil || stdErr != "" { @@ -1737,14 +1696,13 @@ func (shcPlaybookContext *SHCPlaybookContext) triggerBundlePush(ctx context.Cont // setLivenessProbeLevel sets the liveness probe level across all the Search Head Pods. func (shcPlaybookContext *SHCPlaybookContext) setLivenessProbeLevel(ctx context.Context, probeLevel int) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("shcPlaybookContext.setLivenessProbeLevel()") + logger := logging.FromContext(ctx).With("func", "setLivenessProbeLevel") shcStsName := GetSplunkStatefulsetName(SplunkSearchHead, shcPlaybookContext.cr.GetName()) shcStsNamespaceName := types.NamespacedName{Namespace: shcPlaybookContext.cr.GetNamespace(), Name: shcStsName} shcSts, err := splctrl.GetStatefulSetByName(ctx, shcPlaybookContext.client, shcStsNamespaceName) if err != nil { - scopedLog.Error(err, "Unable to get the stateful set") + logger.ErrorContext(ctx, "Unable to get the stateful set", "error", err) return err } @@ -1762,7 +1720,7 @@ func (shcPlaybookContext *SHCPlaybookContext) setLivenessProbeLevel(ctx context. err = setProbeLevelOnCRPods(ctx, shcPlaybookContext.cr, *shcSts.Spec.Replicas, shcPlaybookContext.podExecClient, probeLevel) if err != nil { - scopedLog.Error(err, "Unable to set the Liveness probe level") + logger.ErrorContext(ctx, "Unable to set the Liveness probe level", "error", err) return err } @@ -1803,8 +1761,7 @@ func adjustClusterAppsFilePermissions(ctx context.Context, podExecClient splutil // runPlaybook will implement the bundle push logic for SHC func (shcPlaybookContext *SHCPlaybookContext) runPlaybook(ctx context.Context) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("runPlaybook").WithValues("crName", shcPlaybookContext.cr.GetName(), "namespace", shcPlaybookContext.cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "SHCPlaybookContext.runPlaybook") var err error var ok bool @@ -1813,7 +1770,7 @@ func (shcPlaybookContext *SHCPlaybookContext) runPlaybook(ctx context.Context) e return nil } if cr.Status.Phase != enterpriseApi.PhaseReady { - scopedLog.Info("SHC is not ready yet.") + logger.InfoContext(ctx, "SHC is not ready yet.") return nil } @@ -1822,11 +1779,11 @@ func (shcPlaybookContext *SHCPlaybookContext) runPlaybook(ctx context.Context) e switch appDeployContext.BundlePushStatus.BundlePushStage { // if the bundle push is already in progress, check the status case enterpriseApi.BundlePushInProgress: - scopedLog.Info("checking the status of SHC Bundle Push") + logger.InfoContext(ctx, "checking the status of SHC Bundle Push") // check if the bundle push is complete ok, err = shcPlaybookContext.isBundlePushComplete(ctx) if ok { - scopedLog.Info("Bundle push complete, setting bundle push state in CR") + logger.InfoContext(ctx, "Bundle push complete, setting bundle push state in CR") // set the bundle push status to complete setBundlePushState(ctx, shcPlaybookContext.afwPipeline, enterpriseApi.BundlePushComplete) @@ -1840,28 +1797,28 @@ func (shcPlaybookContext *SHCPlaybookContext) runPlaybook(ctx context.Context) e // set the liveness probe to default shcPlaybookContext.setLivenessProbeLevel(ctx, livenessProbeLevelDefault) } else if err != nil { - scopedLog.Error(err, "there was an error in SHC bundle push, will retry again") + logger.ErrorContext(ctx, "there was an error in SHC bundle push, will retry again", "error", err) } else { - scopedLog.Info("SHC Bundle Push is still in progress, will check back again") + logger.InfoContext(ctx, "SHC Bundle Push is still in progress, will check back again") } case enterpriseApi.BundlePushPending: // run the command to apply cluster bundle - scopedLog.Info("running command to apply SHC Bundle") + logger.InfoContext(ctx, "running command to apply SHC Bundle") // Adjust the file permissions err = adjustClusterAppsFilePermissions(ctx, shcPlaybookContext.podExecClient) if err != nil { - scopedLog.Error(err, "failed to adjust the file permissions") + logger.ErrorContext(ctx, "failed to adjust the file permissions", "error", err) return err } err = shcPlaybookContext.triggerBundlePush(ctx) if err != nil { - scopedLog.Error(err, "failed to apply SHC Bundle") + logger.ErrorContext(ctx, "failed to apply SHC Bundle", "error", err) return err } - scopedLog.Info("SHC Bundle Push is in progress") + logger.InfoContext(ctx, "SHC Bundle Push is in progress") // set the state to bundle push complete since SHC bundle push is a sync call setBundlePushState(ctx, shcPlaybookContext.afwPipeline, enterpriseApi.BundlePushInProgress) @@ -1874,29 +1831,27 @@ func (shcPlaybookContext *SHCPlaybookContext) runPlaybook(ctx context.Context) e // isBundlePushComplete checks the status of bundle push func (idxcPlaybookContext *IdxcPlaybookContext) isBundlePushComplete(ctx context.Context) bool { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("isBundlePushComplete").WithValues("crName", idxcPlaybookContext.cr.GetName(), "namespace", idxcPlaybookContext.cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "IdxcPlaybookContext.isBundlePushComplete") streamOptions := splutil.NewStreamOptionsObject(idxcShowClusterBundleStatusStr) stdOut, stdErr, err := idxcPlaybookContext.podExecClient.RunPodExecCommand(ctx, streamOptions, []string{"/bin/sh"}) if err == nil && strings.Contains(stdOut, "cluster_status=None") && !strings.Contains(stdOut, "last_bundle_validation_status=failure") { - scopedLog.Info("IndexerCluster Bundle push complete") + logger.InfoContext(ctx, "IndexerCluster Bundle push complete") return true } if err != nil || stdErr != "" { - scopedLog.Error(err, "show cluster-bundle-status failed", "stdout", stdOut, "stderr", stdErr) + logger.ErrorContext(ctx, "show cluster-bundle-status failed", "stdout", stdOut, "stderr", stdErr, "error", err) return false } - scopedLog.Info("IndexerCluster Bundle push is still in progress") + logger.InfoContext(ctx, "IndexerCluster Bundle push is still in progress") return false } // triggerBundlePush triggers the bundle push for indexer cluster func (idxcPlaybookContext *IdxcPlaybookContext) triggerBundlePush(ctx context.Context) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("idxcPlaybookContext.triggerBundlePush()") + logger := logging.FromContext(ctx).With("func", "IdxcPlaybookContext.triggerBundlePush") // Reduce the liveness probe level idxcPlaybookContext.setLivenessProbeLevel(ctx, livenessProbeLevelOne) @@ -1906,7 +1861,7 @@ func (idxcPlaybookContext *IdxcPlaybookContext) triggerBundlePush(ctx context.Co // If the error is due to a bundle which is already present, don't do anything. // In the next reconcile we will mark it as bundle push complete if strings.Contains(stdErr, idxcBundleAlreadyPresentStr) { - scopedLog.Info("bundle already present on peers") + logger.InfoContext(ctx, "bundle already present on peers") } else if err != nil || !strings.Contains(stdErr, "OK\n") { err = fmt.Errorf("error while applying cluster bundle. stdout: %s, stderr: %s, err: %v", stdOut, stdErr, err) return err @@ -1917,8 +1872,7 @@ func (idxcPlaybookContext *IdxcPlaybookContext) triggerBundlePush(ctx context.Co // setLivenessProbeLevel sets the liveness probe level across all the indexer pods func (idxcPlaybookContext *IdxcPlaybookContext) setLivenessProbeLevel(ctx context.Context, probeLevel int) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("idxcPlaybookContext.setLivenessProbeLevel()") + logger := logging.FromContext(ctx).With("func", "IdxcPlaybookContext.setLivenessProbeLevel") var err error managerSts := afwGetReleventStatefulsetByKind(ctx, idxcPlaybookContext.cr, idxcPlaybookContext.client) @@ -1950,7 +1904,7 @@ func (idxcPlaybookContext *IdxcPlaybookContext) setLivenessProbeLevel(ctx contex err = idxcPlaybookContext.client.Get(ctx, idxcNameSpaceName, &idxcCR) if err != nil { // Probably a dangling owner reference, just ignore and continue - scopedLog.Error(err, "Unable to fetch the CR", "Name", managerOwnerRefs[i].Name, "Namespace", idxcPlaybookContext.cr.GetNamespace()) + logger.ErrorContext(ctx, "Unable to fetch the CR", "Name", managerOwnerRefs[i].Name, "Namespace", idxcPlaybookContext.cr.GetNamespace(), "error", err) continue } @@ -1958,14 +1912,14 @@ func (idxcPlaybookContext *IdxcPlaybookContext) setLivenessProbeLevel(ctx contex idxcStsNamespaceName := types.NamespacedName{Namespace: idxcCR.GetNamespace(), Name: idxcStsName} idxcSts, err := splctrl.GetStatefulSetByName(ctx, idxcPlaybookContext.client, idxcStsNamespaceName) if err != nil { - scopedLog.Error(err, "Unable to get the stateful set") + logger.ErrorContext(ctx, "Unable to get the stateful set", "error", err) // Probably a dangling owner reference, just ignore and continue continue } err = setProbeLevelOnCRPods(ctx, &idxcCR, *idxcSts.Spec.Replicas, idxcPlaybookContext.podExecClient, probeLevel) if err != nil { - scopedLog.Error(err, "Unable to set the Liveness probe level") + logger.ErrorContext(ctx, "Unable to set the Liveness probe level", "error", err) return err } } @@ -1980,15 +1934,14 @@ func (idxcPlaybookContext *IdxcPlaybookContext) setLivenessProbeLevel(ctx contex // 2. OR else, if the bundle push is already in progress, check the status of bundle push func (idxcPlaybookContext *IdxcPlaybookContext) runPlaybook(ctx context.Context) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("RunPlaybook").WithValues("crName", idxcPlaybookContext.cr.GetName(), "namespace", idxcPlaybookContext.cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "IdxcPlaybookContext.runPlaybook") appDeployContext := idxcPlaybookContext.afwPipeline.appDeployContext switch appDeployContext.BundlePushStatus.BundlePushStage { // if the bundle push is already in progress, check the status case enterpriseApi.BundlePushInProgress: - scopedLog.Info("checking the status of IndexerCluster Bundle Push") + logger.InfoContext(ctx, "checking the status of IndexerCluster Bundle Push") // check if the bundle push is complete if idxcPlaybookContext.isBundlePushComplete(ctx) { // set the bundle push status to complete @@ -2001,22 +1954,22 @@ func (idxcPlaybookContext *IdxcPlaybookContext) runPlaybook(ctx context.Context) setInstallStateForClusterScopedApps(ctx, appDeployContext) idxcPlaybookContext.setLivenessProbeLevel(ctx, livenessProbeLevelDefault) } else { - scopedLog.Info("IndexerCluster Bundle Push is still in progress, will check back again in next reconcile..") + logger.InfoContext(ctx, "IndexerCluster Bundle Push is still in progress, will check back again in next reconcile..") } case enterpriseApi.BundlePushPending: // Adjust the file permissions err := adjustClusterAppsFilePermissions(ctx, idxcPlaybookContext.podExecClient) if err != nil { - scopedLog.Error(err, "failed to adjust the file permissions") + logger.ErrorContext(ctx, "failed to adjust the file permissions", "error", err) return err } // run the command to apply cluster bundle - scopedLog.Info("running command to apply IndexerCluster Bundle") + logger.InfoContext(ctx, "running command to apply IndexerCluster Bundle") err = idxcPlaybookContext.triggerBundlePush(ctx) if err != nil { - scopedLog.Error(err, "failed to apply IndexerCluster Bundle") + logger.ErrorContext(ctx, "failed to apply IndexerCluster Bundle", "error", err) return err } @@ -2049,8 +2002,7 @@ func handleEsappPostinstall(rctx context.Context, preCtx *premiumAppScopePlayboo cr := preCtx.cr appSrcSpec := preCtx.appSrcSpec - reqLogger := log.FromContext(rctx) - scopedLog := reqLogger.WithName("handleEsappPostinstall").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) + logger := logging.FromContext(rctx).With("func", "handleEsappPostinstall", "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) // For ES app, run post-install commands var command string @@ -2068,7 +2020,7 @@ func handleEsappPostinstall(rctx context.Context, preCtx *premiumAppScopePlayboo stdOut, stdErr, err := preCtx.localCtx.podExecClient.RunPodExecCommand(rctx, streamOptions, []string{"/bin/sh"}) if stdErr != "" || err != nil { phaseInfo.FailCount++ - scopedLog.Error(err, "premium scoped app package install failed", "stdout", stdOut, "stderr", stdErr, "post install command", command, "failCount", phaseInfo.FailCount) + logger.ErrorContext(rctx, "premium scoped app package install failed", "stdout", stdOut, "stderr", stdErr, "post install command", command, "failCount", phaseInfo.FailCount, "error", err) return fmt.Errorf("premium scoped app package install failed. stdOut: %s, stdErr: %s, post install command: %s, failCount: %d", stdOut, stdErr, command, phaseInfo.FailCount) } @@ -2085,8 +2037,7 @@ func (preCtx *premiumAppScopePlaybookContext) runPlaybook(rctx context.Context) worker := preCtx.localCtx.worker appSrcSpec := preCtx.appSrcSpec - reqLogger := log.FromContext(rctx) - scopedLog := reqLogger.WithName("premiumAppScopePlaybookContext.runPlaybook").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace(), "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) + logger := logging.FromContext(rctx).With("func", "premiumAppScopePlaybookContext.runPlaybook", "pod", worker.targetPodName, "app name", worker.appDeployInfo.AppName) defer func() { <-preCtx.localCtx.sem @@ -2100,15 +2051,15 @@ func (preCtx *premiumAppScopePlaybookContext) runPlaybook(rctx context.Context) // Call the API to install an app err := installApp(rctx, preCtx.localCtx, cr, phaseInfo) if err != nil { - scopedLog.Error(err, "premium app package installation error") + logger.ErrorContext(rctx, "premium app package installation error", "error", err) return fmt.Errorf("app pkg installation failed. error %s", err.Error()) } - // Handle post install for ES app + // Post install step if appSrcSpec.PremiumAppsProps.Type == enterpriseApi.PremiumAppsTypeEs { err = handleEsappPostinstall(rctx, preCtx, phaseInfo) if err != nil { - scopedLog.Error(err, "app package post installation error") + logger.ErrorContext(rctx, "app package post installation error", "error", err) return fmt.Errorf("app pkg post installation failed. error %s", err.Error()) } } @@ -2119,8 +2070,8 @@ func (preCtx *premiumAppScopePlaybookContext) runPlaybook(rctx context.Context) // Call the API to clean up app err = cleanupApp(rctx, preCtx.localCtx, cr, phaseInfo) if err != nil { - scopedLog.Error(err, "premium app package installation error") - return fmt.Errorf("app pkg installation failed. error %s", err.Error()) + logger.ErrorContext(rctx, "premium app package cleanup error", "error", err) + return fmt.Errorf("app pkg cleanup failed. error %s", err.Error()) } // Mark afw pipeline for bundle push on shc deployer @@ -2170,8 +2121,7 @@ func isPhaseInfoEligibleForSchedulerEntry(ctx context.Context, appSrcName string // afwSchedulerEntry Starts the scheduler Pipeline with the required phases func afwSchedulerEntry(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, appDeployContext *enterpriseApi.AppDeploymentContext, appFrameworkConfig *enterpriseApi.AppFrameworkSpec) (bool, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("afwSchedulerEntry").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "afwSchedulerEntry") // return error, if there is no storage defined for the Operator pod if !isPersistantVolConfigured() { @@ -2199,7 +2149,7 @@ func afwSchedulerEntry(ctx context.Context, client splcommon.ControllerClient, c afwPipeline.phaseWaiter.Add(1) go afwPipeline.installPhaseManager(ctx) - scopedLog.Info("Creating pipeline workers for pending app packages") + logger.InfoContext(ctx, "Creating pipeline workers for pending app packages") for appSrcName, appSrcDeployInfo := range appDeployContext.AppsSrcDeployStatus { @@ -2213,7 +2163,7 @@ func afwSchedulerEntry(ctx context.Context, client splcommon.ControllerClient, c // create the dir on Splunk pod/s where app/s will be copied from operator pod err = createDirOnSplunkPods(ctx, cr, *sts.Spec.Replicas, appsPathOnPod, podExecClient) if err != nil { - scopedLog.Error(err, "unable to create directory on splunk pod") + logger.ErrorContext(ctx, "unable to create directory on splunk pod", "error", err) // break from here and let yield logic take care of everything break } @@ -2234,11 +2184,11 @@ func afwSchedulerEntry(ctx context.Context, client splcommon.ControllerClient, c afwPipeline.phaseWaiter.Add(1) go afwPipeline.afwYieldWatcher(ctx) - scopedLog.Info("Waiting for the phase managers to finish") + logger.InfoContext(ctx, "Waiting for the phase managers to finish") // Wait for all the pipeline managers to finish afwPipeline.phaseWaiter.Wait() - scopedLog.Info("All the phase managers finished") + logger.InfoContext(ctx, "All the phase managers finished") // Finally mark if all the App framework is complete checkAndUpdateAppFrameworkProgressFlag(afwPipeline) @@ -2248,15 +2198,14 @@ func afwSchedulerEntry(ctx context.Context, client splcommon.ControllerClient, c // afwYieldWatcher issues termination request to the scheduler when the yield time expires or the pipelines become empty. func (ppln *AppInstallPipeline) afwYieldWatcher(ctx context.Context) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("afwYieldWatcher").WithValues("name", ppln.cr.GetName(), "namespace", ppln.cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "afwYieldWatcher") yieldTrigger := time.After(time.Duration(ppln.appDeployContext.AppFrameworkConfig.SchedulerYieldInterval) * time.Second) yieldScheduler: for { select { case <-yieldTrigger: - scopedLog.Info("Yielding from AFW scheduler", "time elapsed", time.Now().Unix()-ppln.afwEntryTime) + logger.InfoContext(ctx, "Yielding from AFW scheduler", "time elapsed", time.Now().Unix()-ppln.afwEntryTime) break yieldScheduler default: if ppln.isPipelineEmpty() { @@ -2270,5 +2219,5 @@ yieldScheduler: // Trigger the pipeline termination by closing the channel close(ppln.sigTerm) ppln.phaseWaiter.Done() - scopedLog.Info("Termination issued") + logger.InfoContext(ctx, "Termination issued") } diff --git a/pkg/splunk/enterprise/clustermanager.go b/pkg/splunk/enterprise/clustermanager.go index 269753c5c..40856b368 100644 --- a/pkg/splunk/enterprise/clustermanager.go +++ b/pkg/splunk/enterprise/clustermanager.go @@ -25,7 +25,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/client" rclient "sigs.k8s.io/controller-runtime/pkg/client" - "github.com/go-logr/logr" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" @@ -35,7 +35,6 @@ import ( k8serrors "k8s.io/apimachinery/pkg/api/errors" "k8s.io/apimachinery/pkg/types" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -47,8 +46,7 @@ func ApplyClusterManager(ctx context.Context, client splcommon.ControllerClient, Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyClusterManager") + logger := logging.FromContext(ctx).With("func", "ApplyClusterManager") eventPublisher, _ := newK8EventPublisher(client, cr) ctx = context.WithValue(ctx, splcommon.EventPublisherKey, eventPublisher) cr.Kind = "ClusterManager" @@ -68,7 +66,7 @@ func ApplyClusterManager(ctx context.Context, client splcommon.ControllerClient, err = validateClusterManagerSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateClusterManagerSpec", fmt.Sprintf("validate clustermanager spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate clustermanager spec") + logger.ErrorContext(ctx, "Failed to validate clustermanager spec", "error", err) return result, err } @@ -123,7 +121,7 @@ func ApplyClusterManager(ctx context.Context, client splcommon.ControllerClient, // create or update general config resources namespaceScopedSecret, err := ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkIndexer) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -223,7 +221,7 @@ func ApplyClusterManager(ctx context.Context, client splcommon.ControllerClient, namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkMonitoringConsole, cr.GetNamespace())} err = splctrl.DeleteReferencesToAutomatedMCIfExists(ctx, client, cr, namespacedName) if err != nil { - scopedLog.Error(err, "Error in deleting automated monitoring console resource") + logger.ErrorContext(ctx, "Error in deleting automated monitoring console resource", "error", err) } // Create podExecClient @@ -267,7 +265,6 @@ func ApplyClusterManager(ctx context.Context, client splcommon.ControllerClient, // clusterManagerPodManager is used to manage the cluster manager pod type clusterManagerPodManager struct { - log logr.Logger cr *enterpriseApi.ClusterManager secrets *corev1.Secret newSplunkClient func(managementURI, username, password string) *splclient.SplunkClient @@ -320,8 +317,7 @@ func getClusterManagerStatefulSet(ctx context.Context, client splcommon.Controll // CheckIfsmartstoreConfigMapUpdatedToPod checks if the smartstore configMap is updated on Pod or not func CheckIfsmartstoreConfigMapUpdatedToPod(ctx context.Context, c splcommon.ControllerClient, cr *enterpriseApi.ClusterManager, podExecClient splutil.PodExecClientImpl) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("CheckIfsmartstoreConfigMapUpdatedToPod").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "CheckIfsmartstoreConfigMapUpdatedToPod") eventPublisher, _ := newK8EventPublisher(c, cr) command := fmt.Sprintf("cat /mnt/splunk-operator/local/%s", configToken) @@ -337,7 +333,7 @@ func CheckIfsmartstoreConfigMapUpdatedToPod(ctx context.Context, c splcommon.Con if smartStoreConfigMap != nil { tokenFromConfigMap := smartStoreConfigMap.Data[configToken] if tokenFromConfigMap == stdOut { - scopedLog.Info("Token Matched.", "on Pod=", stdOut, "from configMap=", tokenFromConfigMap) + logger.InfoContext(ctx, "Token Matched", "on Pod", stdOut, "from configMap", tokenFromConfigMap) return nil } eventPublisher.Warning(ctx, "getSmartstoreConfigMap", fmt.Sprintf("waiting for the configMap update to the Pod. Token on Pod=%s, Token from configMap=%s", stdOut, tokenFromConfigMap)) @@ -355,8 +351,7 @@ func PerformCmBundlePush(ctx context.Context, c splcommon.ControllerClient, cr * return nil } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("PerformCmBundlePush").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "PerformCmBundlePush") // Reconciler can be called for multiple reasons. If we are waiting on configMap update to happen, // do not increment the Retry Count unless the last check was 5 seconds ago. // This helps, to wait for the required time @@ -366,7 +361,7 @@ func PerformCmBundlePush(ctx context.Context, c splcommon.ControllerClient, cr * return fmt.Errorf("will re-attempt to push the bundle after the 5 seconds period passed from last check. LastCheckInterval=%d, current epoch=%d", cr.Status.BundlePushTracker.LastCheckInterval, currentEpoch) } - scopedLog.Info("Attempting to push the bundle") + logger.InfoContext(ctx, "Attempting to push the bundle") cr.Status.BundlePushTracker.LastCheckInterval = currentEpoch // The amount of time it takes for the configMap update to Pod depends on @@ -390,7 +385,7 @@ func PerformCmBundlePush(ctx context.Context, c splcommon.ControllerClient, cr * err = PushManagerAppsBundle(ctx, c, cr) if err == nil { - scopedLog.Info("Bundle push success") + logger.InfoContext(ctx, "Bundle push success") cr.Status.BundlePushTracker.NeedToPushManagerApps = false } @@ -399,8 +394,7 @@ func PerformCmBundlePush(ctx context.Context, c splcommon.ControllerClient, cr * // PushManagerAppsBundle issues the REST command to for cluster manager bundle push func PushManagerAppsBundle(ctx context.Context, c splcommon.ControllerClient, cr *enterpriseApi.ClusterManager) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("PushManagerApps").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "PushManagerAppsBundle") eventPublisher, _ := newK8EventPublisher(c, cr) defaultSecretObjName := splcommon.GetNamespaceScopedSecretName(cr.GetNamespace()) @@ -417,7 +411,7 @@ func PushManagerAppsBundle(ctx context.Context, c splcommon.ControllerClient, cr return fmt.Errorf("could not find admin password while trying to push the manager apps bundle") } - scopedLog.Info("Issuing REST call to push manager aps bundle") + logger.InfoContext(ctx, "Issuing REST call to push manager apps bundle") managerIdxcName := cr.GetName() fqdnName := splcommon.GetServiceFQDN(cr.GetNamespace(), GetSplunkServiceName(SplunkClusterManager, managerIdxcName, false)) @@ -430,16 +424,14 @@ func PushManagerAppsBundle(ctx context.Context, c splcommon.ControllerClient, cr // helper function to get the list of ClusterManager types in the current namespace func getClusterManagerList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (int, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getClusterManagerList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getClusterManagerList") objectList := enterpriseApi.ClusterManagerList{} err := c.List(context.TODO(), &objectList, listOpts...) numOfObjects := len(objectList.Items) if err != nil { - scopedLog.Error(err, "ClusterManager types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "ClusterManager types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return numOfObjects, err } @@ -450,16 +442,15 @@ func getClusterManagerList(ctx context.Context, c splcommon.ControllerClient, cr // If it fails to connect to the cluster manager (e.g., pod not ready yet), it returns basic env vars as fallback // This function is used also in mock tests var GetCMMultisiteEnvVarsCall = func(ctx context.Context, cr *enterpriseApi.ClusterManager, namespaceScopedSecret *corev1.Secret) ([]corev1.EnvVar, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("Verify if Multisite Indexer Cluster").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "GetCMMultisiteEnvVarsCall") extraEnv := getClusterManagerExtraEnv(cr, &cr.Spec.CommonSplunkSpec) - mgr := clusterManagerPodManager{log: scopedLog, cr: cr, secrets: namespaceScopedSecret, newSplunkClient: splclient.NewSplunkClient} + mgr := clusterManagerPodManager{cr: cr, secrets: namespaceScopedSecret, newSplunkClient: splclient.NewSplunkClient} cm := mgr.getClusterManagerClient(cr) clusterInfo, err := cm.GetClusterInfo(false) if err != nil { - scopedLog.Error(err, "Failed to get cluster info from cluster manager pod, using basic environment variables") + logger.ErrorContext(ctx, "Failed to get cluster info from cluster manager pod, using basic environment variables", "error", err) return extraEnv, err } @@ -475,8 +466,7 @@ var GetCMMultisiteEnvVarsCall = func(ctx context.Context, cr *enterpriseApi.Clus // changeClusterManagerAnnotations updates the splunk/image-tag field of the ClusterManager annotations to trigger the reconcile loop // on update, and returns error if something is wrong func changeClusterManagerAnnotations(ctx context.Context, c splcommon.ControllerClient, cr *enterpriseApi.LicenseManager) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("changeClusterManagerAnnotations").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "changeClusterManagerAnnotations") eventPublisher, _ := newK8EventPublisher(c, cr) clusterManagerInstance := &enterpriseApi.ClusterManager{} @@ -526,13 +516,13 @@ func changeClusterManagerAnnotations(ctx context.Context, c splcommon.Controller image, err := getCurrentImage(ctx, c, cr, SplunkLicenseManager) if err != nil { eventPublisher.Warning(ctx, "changeClusterManagerAnnotations", fmt.Sprintf("Could not get the LicenseManager Image. Reason %v", err)) - scopedLog.Error(err, "Get LicenseManager Image failed with", "error", err) + logger.ErrorContext(ctx, "Get LicenseManager Image failed", "error", err) return err } err = changeAnnotations(ctx, c, image, clusterManagerInstance) if err != nil { eventPublisher.Warning(ctx, "changeClusterManagerAnnotations", fmt.Sprintf("Could not update annotations. Reason %v", err)) - scopedLog.Error(err, "ClusterManager types update after changing annotations failed with", "error", err) + logger.ErrorContext(ctx, "ClusterManager types update after changing annotations failed", "error", err) return err } diff --git a/pkg/splunk/enterprise/clustermaster.go b/pkg/splunk/enterprise/clustermaster.go index 85fcb70cc..43bc97e06 100644 --- a/pkg/splunk/enterprise/clustermaster.go +++ b/pkg/splunk/enterprise/clustermaster.go @@ -23,8 +23,8 @@ import ( enterpriseApi "github.com/splunk/splunk-operator/api/v4" - "github.com/go-logr/logr" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" @@ -33,7 +33,6 @@ import ( corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -45,8 +44,7 @@ func ApplyClusterMaster(ctx context.Context, client splcommon.ControllerClient, Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyClusterMaster") + logger := logging.FromContext(ctx).With("func", "ApplyClusterMaster") eventPublisher, _ := newK8EventPublisher(client, cr) cr.Kind = "ClusterMaster" @@ -65,7 +63,7 @@ func ApplyClusterMaster(ctx context.Context, client splcommon.ControllerClient, err = validateClusterMasterSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateClusterMasterSpec", fmt.Sprintf("validate clustermaster spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate clustermaster spec") + logger.ErrorContext(ctx, "Failed to validate clustermaster spec", "error", err) return result, err } @@ -120,7 +118,7 @@ func ApplyClusterMaster(ctx context.Context, client splcommon.ControllerClient, // create or update general config resources namespaceScopedSecret, err := ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkIndexer) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -210,7 +208,7 @@ func ApplyClusterMaster(ctx context.Context, client splcommon.ControllerClient, namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkMonitoringConsole, cr.GetNamespace())} err = splctrl.DeleteReferencesToAutomatedMCIfExists(ctx, client, cr, namespacedName) if err != nil { - scopedLog.Error(err, "Error in deleting automated monitoring console resource") + logger.ErrorContext(ctx, "Error in deleting automated monitoring console resource", "error", err) } // Create podExecClient @@ -248,7 +246,6 @@ func ApplyClusterMaster(ctx context.Context, client splcommon.ControllerClient, // clusterMasterPodMaster is used to manage the cluster manager pod type clusterMasterPodManager struct { - log logr.Logger cr *enterpriseApiV3.ClusterMaster secrets *corev1.Secret newSplunkClient func(managementURI, username, password string) *splclient.SplunkClient @@ -301,8 +298,7 @@ func getClusterMasterStatefulSet(ctx context.Context, client splcommon.Controlle // CheckIfMastersmartstoreConfigMapUpdatedToPod checks if the smartstore configMap is updated on Pod or not func CheckIfMastersmartstoreConfigMapUpdatedToPod(ctx context.Context, c splcommon.ControllerClient, cr *enterpriseApiV3.ClusterMaster, podExecClient splutil.PodExecClientImpl) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("CheckIfMastersmartstoreConfigMapUpdatedToPod").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "CheckIfMastersmartstoreConfigMapUpdatedToPod") eventPublisher, _ := newK8EventPublisher(c, cr) command := fmt.Sprintf("cat /mnt/splunk-operator/local/%s", configToken) @@ -318,7 +314,7 @@ func CheckIfMastersmartstoreConfigMapUpdatedToPod(ctx context.Context, c splcomm if smartStoreConfigMap != nil { tokenFromConfigMap := smartStoreConfigMap.Data[configToken] if tokenFromConfigMap == stdOut { - scopedLog.Info("Token Matched.", "on Pod=", stdOut, "from configMap=", tokenFromConfigMap) + logger.InfoContext(ctx, "Token Matched", "on Pod", stdOut, "from configMap", tokenFromConfigMap) return nil } eventPublisher.Warning(ctx, "getSmartstoreConfigMap", fmt.Sprintf("waiting for the configMap update to the Pod. Token on Pod=%s, Token from configMap=%s", stdOut, tokenFromConfigMap)) @@ -336,8 +332,7 @@ func PerformCmasterBundlePush(ctx context.Context, c splcommon.ControllerClient, return nil } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("PerformCmasterBundlePush").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "PerformCmasterBundlePush") // Reconciler can be called for multiple reasons. If we are waiting on configMap update to happen, // do not increment the Retry Count unless the last check was 5 seconds ago. // This helps, to wait for the required time @@ -347,7 +342,7 @@ func PerformCmasterBundlePush(ctx context.Context, c splcommon.ControllerClient, return fmt.Errorf("will re-attempt to push the bundle after the 5 seconds period passed from last check. LastCheckInterval=%d, current epoch=%d", cr.Status.BundlePushTracker.LastCheckInterval, currentEpoch) } - scopedLog.Info("Attempting to push the bundle") + logger.InfoContext(ctx, "Attempting to push the bundle") cr.Status.BundlePushTracker.LastCheckInterval = currentEpoch // The amount of time it takes for the configMap update to Pod depends on @@ -371,7 +366,7 @@ func PerformCmasterBundlePush(ctx context.Context, c splcommon.ControllerClient, err = PushMasterAppsBundle(ctx, c, cr) if err == nil { - scopedLog.Info("Bundle push success") + logger.InfoContext(ctx, "Bundle push success") cr.Status.BundlePushTracker.NeedToPushMasterApps = false } @@ -380,8 +375,7 @@ func PerformCmasterBundlePush(ctx context.Context, c splcommon.ControllerClient, // PushMasterAppsBundle issues the REST command to for cluster manager bundle push func PushMasterAppsBundle(ctx context.Context, c splcommon.ControllerClient, cr *enterpriseApiV3.ClusterMaster) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("PushMasterApps").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "PushMasterAppsBundle") eventPublisher, _ := newK8EventPublisher(c, cr) defaultSecretObjName := splcommon.GetNamespaceScopedSecretName(cr.GetNamespace()) @@ -398,7 +392,7 @@ func PushMasterAppsBundle(ctx context.Context, c splcommon.ControllerClient, cr return fmt.Errorf("could not find admin password while trying to push the manager apps bundle") } - scopedLog.Info("Issuing REST call to push manager aps bundle") + logger.InfoContext(ctx, "Issuing REST call to push manager apps bundle") managerIdxcName := cr.GetName() fqdnName := splcommon.GetServiceFQDN(cr.GetNamespace(), GetSplunkServiceName(SplunkClusterMaster, managerIdxcName, false)) @@ -411,16 +405,14 @@ func PushMasterAppsBundle(ctx context.Context, c splcommon.ControllerClient, cr // helper function to get the list of ClusterMaster types in the current namespace func getClusterMasterList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (int, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getClusterMasterList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getClusterMasterList") objectList := enterpriseApiV3.ClusterMasterList{} err := c.List(context.TODO(), &objectList, listOpts...) numOfObjects := len(objectList.Items) if err != nil { - scopedLog.Error(err, "ClusterMaster types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "ClusterMaster types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return numOfObjects, err } @@ -430,9 +422,7 @@ func getClusterMasterList(ctx context.Context, c splcommon.ControllerClient, cr // VerifyCMasterisMultisite checks if its a multisite func VerifyCMasterisMultisite(ctx context.Context, cr *enterpriseApiV3.ClusterMaster, namespaceScopedSecret *corev1.Secret) ([]corev1.EnvVar, error) { var err error - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("Verify if Multisite Indexer Cluster").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - mgr := clusterMasterPodManager{log: scopedLog, cr: cr, secrets: namespaceScopedSecret, newSplunkClient: splclient.NewSplunkClient} + mgr := clusterMasterPodManager{cr: cr, secrets: namespaceScopedSecret, newSplunkClient: splclient.NewSplunkClient} cm := mgr.getClusterMasterClient(cr) clusterInfo, err := cm.GetClusterInfo(false) if err != nil { diff --git a/pkg/splunk/enterprise/configuration.go b/pkg/splunk/enterprise/configuration.go index a0d90b354..bb25b8308 100644 --- a/pkg/splunk/enterprise/configuration.go +++ b/pkg/splunk/enterprise/configuration.go @@ -33,14 +33,15 @@ import ( metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "k8s.io/apimachinery/pkg/types" "k8s.io/apimachinery/pkg/util/intstr" + "sigs.k8s.io/controller-runtime/pkg/log" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" enterpriseApi "github.com/splunk/splunk-operator/api/v4" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" splutil "github.com/splunk/splunk-operator/pkg/splunk/util" - "sigs.k8s.io/controller-runtime/pkg/log" ) var defaultLivenessProbe corev1.Probe = corev1.Probe{ @@ -416,8 +417,7 @@ func validateCommonSplunkSpec(ctx context.Context, c splcommon.ControllerClient, // ValidateImagePullSecrets sets default values for imagePullSecrets if not provided func ValidateImagePullSecrets(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, spec *enterpriseApi.CommonSplunkSpec) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ValidateImagePullSecrets").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "ValidateImagePullSecrets") // If no imagePullSecrets are configured var nilImagePullSecrets []corev1.LocalObjectReference @@ -430,7 +430,7 @@ func ValidateImagePullSecrets(ctx context.Context, c splcommon.ControllerClient, for _, secret := range spec.ImagePullSecrets { _, err := splutil.GetSecretByName(ctx, c, cr.GetNamespace(), cr.GetName(), secret.Name) if err != nil { - scopedLog.Error(err, "Couldn't get secret in the imagePullSecrets config", "Secret", secret.Name) + logger.ErrorContext(ctx, "Couldn't get secret in the imagePullSecrets config", "Secret", secret.Name, "error", err) } } @@ -568,8 +568,7 @@ func addEphemeralVolumes(statefulSet *appsv1.StatefulSet, volumeType string) err // addStorageVolumes adds storage volumes to the StatefulSet func addStorageVolumes(ctx context.Context, cr splcommon.MetaObject, client splcommon.ControllerClient, spec *enterpriseApi.CommonSplunkSpec, statefulSet *appsv1.StatefulSet, labels map[string]string) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("addStorageVolumes").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "addStorageVolumes") // configure storage for mount path /opt/splunk/etc if spec.EtcVolumeStorageConfig.EphemeralStorage { @@ -598,7 +597,7 @@ func addStorageVolumes(ctx context.Context, cr splcommon.MetaObject, client splc // Add Splunk Probe config map probeConfigMap, err := getProbeConfigMap(ctx, client, cr) if err != nil { - scopedLog.Error(err, "Unable to get probeConfigMap") + logger.ErrorContext(ctx, "Unable to get probeConfigMap", "error", err) return err } addProbeConfigMapVolume(probeConfigMap, statefulSet) @@ -607,28 +606,27 @@ func addStorageVolumes(ctx context.Context, cr splcommon.MetaObject, client splc func getProbeConfigMap(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject) (*corev1.ConfigMap, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getProbeConfigMap").WithValues("namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "getProbeConfigMap") configMapName := GetProbeConfigMapName(cr.GetNamespace()) configMapNamespace := cr.GetNamespace() namespacedName := types.NamespacedName{Namespace: configMapNamespace, Name: configMapName} // Check if the config map already exists - scopedLog.Info("Checking for existing config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) + logger.DebugContext(ctx, "Checking for existing config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) var configMap corev1.ConfigMap err := client.Get(ctx, namespacedName, &configMap) if err == nil { - scopedLog.Info("Retrieved existing config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) + logger.DebugContext(ctx, "Retrieved existing config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) return &configMap, nil } else if !k8serrors.IsNotFound(err) { - scopedLog.Error(err, "Error retrieving config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) + logger.ErrorContext(ctx, "Error retrieving config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace, "error", err) return nil, err } // Existing config map not found, create one for the probes - scopedLog.Info("Creating new config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) + logger.InfoContext(ctx, "Creating new config map", "configMapName", configMapName, "configMapNamespace", configMapNamespace) configMap = corev1.ConfigMap{ ObjectMeta: metav1.ObjectMeta{ Name: configMapName, @@ -803,8 +801,7 @@ func getSmartstoreConfigMap(ctx context.Context, client splcommon.ControllerClie // updateSplunkPodTemplateWithConfig modifies the podTemplateSpec object based on configuration of the Splunk Enterprise resource. func updateSplunkPodTemplateWithConfig(ctx context.Context, client splcommon.ControllerClient, podTemplateSpec *corev1.PodTemplateSpec, cr splcommon.MetaObject, spec *enterpriseApi.CommonSplunkSpec, instanceType InstanceType, extraEnv []corev1.EnvVar, secretToMount string) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("updateSplunkPodTemplateWithConfig").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "updateSplunkPodTemplateWithConfig") // Add custom ports to splunk containers if spec.ServiceTemplate.Spec.Ports != nil { for idx := range podTemplateSpec.Spec.Containers { @@ -864,7 +861,7 @@ func updateSplunkPodTemplateWithConfig(ctx context.Context, client splcommon.Con if err == nil { podTemplateSpec.ObjectMeta.Annotations["defaultConfigRev"] = configMapResourceVersion } else { - scopedLog.Error(err, "Updation of default configMap annotation failed") + logger.ErrorContext(ctx, "Updation of default configMap annotation failed", "error", err) } } @@ -989,7 +986,7 @@ func updateSplunkPodTemplateWithConfig(ctx context.Context, client splcommon.Con managerIdxCluster := &enterpriseApi.ClusterManager{} err := client.Get(ctx, namespacedName, managerIdxCluster) if err != nil { - scopedLog.Error(err, "Unable to get ClusterManager") + logger.ErrorContext(ctx, "Unable to get ClusterManager", "error", err) } if managerIdxCluster.Spec.LicenseManagerRef.Name != "" { @@ -1026,7 +1023,7 @@ func updateSplunkPodTemplateWithConfig(ctx context.Context, client splcommon.Con managerIdxCluster := &enterpriseApiV3.ClusterMaster{} err := client.Get(ctx, namespacedName, managerIdxCluster) if err != nil { - scopedLog.Error(err, "Unable to get ClusterManager") + logger.ErrorContext(ctx, "Unable to get ClusterMaster", "error", err) } if managerIdxCluster.Spec.LicenseManagerRef.Name != "" { @@ -1123,28 +1120,25 @@ func removeDuplicateEnvVars(sliceList []corev1.EnvVar) []corev1.EnvVar { // getLivenessProbe the probe for checking the liveness of the Pod func getLivenessProbe(ctx context.Context, cr splcommon.MetaObject, instanceType InstanceType, spec *enterpriseApi.CommonSplunkSpec) *corev1.Probe { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getLivenessProbe").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx) livenessProbe := getProbeWithConfigUpdates(&defaultLivenessProbe, spec.LivenessProbe, spec.LivenessInitialDelaySeconds) - scopedLog.Info("LivenessProbe", "Configured", livenessProbe) + logger.DebugContext(ctx, "LivenessProbe", "Configured", livenessProbe) return livenessProbe } // getReadinessProbe the probe for checking the readiness of the Pod func getReadinessProbe(ctx context.Context, cr splcommon.MetaObject, instanceType InstanceType, spec *enterpriseApi.CommonSplunkSpec) *corev1.Probe { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getReadinessProbe").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx) readinessProbe := getProbeWithConfigUpdates(&defaultReadinessProbe, spec.ReadinessProbe, spec.ReadinessInitialDelaySeconds) - scopedLog.Info("ReadinessProbe", "Configured", readinessProbe) + logger.DebugContext(ctx, "ReadinessProbe", "Configured", readinessProbe) return readinessProbe } // getStartupProbe the probe for checking the first start of splunk on the Pod func getStartupProbe(ctx context.Context, cr splcommon.MetaObject, instanceType InstanceType, spec *enterpriseApi.CommonSplunkSpec) *corev1.Probe { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getStartupProbe").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx) startupProbe := getProbeWithConfigUpdates(&defaultStartupProbe, spec.StartupProbe, 0) - scopedLog.Info("StartupProbe", "Configured", startupProbe) + logger.DebugContext(ctx, "StartupProbe", "Configured", startupProbe) return startupProbe } @@ -1245,8 +1239,7 @@ func AreRemoteVolumeKeysChanged(ctx context.Context, client splcommon.Controller return false } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("AreRemoteVolumeKeysChanged").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "AreRemoteVolumeKeysChanged") volList := smartstore.VolList for _, volume := range volList { @@ -1261,7 +1254,7 @@ func AreRemoteVolumeKeysChanged(ctx context.Context, client splcommon.Controller // Check if the secret version is already tracked, and if there is a change in it if existingSecretVersion, ok := ResourceRev[volume.SecretRef]; ok { if existingSecretVersion != namespaceScopedSecret.ResourceVersion { - scopedLog.Info("secret keys changed", "previous resource version", existingSecretVersion, "current version", namespaceScopedSecret.ResourceVersion) + logger.InfoContext(ctx, "secret keys changed", "previous resource version", existingSecretVersion, "current version", namespaceScopedSecret.ResourceVersion) ResourceRev[volume.SecretRef] = namespaceScopedSecret.ResourceVersion return true } @@ -1271,7 +1264,7 @@ func AreRemoteVolumeKeysChanged(ctx context.Context, client splcommon.Controller // First time adding to track the secret resource version ResourceRev[volume.SecretRef] = namespaceScopedSecret.ResourceVersion } else { - scopedLog.Info("no valid SecretRef for volume. No secret to track.", "volumeName", volume.Name) + logger.DebugContext(ctx, "no valid SecretRef for volume. No secret to track.", "volumeName", volume.Name) } } @@ -1281,8 +1274,7 @@ func AreRemoteVolumeKeysChanged(ctx context.Context, client splcommon.Controller // ApplyManualAppUpdateConfigMap applies the manual app update config map func ApplyManualAppUpdateConfigMap(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, crKindMap map[string]string) (*corev1.ConfigMap, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyManualAppUpdateConfigMap").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "ApplyManualAppUpdateConfigMap") configMapName := GetSplunkManualAppUpdateConfigMapName(cr.GetNamespace()) namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: configMapName} @@ -1302,17 +1294,17 @@ func ApplyManualAppUpdateConfigMap(ctx context.Context, client splcommon.Control configMap.SetOwnerReferences(append(configMap.GetOwnerReferences(), splcommon.AsOwner(cr, false))) if newConfigMap { - scopedLog.Info("creating manual app update configMap") + logger.InfoContext(ctx, "creating manual app update configMap") err = splutil.CreateResource(ctx, client, configMap) if err != nil { - scopedLog.Error(err, "Unable to create the configMap", "name", configMapName) + logger.ErrorContext(ctx, "Unable to create the configMap", "name", configMapName, "error", err) return configMap, err } } else { - scopedLog.Info("updating manual app update configMap") + logger.InfoContext(ctx, "updating manual app update configMap") err = splutil.UpdateResource(ctx, client, configMap) if err != nil { - scopedLog.Error(err, "unable to update the configMap", "name", configMapName) + logger.ErrorContext(ctx, "unable to update the configMap", "name", configMapName, "error", err) return configMap, err } } @@ -1321,8 +1313,7 @@ func ApplyManualAppUpdateConfigMap(ctx context.Context, client splcommon.Control // getManualUpdateStatus extracts the status field from the configMap data func getManualUpdateStatus(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, configMapName string) string { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getManualUpdateStatus").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "getManualUpdateStatus") namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: configMapName} configMap, err := splctrl.GetConfigMap(ctx, client, namespacedName) @@ -1332,11 +1323,11 @@ func getManualUpdateStatus(ctx context.Context, client splcommon.ControllerClien data := configMap.Data[cr.GetObjectKind().GroupVersionKind().Kind] result = extractFieldFromConfigMapData(statusRegex, data) if result == "on" { - scopedLog.Info("namespace configMap value is set to", "name", configMapName, "data", result) + logger.InfoContext(ctx, "namespace configMap value is set to", "name", configMapName, "data", result) return result } } else { - scopedLog.Error(err, "Unable to get namespace specific configMap", "name", configMapName) + logger.ErrorContext(ctx, "Unable to get namespace specific configMap", "name", configMapName, "error", err) } return "off" @@ -1344,17 +1335,16 @@ func getManualUpdateStatus(ctx context.Context, client splcommon.ControllerClien // getManualUpdatePerCrStatus extracts the status field from the configMap data func getManualUpdatePerCrStatus(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, configMapName string) string { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getManualUpdatePerCrStatus").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "getManualUpdatePerCrStatus") namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: fmt.Sprintf(perCrConfigMapNameStr, KindToInstanceString(cr.GroupVersionKind().Kind), cr.GetName())} crconfigMap, err := splctrl.GetConfigMap(ctx, client, namespacedName) if err == nil { - scopedLog.Info("custom configMap value is set to", "name", configMapName, "data", crconfigMap.Data) + logger.InfoContext(ctx, "custom configMap value is set to", "name", configMapName, "data", crconfigMap.Data) data := crconfigMap.Data["manualUpdate"] return data } else { - scopedLog.Error(err, "unable to get custom specific configMap", "name", configMapName) + logger.ErrorContext(ctx, "unable to get custom specific configMap", "name", configMapName, "error", err) } return "off" @@ -1362,13 +1352,12 @@ func getManualUpdatePerCrStatus(ctx context.Context, client splcommon.Controller // getManualUpdateRefCount extracts the refCount field from the configMap data func getManualUpdateRefCount(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, configMapName string) int { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getManualUpdateRefCount").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "getManualUpdateRefCount") var refCount int namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: configMapName} configMap, err := splctrl.GetConfigMap(ctx, client, namespacedName) if err != nil { - scopedLog.Error(err, "unable to get the configMap", "name", configMapName) + logger.ErrorContext(ctx, "unable to get the configMap", "name", configMapName, "error", err) return refCount } diff --git a/pkg/splunk/enterprise/events.go b/pkg/splunk/enterprise/events.go index ebdc13d62..db7533ed8 100644 --- a/pkg/splunk/enterprise/events.go +++ b/pkg/splunk/enterprise/events.go @@ -21,9 +21,9 @@ import ( enterpriseApi "github.com/splunk/splunk-operator/api/v4" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" + "github.com/splunk/splunk-operator/pkg/logging" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" corev1 "k8s.io/api/core/v1" - "sigs.k8s.io/controller-runtime/pkg/log" ) // K8EventPublisher structure used to publish k8s event @@ -74,13 +74,12 @@ func (k *K8EventPublisher) publishEvent(ctx context.Context, eventType, reason, return } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("PublishEvent") - scopedLog.Info("publishing event", "reason", event.Reason, "message", event.Message) + logger := logging.FromContext(ctx) + logger.DebugContext(ctx, "publishing event", "reason", event.Reason, "message", event.Message) err := k.client.Create(ctx, &event) if err != nil { - scopedLog.Error(err, "failed to record event, ignoring", + logger.ErrorContext(ctx, "failed to record event, ignoring", "reason", event.Reason, "message", event.Message, "error", err) } } diff --git a/pkg/splunk/enterprise/finalizers.go b/pkg/splunk/enterprise/finalizers.go index 574ccf093..1ba9051c1 100644 --- a/pkg/splunk/enterprise/finalizers.go +++ b/pkg/splunk/enterprise/finalizers.go @@ -19,12 +19,11 @@ import ( "context" "fmt" - corev1 "k8s.io/api/core/v1" - "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" - + "github.com/splunk/splunk-operator/pkg/logging" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" + corev1 "k8s.io/api/core/v1" + "sigs.k8s.io/controller-runtime/pkg/client" ) func init() { @@ -35,8 +34,7 @@ func init() { func DeleteSplunkPvc(ctx context.Context, cr splcommon.MetaObject, c splcommon.ControllerClient) error { objectKind := cr.GetObjectKind().GroupVersionKind().Kind - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("DeleteSplunkPvc") + logger := logging.FromContext(ctx).With("func", "DeleteSplunkPvc") var components []string switch objectKind { @@ -57,7 +55,7 @@ func DeleteSplunkPvc(ctx context.Context, cr splcommon.MetaObject, c splcommon.C case "MonitoringConsole": components = append(components, "monitoring-console") default: - scopedLog.Info("Skipping PVC removal") + logger.DebugContext(ctx, "Skipping PVC removal") return nil } @@ -77,7 +75,7 @@ func DeleteSplunkPvc(ctx context.Context, cr splcommon.MetaObject, c splcommon.C // delete each PVC for _, pvc := range pvclist.Items { - scopedLog.Info("Deleting PVC", "name", pvc.ObjectMeta.Name) + logger.InfoContext(ctx, "Deleting PVC", "name", pvc.ObjectMeta.Name) if err := c.Delete(context.Background(), &pvc); err != nil { return err } diff --git a/pkg/splunk/enterprise/indexercluster.go b/pkg/splunk/enterprise/indexercluster.go index 2d135d84f..200711831 100644 --- a/pkg/splunk/enterprise/indexercluster.go +++ b/pkg/splunk/enterprise/indexercluster.go @@ -27,8 +27,8 @@ import ( enterpriseApi "github.com/splunk/splunk-operator/api/v4" - "github.com/go-logr/logr" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" @@ -38,7 +38,6 @@ import ( "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" rclient "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -53,8 +52,7 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyIndexerClusterManager").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "ApplyIndexerClusterManager") eventPublisher, _ := newK8EventPublisher(client, cr) ctx = context.WithValue(ctx, splcommon.EventPublisherKey, eventPublisher) cr.Kind = "IndexerCluster" @@ -70,7 +68,7 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller err = validateIndexerClusterSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateIndexerClusterSpec", fmt.Sprintf("validate indexercluster spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate indexercluster spec") + logger.ErrorContext(ctx, "Failed to validate indexercluster spec", "error", err) return result, err } @@ -91,7 +89,7 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller // create or update general config resources namespaceScopedSecret, err := ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkIndexer) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -110,12 +108,17 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller } else { cr.Status.ClusterManagerPhase = managerIdxCluster.Status.Phase } + if managerIdxCluster.Spec.Image != cr.Spec.Image { + logger.WarnContext(ctx, "Version mismatch between ClusterManager and IndexerCluster. Upgrade ClusterManager first", + "cm_image", managerIdxCluster.Spec.Image, + "idxc_image", cr.Spec.Image) + } } else { - scopedLog.Error(nil, "The configured clusterMasterRef doesn't exist", "clusterManagerRef", cr.Spec.ClusterManagerRef.Name) + logger.ErrorContext(ctx, "The configured clusterManagerRef doesn't exist", "clusterManagerRef", cr.Spec.ClusterManagerRef.Name) cr.Status.ClusterManagerPhase = enterpriseApi.PhaseError } - mgr := newIndexerClusterPodManager(scopedLog, cr, namespaceScopedSecret, splclient.NewSplunkClient) + mgr := newIndexerClusterPodManager(cr, namespaceScopedSecret, splclient.NewSplunkClient) // Check if we have configured enough number(<= RF) of replicas if mgr.cr.Status.ClusterManagerPhase == enterpriseApi.PhaseReady { err = VerifyRFPeers(ctx, mgr, client) @@ -239,6 +242,11 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller } cr.Status.Phase = phase + logger.InfoContext(ctx, "Cluster health check", + "phase", string(cr.Status.Phase), + "desired_replicas", cr.Spec.Replicas, + "ready_replicas", cr.Status.ReadyReplicas) + // no need to requeue if everything is ready if cr.Status.Phase == enterpriseApi.PhaseReady { //update MC @@ -261,7 +269,7 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller } } if len(cr.Spec.MonitoringConsoleRef.Name) > 0 && (cr.Spec.MonitoringConsoleRef.Name != cmMonitoringConsoleConfigRef) { - scopedLog.Info("Indexer Cluster CR should not specify monitoringConsoleRef and if specified, should be similar to cluster manager spec") + logger.WarnContext(ctx, "Indexer Cluster CR should not specify monitoringConsoleRef and if specified, should be similar to cluster manager spec") } } if len(cr.Status.IndexerSecretChanged) > 0 { @@ -288,7 +296,7 @@ func ApplyIndexerClusterManager(ctx context.Context, client splcommon.Controller result.Requeue = false // Set indexer cluster CR as owner reference for clustermanager - scopedLog.Info("Setting indexer cluster as owner for cluster manager") + logger.InfoContext(ctx, "Setting indexer cluster as owner for cluster manager") if len(cr.Spec.ClusterManagerRef.Name) > 0 { namespacedName = types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkClusterManager, cr.Spec.ClusterManagerRef.Name)} } @@ -315,14 +323,14 @@ func ApplyIndexerCluster(ctx context.Context, client splcommon.ControllerClient, Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyIndexerCluster") + logger := logging.FromContext(ctx).With("func", "ApplyIndexerCluster") eventPublisher, _ := newK8EventPublisher(client, cr) cr.Kind = "IndexerCluster" // validate and updates defaults for CR err := validateIndexerClusterSpec(ctx, client, cr) if err != nil { + logger.ErrorContext(ctx, "Failed to validate indexercluster spec", "error", err) return result, err } @@ -347,7 +355,7 @@ func ApplyIndexerCluster(ctx context.Context, client splcommon.ControllerClient, // create or update general config resources namespaceScopedSecret, err := ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkIndexer) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -366,11 +374,16 @@ func ApplyIndexerCluster(ctx context.Context, client splcommon.ControllerClient, } else { cr.Status.ClusterMasterPhase = managerIdxCluster.Status.Phase } + if managerIdxCluster.Spec.Image != cr.Spec.Image { + logger.WarnContext(ctx, "Version mismatch between ClusterMaster and IndexerCluster. Upgrade ClusterManager first", + "cm_image", managerIdxCluster.Spec.Image, + "idxc_image", cr.Spec.Image) + } } else { cr.Status.ClusterMasterPhase = enterpriseApi.PhaseError } - mgr := newIndexerClusterPodManager(scopedLog, cr, namespaceScopedSecret, splclient.NewSplunkClient) + mgr := newIndexerClusterPodManager(cr, namespaceScopedSecret, splclient.NewSplunkClient) // Check if we have configured enough number(<= RF) of replicas if mgr.cr.Status.ClusterMasterPhase == enterpriseApi.PhaseReady { err = VerifyRFPeers(ctx, mgr, client) @@ -495,6 +508,11 @@ func ApplyIndexerCluster(ctx context.Context, client splcommon.ControllerClient, } cr.Status.Phase = phase + logger.InfoContext(ctx, "Cluster health check", + "phase", string(cr.Status.Phase), + "desired_replicas", cr.Spec.Replicas, + "ready_replicas", cr.Status.ReadyReplicas) + // no need to requeue if everything is ready if cr.Status.Phase == enterpriseApi.PhaseReady { //update MC @@ -517,7 +535,7 @@ func ApplyIndexerCluster(ctx context.Context, client splcommon.ControllerClient, } } if len(cr.Spec.MonitoringConsoleRef.Name) > 0 && (cr.Spec.MonitoringConsoleRef.Name != cmMonitoringConsoleConfigRef) { - scopedLog.Info("Indexer Cluster CR should not specify monitoringConsoleRef and if specified, should be similar to cluster master spec") + logger.WarnContext(ctx, "Indexer Cluster CR should not specify monitoringConsoleRef and if specified, should be similar to cluster master spec") } } if len(cr.Status.IndexerSecretChanged) > 0 { @@ -544,7 +562,7 @@ func ApplyIndexerCluster(ctx context.Context, client splcommon.ControllerClient, result.Requeue = false // Set indexer cluster CR as owner reference for clustermaster - scopedLog.Info("Setting indexer cluster as owner for cluster master") + logger.InfoContext(ctx, "Setting indexer cluster as owner for cluster master") namespacedName = types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkClusterMaster, cr.Spec.ClusterMasterRef.Name)} err = splctrl.SetStatefulSetOwnerRef(ctx, client, cr, namespacedName) if err != nil { @@ -569,16 +587,14 @@ var VerifyRFPeers = func(ctx context.Context, mgr indexerClusterPodManager, clie // indexerClusterPodManager is used to manage the pods within an indexer cluster type indexerClusterPodManager struct { c splcommon.ControllerClient - log logr.Logger cr *enterpriseApi.IndexerCluster secrets *corev1.Secret newSplunkClient func(managementURI, username, password string) *splclient.SplunkClient } // newIndexerClusterPodManager function to create pod manager this is added to write unit test case -var newIndexerClusterPodManager = func(log logr.Logger, cr *enterpriseApi.IndexerCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) indexerClusterPodManager { +var newIndexerClusterPodManager = func(cr *enterpriseApi.IndexerCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) indexerClusterPodManager { return indexerClusterPodManager{ - log: log, cr: cr, secrets: secret, newSplunkClient: newSplunkClient, @@ -631,21 +647,20 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica return err } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyIdxcSecret").WithValues("Desired replicas", replicas, "IdxcSecretChanged", mgr.cr.Status.IndexerSecretChanged, "CrStatusNamespaceSecretResourceVersion", mgr.cr.Status.NamespaceSecretResourceVersion, "NamespaceSecretResourceVersion", namespaceSecret.GetObjectMeta().GetResourceVersion()) + idxcSecretLogger := logging.FromContext(ctx).With("func", "ApplyIdxcSecret", "desired_replicas", replicas) // If namespace scoped secret revision is the same ignore if len(mgr.cr.Status.NamespaceSecretResourceVersion) == 0 { // First time, set resource version in CR mgr.cr.Status.NamespaceSecretResourceVersion = namespaceSecret.ObjectMeta.ResourceVersion - scopedLog.Info("Setting CrStatusNamespaceSecretResourceVersion for the first time") + idxcSecretLogger.InfoContext(ctx, "Setting CrStatusNamespaceSecretResourceVersion for the first time") return nil } else if mgr.cr.Status.NamespaceSecretResourceVersion == namespaceSecret.ObjectMeta.ResourceVersion { // If resource version hasn't changed don't return return nil } - scopedLog.Info("Namespaced scoped secret revision has changed") + idxcSecretLogger.InfoContext(ctx, "Namespaced scoped secret revision has changed") // Retrieve idxc_secret password from secret data nsIdxcSecret := string(namespaceSecret.Data[splcommon.IdxcSecret]) @@ -658,10 +673,10 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica // Check if pod exists before updating secrets pod := &corev1.Pod{} namespacedName := types.NamespacedName{Namespace: mgr.cr.GetNamespace(), Name: indexerPodName} - scopedLog.Info("Check if pod is created before updating its secrets") + idxcSecretLogger.DebugContext(ctx, "Check if pod is created before updating its secrets", "pod", indexerPodName) err := mgr.c.Get(ctx, namespacedName, pod) if err != nil { - mgr.log.Info("Peer doesn't exists", "peerName", indexerPodName) + idxcSecretLogger.InfoContext(ctx, "Peer doesn't exist", "peerName", indexerPodName) continue } @@ -680,7 +695,7 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica // If idxc secret is different from namespace scoped secret change it if indIdxcSecret != nsIdxcSecret { - scopedLog.Info("idxc Secret different from namespace scoped secret") + idxcSecretLogger.InfoContext(ctx, "idxc Secret different from namespace scoped secret", "pod", indexerPodName) // Enable maintenance mode if len(mgr.cr.Status.IndexerSecretChanged) == 0 && !mgr.cr.Status.MaintenanceMode { @@ -700,7 +715,7 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica if err != nil { return err } - scopedLog.Info("Set CM in maintenance mode") + idxcSecretLogger.InfoContext(ctx, "Set CM in maintenance mode") } // If idxc secret already changed, ignore @@ -718,14 +733,14 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica if err != nil { return err } - scopedLog.Info("Changed idxc secret") + idxcSecretLogger.InfoContext(ctx, "Changed idxc secret", "pod", indexerPodName) // Restart splunk instance on pod err = idxcClient.RestartSplunk() if err != nil { return err } - scopedLog.Info("Restarted splunk") + idxcSecretLogger.InfoContext(ctx, "Restarted splunk", "pod", indexerPodName) // Keep a track of all the secrets on pods to change their idxc secret below mgr.cr.Status.IdxcPasswordChangedSecrets[podSecret.GetName()] = true @@ -768,7 +783,7 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica if err != nil { return err } - scopedLog.Info("idxc password changed on the secret mounted on pod", "Secret on Pod:", podSecretName) + idxcSecretLogger.InfoContext(ctx, "idxc password changed on the secret mounted on pod", "secret_on_pod", podSecretName) // Set to false marking the idxc password change in the secret mgr.cr.Status.IdxcPasswordChangedSecrets[podSecretName] = false @@ -781,6 +796,7 @@ func ApplyIdxcSecret(ctx context.Context, mgr *indexerClusterPodManager, replica // Update for indexerClusterPodManager handles all updates for a statefulset of indexers func (mgr *indexerClusterPodManager) Update(ctx context.Context, c splcommon.ControllerClient, statefulSet *appsv1.StatefulSet, desiredReplicas int32) (enterpriseApi.Phase, error) { + logger := logging.FromContext(ctx).With("func", "indexerClusterPodManager.Update") var err error @@ -795,7 +811,7 @@ func (mgr *indexerClusterPodManager) Update(ctx context.Context, c splcommon.Con return enterpriseApi.PhaseError, err } } else { - mgr.log.Info("Cluster Manager is not ready yet", "reason ", err) + logger.WarnContext(ctx, "Cluster Manager is not ready yet", "error", err) return enterpriseApi.PhaseError, err } @@ -811,7 +827,7 @@ func (mgr *indexerClusterPodManager) Update(ctx context.Context, c splcommon.Con // update CR status with IDXC information err = mgr.updateStatus(ctx, statefulSet) if err != nil || mgr.cr.Status.ReadyReplicas == 0 || !mgr.cr.Status.Initialized || !mgr.cr.Status.IndexingReady || !mgr.cr.Status.ServiceReady { - mgr.log.Info("Indexer cluster is not ready", "reason ", err) + logger.InfoContext(ctx, "Indexer cluster is not ready", "error", err) return enterpriseApi.PhasePending, nil } @@ -854,6 +870,7 @@ func (mgr *indexerClusterPodManager) FinishRecycle(ctx context.Context, n int32) // decommission for indexerClusterPodManager decommissions an indexer pod; it returns true when ready func (mgr *indexerClusterPodManager) decommission(ctx context.Context, n int32, enforceCounts bool) (bool, error) { + logger := logging.FromContext(ctx).With("func", "decommission") peerName := GetSplunkStatefulsetPodName(SplunkIndexer, mgr.cr.GetName(), n) switch mgr.cr.Status.Peers[n].Status { @@ -864,31 +881,31 @@ func (mgr *indexerClusterPodManager) decommission(ctx context.Context, n int32, // Don't return error here. We may be reconciling several times, and the actual Pod status is down, but // not yet reflecting on the Cluster Master, in which case, the podExec fails, though the decommission is // going fine. - mgr.log.Info("Unable to lower the liveness probe level", "peerName", peerName, "enforceCounts", enforceCounts) + logger.WarnContext(ctx, "Unable to lower the liveness probe level", "peerName", peerName, "enforceCounts", enforceCounts) } - mgr.log.Info("Decommissioning indexer cluster peer", "peerName", peerName, "enforceCounts", enforceCounts) + logger.InfoContext(ctx, "Decommissioning indexer cluster peer", "peerName", peerName, "enforceCounts", enforceCounts) c := mgr.getClient(ctx, n) return false, c.DecommissionIndexerClusterPeer(enforceCounts) case "Decommissioning": - mgr.log.Info("Waiting for decommission to complete", "peerName", peerName) + logger.InfoContext(ctx, "Waiting for decommission to complete", "peerName", peerName) return false, nil case "ReassigningPrimaries": - mgr.log.Info("Waiting for decommission to complete", "peerName", peerName) + logger.InfoContext(ctx, "Waiting for decommission to complete", "peerName", peerName) return false, nil case "GracefulShutdown": - mgr.log.Info("Decommission complete", "peerName", peerName, "Status", mgr.cr.Status.Peers[n].Status) + logger.InfoContext(ctx, "Decommission complete", "peerName", peerName, "status", mgr.cr.Status.Peers[n].Status) return true, nil case "Down": - mgr.log.Info("Decommission complete", "peerName", peerName, "Status", mgr.cr.Status.Peers[n].Status) + logger.InfoContext(ctx, "Decommission complete", "peerName", peerName, "status", mgr.cr.Status.Peers[n].Status) return true, nil case "": // this can happen after the peer has been removed from the indexer cluster - mgr.log.Info("Peer has empty ID", "peerName", peerName) + logger.InfoContext(ctx, "Peer has empty ID", "peerName", peerName) return false, nil } @@ -898,9 +915,7 @@ func (mgr *indexerClusterPodManager) decommission(ctx context.Context, n int32, // getClient for indexerClusterPodManager returns a SplunkClient for the member n func (mgr *indexerClusterPodManager) getClient(ctx context.Context, n int32) *splclient.SplunkClient { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("indexerClusterPodManager.getClient").WithValues("name", mgr.cr.GetName(), "namespace", mgr.cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getClient") // Get Pod Name memberName := GetSplunkStatefulsetPodName(SplunkIndexer, mgr.cr.GetName(), n) @@ -911,7 +926,7 @@ func (mgr *indexerClusterPodManager) getClient(ctx context.Context, n int32) *sp // Retrieve admin password from Pod adminPwd, err := splutil.GetSpecificSecretTokenFromPod(ctx, mgr.c, memberName, mgr.cr.GetNamespace(), "password") if err != nil { - scopedLog.Error(err, "Couldn't retrieve the admin password from pod") + logger.ErrorContext(ctx, "Couldn't retrieve the admin password from pod", "member", memberName, "error", err) } return mgr.newSplunkClient(fmt.Sprintf("https://%s:8089", fqdnName), "admin", adminPwd) @@ -919,9 +934,7 @@ func (mgr *indexerClusterPodManager) getClient(ctx context.Context, n int32) *sp // getClusterManagerClient for indexerClusterPodManager returns a SplunkClient for cluster manager func (mgr *indexerClusterPodManager) getClusterManagerClient(ctx context.Context) *splclient.SplunkClient { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("indexerClusterPodManager.getClusterManagerClient") - + logger := logging.FromContext(ctx).With("func", "getClusterManagerClient") // Retrieve admin password from Pod var managerIdxcName string var cm InstanceType @@ -932,7 +945,7 @@ func (mgr *indexerClusterPodManager) getClusterManagerClient(ctx context.Context managerIdxcName = mgr.cr.Spec.ClusterMasterRef.Name cm = SplunkClusterMaster } else { - mgr.log.Info("Empty cluster manager reference") + logger.WarnContext(ctx, "Empty cluster manager reference") } // Get Fully Qualified Domain Name @@ -942,7 +955,7 @@ func (mgr *indexerClusterPodManager) getClusterManagerClient(ctx context.Context podName := fmt.Sprintf("splunk-%s-%s-%s", managerIdxcName, cm, "0") adminPwd, err := splutil.GetSpecificSecretTokenFromPod(ctx, mgr.c, podName, mgr.cr.GetNamespace(), "password") if err != nil { - scopedLog.Error(err, "Couldn't retrieve the admin password from pod") + logger.ErrorContext(ctx, "Couldn't retrieve the admin password from pod", "pod", podName, "error", err) } return mgr.newSplunkClient(fmt.Sprintf("https://%s:8089", fqdnName), "admin", adminPwd) @@ -979,7 +992,8 @@ func (mgr *indexerClusterPodManager) verifyRFPeers(ctx context.Context, c splcom } if mgr.cr.Spec.Replicas < replicationFactor { - mgr.log.Info("Changing number of replicas as it is less than RF number of peers", "replicas", mgr.cr.Spec.Replicas) + logger := logging.FromContext(ctx).With("func", "verifyRFPeers") + logger.InfoContext(ctx, "Changing number of replicas as it is less than RF number of peers", "replicas", mgr.cr.Spec.Replicas) mgr.cr.Spec.Replicas = replicationFactor } return nil @@ -1017,6 +1031,18 @@ func (mgr *indexerClusterPodManager) updateStatus(ctx context.Context, statefulS mgr.cr.Status.ServiceReady = clusterInfo.ServiceReady mgr.cr.Status.MaintenanceMode = clusterInfo.MaintenanceMode + statusLogger := logging.FromContext(ctx) + + if !clusterInfo.ServiceReady || !clusterInfo.IndexingReady { + statusLogger.WarnContext(ctx, "Cluster quorum below threshold", + "initialized", clusterInfo.Initialized, + "indexing_ready", clusterInfo.IndexingReady, + "service_ready", clusterInfo.ServiceReady, + "maintenance_mode", clusterInfo.MaintenanceMode) + } + + previousPeerCount := int32(len(mgr.cr.Status.Peers)) + // get peer information from cluster manager peers, err := GetClusterManagerPeersCall(ctx, mgr) if err != nil { @@ -1033,7 +1059,7 @@ func (mgr *indexerClusterPodManager) updateStatus(ctx context.Context, statefulS peerStatus.BucketCount = peerInfo.BucketCount peerStatus.Searchable = peerInfo.Searchable } else { - mgr.log.Info("Peer is not known by cluster manager", "peerName", peerName) + statusLogger.InfoContext(ctx, "Peer is not known by cluster manager", "peerName", peerName) } if n < int32(len(mgr.cr.Status.Peers)) { mgr.cr.Status.Peers[n] = peerStatus @@ -1047,6 +1073,17 @@ func (mgr *indexerClusterPodManager) updateStatus(ctx context.Context, statefulS mgr.cr.Status.Peers = mgr.cr.Status.Peers[:statefulSet.Status.Replicas] } + newPeerCount := int32(len(mgr.cr.Status.Peers)) + if newPeerCount > previousPeerCount { + statusLogger.InfoContext(ctx, "Peer joined cluster", + "total_peers", newPeerCount, + "previous_peers", previousPeerCount) + } else if newPeerCount < previousPeerCount { + statusLogger.WarnContext(ctx, "Peer left cluster", + "total_peers", newPeerCount, + "previous_peers", previousPeerCount) + } + return nil } @@ -1083,14 +1120,12 @@ func validateIndexerClusterSpec(ctx context.Context, c splcommon.ControllerClien // helper function to get the list of IndexerCluster types in the current namespace func getIndexerClusterList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (enterpriseApi.IndexerClusterList, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getIndexerClusterList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getIndexerClusterList") objectList := enterpriseApi.IndexerClusterList{} err := c.List(context.TODO(), &objectList, listOpts...) if err != nil { - scopedLog.Error(err, "IndexerCluster types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "IndexerCluster types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return objectList, err } diff --git a/pkg/splunk/enterprise/indexercluster_test.go b/pkg/splunk/enterprise/indexercluster_test.go index 92f562c5a..23a57d116 100644 --- a/pkg/splunk/enterprise/indexercluster_test.go +++ b/pkg/splunk/enterprise/indexercluster_test.go @@ -42,7 +42,6 @@ import ( "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/client/fake" - "github.com/go-logr/logr" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" spltest "github.com/splunk/splunk-operator/pkg/splunk/test" @@ -305,8 +304,6 @@ func TestGetMonitoringConsoleClient(t *testing.T) { }, }, } - scopedLog := logt.WithName("TestGetMonitoringConsoleClient") - secrets := &corev1.Secret{ ObjectMeta: metav1.ObjectMeta{ Name: "splunk-manager1-indexer-secrets", @@ -318,7 +315,6 @@ func TestGetMonitoringConsoleClient(t *testing.T) { } mockSplunkClient := &spltest.MockHTTPClient{} mgr := &indexerClusterPodManager{ - log: scopedLog, cr: ¤t, secrets: secrets, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { @@ -334,7 +330,6 @@ func TestGetClusterManagerClient(t *testing.T) { os.Setenv("SPLUNK_GENERAL_TERMS", "--accept-sgt-current-at-splunk-com") ctx := context.TODO() - scopedLog := logt.WithName("TestGetClusterManagerClient") cr := enterpriseApi.IndexerCluster{ TypeMeta: metav1.TypeMeta{ Kind: "IndexerCluster", @@ -366,7 +361,6 @@ func TestGetClusterManagerClient(t *testing.T) { } mockSplunkClient := &spltest.MockHTTPClient{} mgr := &indexerClusterPodManager{ - log: scopedLog, cr: &cr, secrets: secrets, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { @@ -385,7 +379,6 @@ func TestGetClusterManagerClient(t *testing.T) { func getIndexerClusterPodManager(method string, mockHandlers []spltest.MockHTTPHandler, mockSplunkClient *spltest.MockHTTPClient, replicas int32) *indexerClusterPodManager { os.Setenv("SPLUNK_GENERAL_TERMS", "--accept-sgt-current-at-splunk-com") - scopedLog := logt.WithName(method) cr := enterpriseApi.IndexerCluster{ TypeMeta: metav1.TypeMeta{ Kind: "IndexerCluster", @@ -419,7 +412,6 @@ func getIndexerClusterPodManager(method string, mockHandlers []spltest.MockHTTPH } mgr := &indexerClusterPodManager{ - log: scopedLog, cr: &cr, secrets: secrets, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { @@ -1027,7 +1019,6 @@ func TestSetClusterMaintenanceMode(t *testing.T) { func TestApplyIdxcSecret(t *testing.T) { os.Setenv("SPLUNK_GENERAL_TERMS", "--accept-sgt-current-at-splunk-com") method := "ApplyIdxcSecret" - scopedLog := logt.WithName(method) var initObjectList []client.Object ctx := context.TODO() @@ -1152,7 +1143,6 @@ func TestApplyIdxcSecret(t *testing.T) { mockSplunkClient.AddHandlers(mockHandlers...) mgr := &indexerClusterPodManager{ c: c, - log: scopedLog, cr: &cr, secrets: secrets, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { @@ -1545,9 +1535,8 @@ func TestIndexerClusterWithReadyState(t *testing.T) { return nil } - newIndexerClusterPodManager = func(log logr.Logger, cr *enterpriseApi.IndexerCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) indexerClusterPodManager { + newIndexerClusterPodManager = func(cr *enterpriseApi.IndexerCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) indexerClusterPodManager { return indexerClusterPodManager{ - log: log, cr: cr, secrets: secret, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { diff --git a/pkg/splunk/enterprise/licensemanager.go b/pkg/splunk/enterprise/licensemanager.go index d603cbc9f..08c2ceb24 100644 --- a/pkg/splunk/enterprise/licensemanager.go +++ b/pkg/splunk/enterprise/licensemanager.go @@ -28,9 +28,10 @@ import ( corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" + "github.com/splunk/splunk-operator/pkg/logging" + splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" ) @@ -43,8 +44,7 @@ func ApplyLicenseManager(ctx context.Context, client splcommon.ControllerClient, Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyLicenseManager") + logger := logging.FromContext(ctx).With("func", "ApplyLicenseManager") eventPublisher, _ := newK8EventPublisher(client, cr) ctx = context.WithValue(ctx, splcommon.EventPublisherKey, eventPublisher) cr.Kind = "LicenseManager" @@ -60,7 +60,7 @@ func ApplyLicenseManager(ctx context.Context, client splcommon.ControllerClient, err = validateLicenseManagerSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateLicenseManagerSpec", fmt.Sprintf("validate licensemanager spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate license manager spec") + logger.ErrorContext(ctx, "Failed to validate license manager spec", "error", err) return result, err } @@ -85,7 +85,7 @@ func ApplyLicenseManager(ctx context.Context, client splcommon.ControllerClient, // create or update general config resources _, err = ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkLicenseManager) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -161,7 +161,7 @@ func ApplyLicenseManager(ctx context.Context, client splcommon.ControllerClient, namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkMonitoringConsole, cr.GetNamespace())} err = splctrl.DeleteReferencesToAutomatedMCIfExists(ctx, client, cr, namespacedName) if err != nil { - scopedLog.Error(err, "Error in deleting automated monitoring console resource") + logger.ErrorContext(ctx, "Error in deleting automated monitoring console resource", "error", err) } // Add a splunk operator telemetry app @@ -222,14 +222,12 @@ func validateLicenseManagerSpec(ctx context.Context, c splcommon.ControllerClien // helper function to get the list of LicenseManager types in the current namespace func getLicenseManagerList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (enterpriseApi.LicenseManagerList, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getLicenseManagerList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getLicenseManagerList") objectList := enterpriseApi.LicenseManagerList{} err := c.List(context.TODO(), &objectList, listOpts...) if err != nil { - scopedLog.Error(err, "LicenseManager types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "LicenseManager types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return objectList, err } diff --git a/pkg/splunk/enterprise/licensemaster.go b/pkg/splunk/enterprise/licensemaster.go index 30ff75046..d8a377657 100644 --- a/pkg/splunk/enterprise/licensemaster.go +++ b/pkg/splunk/enterprise/licensemaster.go @@ -27,10 +27,10 @@ import ( corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" + "github.com/splunk/splunk-operator/pkg/logging" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" splutil "github.com/splunk/splunk-operator/pkg/splunk/util" @@ -44,8 +44,7 @@ func ApplyLicenseMaster(ctx context.Context, client splcommon.ControllerClient, Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyLicenseMaster") + logger := logging.FromContext(ctx).With("func", "ApplyLicenseMaster") eventPublisher, _ := newK8EventPublisher(client, cr) ctx = context.WithValue(ctx, splcommon.EventPublisherKey, eventPublisher) @@ -60,7 +59,7 @@ func ApplyLicenseMaster(ctx context.Context, client splcommon.ControllerClient, err = validateLicenseMasterSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateLicenseMasterSpec", fmt.Sprintf("validate licensemaster spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate license master spec") + logger.ErrorContext(ctx, "Failed to validate license master spec", "error", err) return result, err } @@ -85,7 +84,7 @@ func ApplyLicenseMaster(ctx context.Context, client splcommon.ControllerClient, // create or update general config resources _, err = ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkLicenseMaster) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -161,7 +160,7 @@ func ApplyLicenseMaster(ctx context.Context, client splcommon.ControllerClient, namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkMonitoringConsole, cr.GetNamespace())} err = splctrl.DeleteReferencesToAutomatedMCIfExists(ctx, client, cr, namespacedName) if err != nil { - scopedLog.Error(err, "Error in deleting automated monitoring console resource") + logger.ErrorContext(ctx, "Error in deleting automated monitoring console resource", "error", err) } // Add a splunk operator telemetry app @@ -215,16 +214,14 @@ func validateLicenseMasterSpec(ctx context.Context, c splcommon.ControllerClient // helper function to get the list of LicenseMaster types in the current namespace func getLicenseMasterList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (int, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getLicenseMasterList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getLicenseMasterList") objectList := enterpriseApiV3.LicenseMasterList{} err := c.List(context.TODO(), &objectList, listOpts...) numOfObjects := len(objectList.Items) if err != nil { - scopedLog.Error(err, "LicenseMaster types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "LicenseMaster types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return numOfObjects, err } diff --git a/pkg/splunk/enterprise/monitoringconsole.go b/pkg/splunk/enterprise/monitoringconsole.go index 64de4a2de..311d10480 100644 --- a/pkg/splunk/enterprise/monitoringconsole.go +++ b/pkg/splunk/enterprise/monitoringconsole.go @@ -35,8 +35,9 @@ import ( "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" rclient "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" + + "github.com/splunk/splunk-operator/pkg/logging" ) // ApplyMonitoringConsole reconciles the StatefulSet for N monitoring console instances of Splunk Enterprise. @@ -47,8 +48,7 @@ func ApplyMonitoringConsole(ctx context.Context, client splcommon.ControllerClie Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyMonitoringConsole") + logger := logging.FromContext(ctx).With("func", "ApplyMonitoringConsole") eventPublisher, _ := newK8EventPublisher(client, cr) ctx = context.WithValue(ctx, splcommon.EventPublisherKey, eventPublisher) cr.Kind = "MonitoringConsole" @@ -68,7 +68,7 @@ func ApplyMonitoringConsole(ctx context.Context, client splcommon.ControllerClie err = validateMonitoringConsoleSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateMonitoringConsoleSpec", fmt.Sprintf("validate monitoringconsole spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate monitoring console spec") + logger.ErrorContext(ctx, "Failed to validate monitoring console spec", "error", err) return result, err } @@ -95,7 +95,7 @@ func ApplyMonitoringConsole(ctx context.Context, client splcommon.ControllerClie // create or update general config resources _, err = ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkMonitoringConsole) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -208,14 +208,12 @@ func getMonitoringConsoleStatefulSet(ctx context.Context, client splcommon.Contr // helper function to get the list of MonitoringConsole types in the current namespace func getMonitoringConsoleList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (enterpriseApi.MonitoringConsoleList, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getMonitoringConsoleList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getMonitoringConsoleList") objectList := enterpriseApi.MonitoringConsoleList{} err := c.List(context.TODO(), &objectList, listOpts...) if err != nil { - scopedLog.Error(err, "MonitoringConsole types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "MonitoringConsole types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return objectList, err } @@ -375,8 +373,7 @@ func DeleteURLsConfigMap(revised *corev1.ConfigMap, crName string, newURLs []cor // changeMonitoringConsoleAnnotations updates the splunk/image-tag field of the MonitoringConsole annotations to trigger the reconcile loop // on update, and returns error if something is wrong. func changeMonitoringConsoleAnnotations(ctx context.Context, client splcommon.ControllerClient, cr *enterpriseApi.ClusterManager) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("changeMonitoringConsoleAnnotations").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "changeMonitoringConsoleAnnotations") eventPublisher, _ := newK8EventPublisher(client, cr) monitoringConsoleInstance := &enterpriseApi.MonitoringConsole{} @@ -426,13 +423,13 @@ func changeMonitoringConsoleAnnotations(ctx context.Context, client splcommon.Co image, err := getCurrentImage(ctx, client, cr, SplunkClusterManager) if err != nil { eventPublisher.Warning(ctx, "changeMonitoringConsoleAnnotations", fmt.Sprintf("Could not get the ClusterManager Image. Reason %v", err)) - scopedLog.Error(err, "Get ClusterManager Image failed with", "error", err) + logger.ErrorContext(ctx, "Get ClusterManager Image failed", "error", err) return err } err = changeAnnotations(ctx, client, image, monitoringConsoleInstance) if err != nil { eventPublisher.Warning(ctx, "changeMonitoringConsoleAnnotations", fmt.Sprintf("Could not update annotations. Reason %v", err)) - scopedLog.Error(err, "MonitoringConsole types update after changing annotations failed with", "error", err) + logger.ErrorContext(ctx, "MonitoringConsole types update after changing annotations failed", "error", err) return err } diff --git a/pkg/splunk/enterprise/searchheadcluster.go b/pkg/splunk/enterprise/searchheadcluster.go index d5b4fd12f..47f8642a7 100644 --- a/pkg/splunk/enterprise/searchheadcluster.go +++ b/pkg/splunk/enterprise/searchheadcluster.go @@ -17,7 +17,6 @@ package enterprise import ( "context" - "errors" "fmt" "reflect" "strings" @@ -25,6 +24,7 @@ import ( enterpriseApi "github.com/splunk/splunk-operator/api/v4" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" @@ -34,7 +34,6 @@ import ( "k8s.io/apimachinery/pkg/types" "k8s.io/client-go/tools/remotecommand" "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -45,8 +44,7 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie Requeue: true, RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplySearchHeadCluster") + logger := logging.FromContext(ctx).With("func", "ApplySearchHeadCluster") eventPublisher, _ := newK8EventPublisher(client, cr) ctx = context.WithValue(ctx, splcommon.EventPublisherKey, eventPublisher) @@ -64,7 +62,7 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie err = validateSearchHeadClusterSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateSearchHeadClusterSpec", fmt.Sprintf("validate searchHeadCluster spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate searchHeadCluster spec") + logger.ErrorContext(ctx, "Failed to validate searchHeadCluster spec", "error", err) return result, err } @@ -77,7 +75,7 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie // create or update general config resources namespaceScopedSecret, err := ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkSearchHead) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -177,13 +175,18 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie } } + logger.InfoContext(ctx, "Deployer sync started") + deployerManager := splctrl.DefaultStatefulSetPodManager{} phase, err := deployerManager.Update(ctx, client, statefulSet, 1) if err != nil { + logger.ErrorContext(ctx, "Deployer sync failed", "error", err) return result, err } cr.Status.DeployerPhase = phase + logger.InfoContext(ctx, "Deployer sync completed", "deployer_phase", string(phase)) + // create or update statefulset for the search heads statefulSet, err = getSearchHeadStatefulSet(ctx, client, cr) if err != nil { @@ -196,7 +199,7 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie return result, err } - mgr := newSearchHeadClusterPodManager(client, scopedLog, cr, namespaceScopedSecret, splclient.NewSplunkClient) + mgr := newSearchHeadClusterPodManager(client, cr, namespaceScopedSecret, splclient.NewSplunkClient) // handle SHC upgrade process phase, err = mgr.Update(ctx, client, statefulSet, cr.Spec.Replicas) @@ -206,6 +209,12 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie } cr.Status.Phase = phase + logger.InfoContext(ctx, "Search head cluster health check", + "phase", string(cr.Status.Phase), + "deployer_phase", string(cr.Status.DeployerPhase), + "desired_replicas", cr.Spec.Replicas, + "ready_replicas", cr.Status.ReadyReplicas) + var finalResult *reconcile.Result if cr.Status.DeployerPhase == enterpriseApi.PhaseReady { finalResult = handleAppFrameworkActivity(ctx, client, cr, &cr.Status.AppContext, &cr.Spec.AppFrameworkConfig) @@ -224,7 +233,7 @@ func ApplySearchHeadCluster(ctx context.Context, client splcommon.ControllerClie namespacedName := types.NamespacedName{Namespace: cr.GetNamespace(), Name: GetSplunkStatefulsetName(SplunkMonitoringConsole, cr.GetNamespace())} err = splctrl.DeleteReferencesToAutomatedMCIfExists(ctx, client, cr, namespacedName) if err != nil { - scopedLog.Error(err, "Error in deleting automated monitoring console resource") + logger.ErrorContext(ctx, "Error in deleting automated monitoring console resource", "error", err) } // Reset secrets related status structs @@ -266,13 +275,12 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli return err } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyShcSecret").WithValues("Desired replicas", replicas, "ShcSecretChanged", mgr.cr.Status.ShcSecretChanged, "AdminSecretChanged", mgr.cr.Status.AdminSecretChanged, "CrStatusNamespaceSecretResourceVersion", mgr.cr.Status.NamespaceSecretResourceVersion, "NamespaceSecretResourceVersion", namespaceSecret.GetObjectMeta().GetResourceVersion()) + shcSecretLogger := logging.FromContext(ctx).With("func", "ApplyShcSecret", "desired_replicas", replicas) // If namespace scoped secret revision is the same ignore if len(mgr.cr.Status.NamespaceSecretResourceVersion) == 0 { // First time, set resource version in CR - scopedLog.Info("Setting CrStatusNamespaceSecretResourceVersion for the first time") + shcSecretLogger.InfoContext(ctx, "Setting CrStatusNamespaceSecretResourceVersion for the first time") mgr.cr.Status.NamespaceSecretResourceVersion = namespaceSecret.ObjectMeta.ResourceVersion return nil } else if mgr.cr.Status.NamespaceSecretResourceVersion == namespaceSecret.ObjectMeta.ResourceVersion { @@ -280,7 +288,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli return nil } - scopedLog.Info("Namespaced scoped secret revision has changed") + shcSecretLogger.InfoContext(ctx, "Namespaced scoped secret revision has changed") // Retrieve shc_secret password from secret data nsShcSecret := string(namespaceSecret.Data["shc_secret"]) @@ -293,8 +301,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli // Get search head pod's name shPodName := GetSplunkStatefulsetPodName(SplunkSearchHead, mgr.cr.GetName(), i) - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyShcSecretPodLoop").WithValues("Desired replicas", replicas, "ShcSecretChanged", mgr.cr.Status.ShcSecretChanged, "AdminSecretChanged", mgr.cr.Status.AdminSecretChanged, "NamespaceSecretResourceVersion", mgr.cr.Status.NamespaceSecretResourceVersion, "pod", shPodName) + podLogger := shcSecretLogger.With("pod", shPodName) // Retrieve shc_secret password from Pod shcSecret, err := splutil.GetSpecificSecretTokenFromPod(ctx, mgr.c, shPodName, mgr.cr.GetNamespace(), "shc_secret") @@ -315,7 +322,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli // If shc secret is different from namespace scoped secret change it if shcSecret != nsShcSecret { - scopedLog.Info("shcSecret different from namespace scoped secret, changing shc secret") + podLogger.InfoContext(ctx, "shcSecret different from namespace scoped secret, changing shc secret") // If shc secret already changed, ignore if i < int32(len(mgr.cr.Status.ShcSecretChanged)) { if mgr.cr.Status.ShcSecretChanged[i] { @@ -331,7 +338,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli if err != nil { return err } - scopedLog.Info("shcSecret changed") + podLogger.InfoContext(ctx, "shcSecret changed") // Get client for Pod and restart splunk instance on pod shClient := mgr.getClient(ctx, i) @@ -339,7 +346,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli if err != nil { return err } - scopedLog.Info("Restarted Splunk") + podLogger.InfoContext(ctx, "Restarted Splunk") // Set the shc_secret changed flag to true if i < int32(len(mgr.cr.Status.ShcSecretChanged)) { @@ -351,7 +358,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli // If admin secret is different from namespace scoped secret change it if adminPwd != nsAdminSecret { - scopedLog.Info("admin password different from namespace scoped secret, changing admin password") + podLogger.InfoContext(ctx, "admin password different from namespace scoped secret, changing admin password") // If admin password already changed, ignore if i < int32(len(mgr.cr.Status.AdminSecretChanged)) { if mgr.cr.Status.AdminSecretChanged[i] { @@ -366,7 +373,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli if err != nil { return err } - scopedLog.Info("admin password changed on the splunk instance of pod") + podLogger.InfoContext(ctx, "admin password changed on the splunk instance of pod") // Get client for Pod and restart splunk instance on pod shClient := mgr.getClient(ctx, i) @@ -374,13 +381,13 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli if err != nil { return err } - scopedLog.Info("Restarted Splunk") + podLogger.InfoContext(ctx, "Restarted Splunk") // Set the adminSecretChanged changed flag to true if i < int32(len(mgr.cr.Status.AdminSecretChanged)) { mgr.cr.Status.AdminSecretChanged[i] = true } else { - scopedLog.Info("Appending to AdminSecretChanged") + podLogger.InfoContext(ctx, "Appending to AdminSecretChanged") mgr.cr.Status.AdminSecretChanged = append(mgr.cr.Status.AdminSecretChanged, true) } @@ -390,7 +397,7 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli return err } mgr.cr.Status.AdminPasswordChangedSecrets[podSecret.GetName()] = true - scopedLog.Info("Secret mounted on pod(to be changed) added to map") + podLogger.InfoContext(ctx, "Secret mounted on pod(to be changed) added to map") } } @@ -413,61 +420,60 @@ func ApplyShcSecret(ctx context.Context, mgr *searchHeadClusterPodManager, repli if err != nil { return err } - scopedLog.Info("admin password changed on the secret mounted on pod") + shcSecretLogger.InfoContext(ctx, "admin password changed on the secret mounted on pod", "secret", podSecretName) } } return nil } -// getSearchHeadStatefulSet returns a Kubernetes StatefulSet object for Splunk Enterprise search heads. -func getSearchHeadStatefulSet(ctx context.Context, client splcommon.ControllerClient, cr *enterpriseApi.SearchHeadCluster) (*appsv1.StatefulSet, error) { - - // get search head env variables with deployer - env := getSearchHeadEnv(cr) - - // get generic statefulset for Splunk Enterprise objects - ss, err := getSplunkStatefulSet(ctx, client, cr, &cr.Spec.CommonSplunkSpec, SplunkSearchHead, cr.Spec.Replicas, env) - if err != nil { - return nil, err - } - - return ss, nil -} - // CSPL-3652 Configure deployer resources if configured // Use default otherwise // Make sure to set the resources ONLY for the deployer func setDeployerConfig(ctx context.Context, cr *enterpriseApi.SearchHeadCluster, podTemplate *corev1.PodTemplateSpec) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("setDeployerConfig").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + depLogger := logging.FromContext(ctx).With("func", "setDeployerConfig") // Break out if this is not a deployer if !strings.Contains("deployer", podTemplate.Labels["app.kubernetes.io/name"]) { - return errors.New("not a deployer, skipping setting resources") + return nil } depRes := cr.Spec.DeployerResourceSpec for i := range podTemplate.Spec.Containers { if len(depRes.Requests) != 0 { podTemplate.Spec.Containers[i].Resources.Requests = cr.Spec.DeployerResourceSpec.Requests - scopedLog.Info("Setting deployer resources requests", "requests", cr.Spec.DeployerResourceSpec.Requests) + depLogger.InfoContext(ctx, "Setting deployer resources requests", "requests", fmt.Sprint(cr.Spec.DeployerResourceSpec.Requests)) } if len(depRes.Limits) != 0 { podTemplate.Spec.Containers[i].Resources.Limits = cr.Spec.DeployerResourceSpec.Limits - scopedLog.Info("Setting deployer resources limits", "limits", cr.Spec.DeployerResourceSpec.Limits) + depLogger.InfoContext(ctx, "Setting deployer resources limits", "limits", fmt.Sprint(cr.Spec.DeployerResourceSpec.Limits)) } } // Add node affinity if configured if cr.Spec.DeployerNodeAffinity != nil { podTemplate.Spec.Affinity.NodeAffinity = cr.Spec.DeployerNodeAffinity - scopedLog.Info("Setting deployer node affinity", "nodeAffinity", cr.Spec.DeployerNodeAffinity) + depLogger.InfoContext(ctx, "Setting deployer node affinity") } return nil } +// getSearchHeadStatefulSet returns a Kubernetes StatefulSet object for Splunk Enterprise search heads. +func getSearchHeadStatefulSet(ctx context.Context, client splcommon.ControllerClient, cr *enterpriseApi.SearchHeadCluster) (*appsv1.StatefulSet, error) { + + // get search head env variables with deployer + env := getSearchHeadEnv(cr) + + // get generic statefulset for Splunk Enterprise objects + ss, err := getSplunkStatefulSet(ctx, client, cr, &cr.Spec.CommonSplunkSpec, SplunkSearchHead, cr.Spec.Replicas, env) + if err != nil { + return nil, err + } + + return ss, nil +} + // getDeployerStatefulSet returns a Kubernetes StatefulSet object for a Splunk Enterprise license manager. func getDeployerStatefulSet(ctx context.Context, client splcommon.ControllerClient, cr *enterpriseApi.SearchHeadCluster) (*appsv1.StatefulSet, error) { ss, err := getSplunkStatefulSet(ctx, client, cr, &cr.Spec.CommonSplunkSpec, SplunkDeployer, 1, getSearchHeadExtraEnv(cr, cr.Spec.Replicas)) @@ -505,14 +511,12 @@ func validateSearchHeadClusterSpec(ctx context.Context, c splcommon.ControllerCl // helper function to get the list of SearchHeadCluster types in the current namespace func getSearchHeadClusterList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (enterpriseApi.SearchHeadClusterList, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getSearchHeadClusterList").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "getSearchHeadClusterList") objectList := enterpriseApi.SearchHeadClusterList{} err := c.List(context.TODO(), &objectList, listOpts...) if err != nil { - scopedLog.Error(err, "SearchHeadCluster types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "SearchHeadCluster types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return objectList, err } diff --git a/pkg/splunk/enterprise/searchheadcluster_test.go b/pkg/splunk/enterprise/searchheadcluster_test.go index 569d0be8a..23b376fc7 100644 --- a/pkg/splunk/enterprise/searchheadcluster_test.go +++ b/pkg/splunk/enterprise/searchheadcluster_test.go @@ -41,7 +41,6 @@ import ( "sigs.k8s.io/controller-runtime/pkg/client" "sigs.k8s.io/controller-runtime/pkg/client/fake" - "github.com/go-logr/logr" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" @@ -184,7 +183,6 @@ func searchHeadClusterPodManagerTester(t *testing.T, method string, mockHandlers os.Setenv("SPLUNK_GENERAL_TERMS", "--accept-sgt-current-at-splunk-com") // test for updating - scopedLog := logt.WithName(method) cr := enterpriseApi.SearchHeadCluster{ TypeMeta: metav1.TypeMeta{ Kind: "SearchHeadCluster", @@ -213,7 +211,6 @@ func searchHeadClusterPodManagerTester(t *testing.T, method string, mockHandlers mockSplunkClient.AddHandlers(mockHandlers...) mgr := &searchHeadClusterPodManager{ - log: scopedLog, cr: &cr, secrets: secrets, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { @@ -419,7 +416,6 @@ func TestApplyShcSecret(t *testing.T) { os.Setenv("SPLUNK_GENERAL_TERMS", "--accept-sgt-current-at-splunk-com") ctx := context.TODO() method := "ApplyShcSecret" - scopedLog := logt.WithName(method) var initObjectList []client.Object c := spltest.NewMockClient() @@ -513,7 +509,6 @@ func TestApplyShcSecret(t *testing.T) { mockSplunkClient.AddHandlers(mockHandlers...) mgr := &searchHeadClusterPodManager{ c: c, - log: scopedLog, cr: &cr, secrets: secrets, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { @@ -1563,9 +1558,8 @@ func TestSearchHeadClusterWithReadyState(t *testing.T) { } // mock new search pod manager - newSearchHeadClusterPodManager = func(client splcommon.ControllerClient, log logr.Logger, cr *enterpriseApi.SearchHeadCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) searchHeadClusterPodManager { + newSearchHeadClusterPodManager = func(client splcommon.ControllerClient, cr *enterpriseApi.SearchHeadCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) searchHeadClusterPodManager { return searchHeadClusterPodManager{ - log: log, cr: cr, secrets: secret, newSplunkClient: func(managementURI, username, password string) *splclient.SplunkClient { diff --git a/pkg/splunk/enterprise/searchheadclusterpodmanager.go b/pkg/splunk/enterprise/searchheadclusterpodmanager.go index 093ce9fe9..a74d51637 100644 --- a/pkg/splunk/enterprise/searchheadclusterpodmanager.go +++ b/pkg/splunk/enterprise/searchheadclusterpodmanager.go @@ -5,9 +5,9 @@ import ( "fmt" "time" - "github.com/go-logr/logr" "github.com/prometheus/client_golang/prometheus" enterpriseApi "github.com/splunk/splunk-operator/api/v4" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" metrics "github.com/splunk/splunk-operator/pkg/splunk/client/metrics" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" @@ -15,22 +15,19 @@ import ( splutil "github.com/splunk/splunk-operator/pkg/splunk/util" appsv1 "k8s.io/api/apps/v1" corev1 "k8s.io/api/core/v1" - "sigs.k8s.io/controller-runtime/pkg/log" ) // searchHeadClusterPodManager is used to manage the pods within a search head cluster type searchHeadClusterPodManager struct { c splcommon.ControllerClient - log logr.Logger cr *enterpriseApi.SearchHeadCluster secrets *corev1.Secret newSplunkClient func(managementURI, username, password string) *splclient.SplunkClient } // newSerachHeadClusterPodManager function to create pod manager this is added to write unit test case -var newSearchHeadClusterPodManager = func(client splcommon.ControllerClient, log logr.Logger, cr *enterpriseApi.SearchHeadCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) searchHeadClusterPodManager { +var newSearchHeadClusterPodManager = func(client splcommon.ControllerClient, cr *enterpriseApi.SearchHeadCluster, secret *corev1.Secret, newSplunkClient NewSplunkClientFunc) searchHeadClusterPodManager { return searchHeadClusterPodManager{ - log: log, cr: cr, secrets: secret, newSplunkClient: newSplunkClient, @@ -40,6 +37,8 @@ var newSearchHeadClusterPodManager = func(client splcommon.ControllerClient, log // Update for searchHeadClusterPodManager handles all updates for a statefulset of search heads func (mgr *searchHeadClusterPodManager) Update(ctx context.Context, c splcommon.ControllerClient, statefulSet *appsv1.StatefulSet, desiredReplicas int32) (enterpriseApi.Phase, error) { + logger := logging.FromContext(ctx).With("func", "searchHeadClusterPodManager.Update") + // Assign client if mgr.c == nil { mgr.c = c @@ -63,7 +62,7 @@ func (mgr *searchHeadClusterPodManager) Update(ctx context.Context, c splcommon. // update CR status with SHC information err = mgr.updateStatus(ctx, statefulSet) if err != nil || mgr.cr.Status.ReadyReplicas == 0 || !mgr.cr.Status.Initialized || !mgr.cr.Status.CaptainReady { - mgr.log.Info("Search head cluster is not ready", "reason ", err) + logger.InfoContext(ctx, "Search head cluster is not ready", "error", err) return enterpriseApi.PhasePending, nil } @@ -73,6 +72,7 @@ func (mgr *searchHeadClusterPodManager) Update(ctx context.Context, c splcommon. // PrepareScaleDown for searchHeadClusterPodManager prepares search head pod to be removed via scale down event; it returns true when ready func (mgr *searchHeadClusterPodManager) PrepareScaleDown(ctx context.Context, n int32) (bool, error) { + logger := logging.FromContext(ctx).With("func", "PrepareScaleDown") // start by quarantining the pod result, err := mgr.PrepareRecycle(ctx, n) if err != nil || !result { @@ -81,7 +81,10 @@ func (mgr *searchHeadClusterPodManager) PrepareScaleDown(ctx context.Context, n // pod is quarantined; decommission it memberName := GetSplunkStatefulsetPodName(SplunkSearchHead, mgr.cr.GetName(), n) - mgr.log.Info("Removing member from search head cluster", "memberName", memberName) + logger.WarnContext(ctx, "Member leaving search head cluster", + "member", memberName, + "remaining_count", len(mgr.cr.Status.Members)-1) + c := mgr.getClient(ctx, n) err = c.RemoveSearchHeadClusterMember() if err != nil { @@ -94,12 +97,13 @@ func (mgr *searchHeadClusterPodManager) PrepareScaleDown(ctx context.Context, n // PrepareRecycle for searchHeadClusterPodManager prepares search head pod to be recycled for updates; it returns true when ready func (mgr *searchHeadClusterPodManager) PrepareRecycle(ctx context.Context, n int32) (bool, error) { + logger := logging.FromContext(ctx).With("func", "PrepareRecycle") memberName := GetSplunkStatefulsetPodName(SplunkSearchHead, mgr.cr.GetName(), n) switch mgr.cr.Status.Members[n].Status { case "Up": // Detain search head - mgr.log.Info("Detaining search head cluster member", "memberName", memberName) + logger.InfoContext(ctx, "Detaining search head cluster member", "memberName", memberName) c := mgr.getClient(ctx, n) podExecClient := splutil.GetPodExecClient(mgr.c, mgr.cr, getApplicablePodNameForK8Probes(mgr.cr, n)) @@ -110,14 +114,14 @@ func (mgr *searchHeadClusterPodManager) PrepareRecycle(ctx context.Context, n in // During the Recycle, our reconcile loop is entered multiple times. If the Pod is already down, // there is a chance of readiness probe failing, in which case, even the podExec will not be successful. // So, just log the message, and ignore the error. - mgr.log.Info("Setting Probe level failed. Probably, the Pod is already down", "memberName", memberName) + logger.WarnContext(ctx, "Setting Probe level failed. Probably, the Pod is already down", "memberName", memberName) } - mgr.log.Info("Initializes rolling upgrade process") + logger.InfoContext(ctx, "Initializes rolling upgrade process") err = c.InitiateUpgrade() if err != nil { - mgr.log.Info("Initialization of rolling upgrade failed.") + logger.ErrorContext(ctx, "Initialization of rolling upgrade failed", "error", err) return false, err } @@ -148,14 +152,14 @@ func (mgr *searchHeadClusterPodManager) PrepareRecycle(ctx context.Context, n in // Wait until active searches have drained searchesComplete := mgr.cr.Status.Members[n].ActiveHistoricalSearchCount+mgr.cr.Status.Members[n].ActiveRealtimeSearchCount == 0 if searchesComplete { - mgr.log.Info("Detention complete", "memberName", memberName) + logger.InfoContext(ctx, "Detention complete", "memberName", memberName) } else { - mgr.log.Info("Waiting for active searches to complete", "memberName", memberName) + logger.InfoContext(ctx, "Waiting for active searches to complete", "memberName", memberName) } return searchesComplete, nil case "": // this can happen after the member has already been recycled and we're just waiting for state to update - mgr.log.Info("Member has empty Status", "memberName", memberName) + logger.InfoContext(ctx, "Member has empty Status", "memberName", memberName) return false, nil } @@ -165,6 +169,7 @@ func (mgr *searchHeadClusterPodManager) PrepareRecycle(ctx context.Context, n in // FinishRecycle for searchHeadClusterPodManager completes recycle event for search head pod; it returns true when complete func (mgr *searchHeadClusterPodManager) FinishRecycle(ctx context.Context, n int32) (bool, error) { + logger := logging.FromContext(ctx).With("func", "FinishRecycle") memberName := GetSplunkStatefulsetPodName(SplunkSearchHead, mgr.cr.GetName(), n) switch mgr.cr.Status.Members[n].Status { @@ -174,7 +179,7 @@ func (mgr *searchHeadClusterPodManager) FinishRecycle(ctx context.Context, n int case "ManualDetention": // release from detention - mgr.log.Info("Releasing search head cluster member from detention", "memberName", memberName) + logger.InfoContext(ctx, "Releasing search head cluster member from detention", "memberName", memberName) c := mgr.getClient(ctx, n) return false, c.SetSearchHeadDetention(false) } @@ -184,11 +189,9 @@ func (mgr *searchHeadClusterPodManager) FinishRecycle(ctx context.Context, n int } func (mgr *searchHeadClusterPodManager) FinishUpgrade(ctx context.Context, n int32) error { - - reqLogger := log.FromContext(ctx) - // check if shc is in an upgrade process if mgr.cr.Status.UpgradePhase == enterpriseApi.UpgradePhaseUpgrading { + logger := logging.FromContext(ctx).With("func", "FinishUpgrade") c := mgr.getClient(ctx, n) // stop gathering metrics @@ -200,7 +203,7 @@ func (mgr *searchHeadClusterPodManager) FinishUpgrade(ctx context.Context, n int // revert upgrade state status mgr.cr.Status.UpgradePhase = enterpriseApi.UpgradePhaseUpgraded - reqLogger.Info("Finalize Upgrade") + logger.InfoContext(ctx, "Finalize Upgrade") return c.FinalizeUpgrade() } @@ -209,9 +212,7 @@ func (mgr *searchHeadClusterPodManager) FinishUpgrade(ctx context.Context, n int // getClient for searchHeadClusterPodManager returns a SplunkClient for the member n func (mgr *searchHeadClusterPodManager) getClient(ctx context.Context, n int32) *splclient.SplunkClient { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("searchHeadClusterPodManager.getClient").WithValues("name", mgr.cr.GetName(), "namespace", mgr.cr.GetNamespace()) - + logger := logging.FromContext(ctx).With("func", "searchHeadClusterPodManager.getClient") // Get Pod Name memberName := GetSplunkStatefulsetPodName(SplunkSearchHead, mgr.cr.GetName(), n) @@ -222,7 +223,7 @@ func (mgr *searchHeadClusterPodManager) getClient(ctx context.Context, n int32) // Retrieve admin password from Pod adminPwd, err := splutil.GetSpecificSecretTokenFromPod(ctx, mgr.c, memberName, mgr.cr.GetNamespace(), "password") if err != nil { - scopedLog.Error(err, "Couldn't retrieve the admin password from Pod") + logger.ErrorContext(ctx, "Couldn't retrieve the admin password from Pod", "member", memberName, "error", err) } return mgr.newSplunkClient(fmt.Sprintf("https://%s:8089", fqdnName), "admin", adminPwd) @@ -243,12 +244,18 @@ var GetSearchHeadCaptainInfo = func(ctx context.Context, mgr *searchHeadClusterP // updateStatus for searchHeadClusterPodManager uses the REST API to update the status for a SearcHead custom resource func (mgr *searchHeadClusterPodManager) updateStatus(ctx context.Context, statefulSet *appsv1.StatefulSet) error { // populate members status using REST API to get search head cluster member info + previousCaptain := mgr.cr.Status.Captain + previousMemberCount := int32(len(mgr.cr.Status.Members)) + mgr.cr.Status.Captain = "" mgr.cr.Status.CaptainReady = false mgr.cr.Status.ReadyReplicas = statefulSet.Status.ReadyReplicas if mgr.cr.Status.ReadyReplicas == 0 { return nil } + + shcLogger := logging.FromContext(ctx) + gotCaptainInfo := false for n := int32(0); n < statefulSet.Status.Replicas; n++ { memberName := GetSplunkStatefulsetPodName(SplunkSearchHead, mgr.cr.GetName(), n) @@ -261,7 +268,7 @@ func (mgr *searchHeadClusterPodManager) updateStatus(ctx context.Context, statef memberStatus.ActiveHistoricalSearchCount = memberInfo.ActiveHistoricalSearchCount memberStatus.ActiveRealtimeSearchCount = memberInfo.ActiveRealtimeSearchCount } else { - mgr.log.Error(err, "Unable to retrieve search head cluster member info", "memberName", memberName) + shcLogger.ErrorContext(ctx, "Unable to retrieve search head cluster member info", "memberName", memberName, "error", err) } if err == nil && !gotCaptainInfo { @@ -274,9 +281,17 @@ func (mgr *searchHeadClusterPodManager) updateStatus(ctx context.Context, statef mgr.cr.Status.MinPeersJoined = captainInfo.MinPeersJoined mgr.cr.Status.MaintenanceMode = captainInfo.MaintenanceMode gotCaptainInfo = true + + if previousCaptain != "" && previousCaptain != captainInfo.Label { + shcLogger.InfoContext(ctx, "Captain election completed", + "old_captain", previousCaptain, + "new_captain", captainInfo.Label) + } } else { mgr.cr.Status.CaptainReady = false - mgr.log.Error(err, "Unable to retrieve captain info", "memberName", memberName) + shcLogger.ErrorContext(ctx, "Captain election failed", + "member", memberName, + "error", err) } } @@ -292,5 +307,16 @@ func (mgr *searchHeadClusterPodManager) updateStatus(ctx context.Context, statef mgr.cr.Status.Members = mgr.cr.Status.Members[:statefulSet.Status.Replicas] } + newMemberCount := int32(len(mgr.cr.Status.Members)) + if newMemberCount > previousMemberCount { + shcLogger.InfoContext(ctx, "Member joined search head cluster", + "total_members", newMemberCount, + "previous_members", previousMemberCount) + } else if newMemberCount < previousMemberCount { + shcLogger.WarnContext(ctx, "Member left search head cluster", + "total_members", newMemberCount, + "previous_members", previousMemberCount) + } + return nil } diff --git a/pkg/splunk/enterprise/standalone.go b/pkg/splunk/enterprise/standalone.go index dbfa17051..468c5d0e4 100644 --- a/pkg/splunk/enterprise/standalone.go +++ b/pkg/splunk/enterprise/standalone.go @@ -23,6 +23,7 @@ import ( enterpriseApi "github.com/splunk/splunk-operator/api/v4" + "github.com/splunk/splunk-operator/pkg/logging" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" splutil "github.com/splunk/splunk-operator/pkg/splunk/util" @@ -30,7 +31,6 @@ import ( corev1 "k8s.io/api/core/v1" "k8s.io/apimachinery/pkg/types" "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" "sigs.k8s.io/controller-runtime/pkg/reconcile" ) @@ -43,8 +43,7 @@ func ApplyStandalone(ctx context.Context, client splcommon.ControllerClient, cr RequeueAfter: time.Second * 5, } - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplyStandalone") + logger := logging.FromContext(ctx).With("func", "ApplyStandalone") if cr.Status.ResourceRevMap == nil { cr.Status.ResourceRevMap = make(map[string]string) } @@ -63,7 +62,7 @@ func ApplyStandalone(ctx context.Context, client splcommon.ControllerClient, cr err = validateStandaloneSpec(ctx, client, cr) if err != nil { eventPublisher.Warning(ctx, "validateStandaloneSpec", fmt.Sprintf("validate standalone spec failed %s", err.Error())) - scopedLog.Error(err, "Failed to validate standalone spec") + logger.ErrorContext(ctx, "Failed to validate standalone spec", "error", err) return result, err } @@ -109,7 +108,7 @@ func ApplyStandalone(ctx context.Context, client splcommon.ControllerClient, cr // create or update general config resources _, err = ApplySplunkConfig(ctx, client, cr, cr.Spec.CommonSplunkSpec, SplunkStandalone) if err != nil { - scopedLog.Error(err, "create or update general config failed", "error", err.Error()) + logger.ErrorContext(ctx, "create or update general config failed", "error", err) eventPublisher.Warning(ctx, "ApplySplunkConfig", fmt.Sprintf("create or update general config failed with error %s", err.Error())) return result, err } @@ -239,7 +238,7 @@ func ApplyStandalone(ctx context.Context, client splcommon.ControllerClient, cr err = splctrl.DeleteReferencesToAutomatedMCIfExists(ctx, client, cr, namespacedName) if err != nil { eventPublisher.Warning(ctx, "DeleteReferencesToAutomatedMCIfExists", fmt.Sprintf("delete reference to automated MC if exists failed %s", err.Error())) - scopedLog.Error(err, "Error in deleting automated monitoring console resource") + logger.ErrorContext(ctx, "Error in deleting automated monitoring console resource", "error", err) } finalResult := handleAppFrameworkActivity(ctx, client, cr, &cr.Status.AppContext, &cr.Spec.AppFrameworkConfig) @@ -311,14 +310,12 @@ func validateStandaloneSpec(ctx context.Context, c splcommon.ControllerClient, c // helper function to get the list of Standalone types in the current namespace func getStandaloneList(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, listOpts []client.ListOption) (enterpriseApi.StandaloneList, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getStandaloneList") - + logger := logging.FromContext(ctx).With("func", "getStandaloneList") objectList := enterpriseApi.StandaloneList{} err := c.List(context.TODO(), &objectList, listOpts...) if err != nil { - scopedLog.Error(err, "Standalone types not found in namespace", "namsespace", cr.GetNamespace()) + logger.ErrorContext(ctx, "Standalone types not found in namespace", "namespace", cr.GetNamespace(), "error", err) return objectList, err } diff --git a/pkg/splunk/enterprise/upgrade.go b/pkg/splunk/enterprise/upgrade.go index 5d50e8cec..d35a06ccb 100644 --- a/pkg/splunk/enterprise/upgrade.go +++ b/pkg/splunk/enterprise/upgrade.go @@ -5,6 +5,7 @@ import ( "fmt" enterpriseApi "github.com/splunk/splunk-operator/api/v4" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" appsv1 "k8s.io/api/apps/v1" @@ -12,7 +13,6 @@ import ( "k8s.io/apimachinery/pkg/types" rclient "sigs.k8s.io/controller-runtime/pkg/client" runtime "sigs.k8s.io/controller-runtime/pkg/client" - "sigs.k8s.io/controller-runtime/pkg/log" ) // helps in mock function @@ -34,11 +34,10 @@ var GetClusterInfoCall = func(ctx context.Context, mgr *indexerClusterPodManager // function returns bool and error , true - go ahead with upgrade // false - exit the reconciliation loop with error func UpgradePathValidation(ctx context.Context, c splcommon.ControllerClient, cr splcommon.MetaObject, spec enterpriseApi.CommonSplunkSpec, mgr *indexerClusterPodManager) (bool, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("isClusterManagerReadyForUpgrade").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "UpgradePathValidation") eventPublisher, _ := newK8EventPublisher(c, cr) kind := cr.GroupVersionKind().Kind - scopedLog.Info("kind is set to ", "kind", kind) + logger.InfoContext(ctx, "kind is set to", "kind", kind) // start from standalone first goto Standalone @@ -76,7 +75,7 @@ LicenseManager: lmImage, err := getCurrentImage(ctx, c, licenseManager, SplunkLicenseManager) if err != nil { eventPublisher.Warning(ctx, "isClusterManagerReadyForUpgrade", fmt.Sprintf("Could not get the License Manager Image. Reason %v", err)) - scopedLog.Error(err, "Unable to get licenseManager current image") + logger.ErrorContext(ctx, "Unable to get licenseManager current image", "error", err) return false, err } // if license manager status is ready and CR spec and current license manager image are not same @@ -123,7 +122,7 @@ ClusterManager: err := c.Get(ctx, namespacedName, clusterManager) if err != nil { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not find the Cluster Manager. Reason %v", err)) - scopedLog.Error(err, "Unable to get clusterManager") + logger.ErrorContext(ctx, "Unable to get clusterManager", "error", err) goto SearchHeadCluster } @@ -131,7 +130,7 @@ ClusterManager: cmImage, err := getCurrentImage(ctx, c, clusterManager, SplunkClusterManager) if err != nil { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not get the Cluster Manager Image. Reason %v", err)) - scopedLog.Error(err, "Unable to get clusterManager current image") + logger.ErrorContext(ctx, "Unable to get clusterManager current image", "error", err) return false, err } @@ -248,7 +247,7 @@ SearchHeadCluster: shcImage, err := getCurrentImage(ctx, c, &searchHeadClusterInstance, SplunkSearchHead) if err != nil { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not get the Search Head Cluster Image. Reason %v", err)) - scopedLog.Error(err, "Unable to get SearchHeadCluster current image") + logger.ErrorContext(ctx, "Unable to get SearchHeadCluster current image", "error", err) return false, err } @@ -271,7 +270,7 @@ MonitoringConsole: err := c.List(ctx, clusterManagerList, listOpts...) if err != nil && err.Error() != "NotFound" { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not find the Cluster Manager list. Reason %v", err)) - scopedLog.Error(err, "Unable to get clusterManager list") + logger.ErrorContext(ctx, "Unable to get clusterManager list", "error", err) return false, err } @@ -289,7 +288,7 @@ MonitoringConsole: err = c.List(ctx, searchHeadClusterList, listOpts...) if err != nil && err.Error() != "NotFound" { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not find the Search Head Cluster list. Reason %v", err)) - scopedLog.Error(err, "Unable to get Search Head Cluster list") + logger.ErrorContext(ctx, "Unable to get Search Head Cluster list", "error", err) return false, err } @@ -307,7 +306,7 @@ MonitoringConsole: err = c.List(ctx, indexerClusterList, listOpts...) if err != nil && err.Error() != "NotFound" { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not find the Indexer list. Reason %v", err)) - scopedLog.Error(err, "Unable to get indexer cluster list") + logger.ErrorContext(ctx, "Unable to get indexer cluster list", "error", err) return false, err } @@ -325,7 +324,7 @@ MonitoringConsole: err = c.List(ctx, standaloneList, listOpts...) if err != nil && err.Error() != "NotFound" { eventPublisher.Warning(ctx, "UpgradePathValidation", fmt.Sprintf("Could not find the Standalone list. Reason %v", err)) - scopedLog.Error(err, "Unable to get standalone list") + logger.ErrorContext(ctx, "Unable to get standalone list", "error", err) return false, err } diff --git a/pkg/splunk/enterprise/util.go b/pkg/splunk/enterprise/util.go index abd96482a..b61c6fe19 100644 --- a/pkg/splunk/enterprise/util.go +++ b/pkg/splunk/enterprise/util.go @@ -47,6 +47,7 @@ import ( "sigs.k8s.io/controller-runtime/pkg/reconcile" enterpriseApiV3 "github.com/splunk/splunk-operator/api/v3" + "github.com/splunk/splunk-operator/pkg/logging" splclient "github.com/splunk/splunk-operator/pkg/splunk/client" splcommon "github.com/splunk/splunk-operator/pkg/splunk/common" splctrl "github.com/splunk/splunk-operator/pkg/splunk/splkcontroller" @@ -136,8 +137,7 @@ func updateStorageTracker(ctx context.Context) error { // GetRemoteStorageClient returns the corresponding RemoteDataClient func GetRemoteStorageClient(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, appFrameworkRef *enterpriseApi.AppFrameworkSpec, vol *enterpriseApi.VolumeSpec, location string, fn splclient.GetInitFunc) (splclient.SplunkRemoteDataClient, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("GetRemoteStorageClient").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "GetRemoteStorageClient") remoteDataClient := splclient.SplunkRemoteDataClient{} //use the provider name to get the corresponding function pointer @@ -149,7 +149,7 @@ func GetRemoteStorageClient(ctx context.Context, client splcommon.ControllerClie var secretAccessKey string if appSecretRef == "" { // No secretRef means we should try to use the credentials available in the pod already via kube2iam or something similar - scopedLog.Info("No secrectRef provided. Attempt to access remote storage client without access/secret keys") + logger.InfoContext(ctx, "No secretRef provided. Attempt to access remote storage client without access/secret keys") accessKeyID = "" secretAccessKey = "" } else { @@ -197,14 +197,14 @@ func GetRemoteStorageClient(ctx context.Context, client splcommon.ControllerClie // Ex. ("a/b" + "c"), ("a/b/" + "c"), ("a/b/" + "/c"), ("a/b/" + "/c"), ("a/b//", + "c/././") ("a/b/../b", + "c/../c") all are joined as "a/b/c" prefix := filepath.Join(basePrefix, location) + "/" - scopedLog.Info("Creating the client", "volume", vol.Name, "bucket", bucket, "bucket path", prefix) + logger.InfoContext(ctx, "Creating the client", "volume", vol.Name, "bucket", bucket, "bucket path", prefix) var err error remoteDataClient.Client, err = getClient(ctx, bucket, accessKeyID, secretAccessKey, prefix, prefix /* startAfter*/, vol.Region, vol.Endpoint, fn) if err != nil { - scopedLog.Error(err, "Failed to get the S3 client") + logger.ErrorContext(ctx, "Failed to get the S3 client", "error", err) return remoteDataClient, err } @@ -246,8 +246,7 @@ func ApplySplunkConfig(ctx context.Context, client splcommon.ControllerClient, c // ReconcileCRSpecificConfigMap reconciles CR Specific config map exists and contains the ManualUpdate field set to "off" func ReconcileCRSpecificConfigMap(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, instanceType InstanceType) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ReconcileCRSpecificConfigMap").WithValues("name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "ReconcileCRSpecificConfigMap") a := cr.GetObjectKind() b := a.GroupVersionKind() c := b.Kind @@ -272,13 +271,13 @@ func ReconcileCRSpecificConfigMap(ctx context.Context, client splcommon.Controll configMap.SetOwnerReferences(append(configMap.GetOwnerReferences(), splcommon.AsOwner(cr, true))) err = client.Create(ctx, configMap) if err != nil { - scopedLog.Error(err, "Failed to create config map") + logger.ErrorContext(ctx, "Failed to create config map", "error", err) return err } - scopedLog.Info("Created new config map with ManualUpdate set to 'on'") + logger.InfoContext(ctx, "Created new config map with ManualUpdate set to 'off'") return nil } - scopedLog.Error(err, "Failed to get config map") + logger.ErrorContext(ctx, "Failed to get config map", "error", err) return err } @@ -287,10 +286,10 @@ func ReconcileCRSpecificConfigMap(ctx context.Context, client splcommon.Controll configMap.Data["manualUpdate"] = "off" err = client.Update(ctx, configMap) if err != nil { - scopedLog.Error(err, "Failed to update config map with manualUpdate field") + logger.ErrorContext(ctx, "Failed to update config map with manualUpdate field", "error", err) return err } - scopedLog.Info("Updated config map with manualUpdate set to 'on'") + logger.InfoContext(ctx, "Updated config map with manualUpdate set to 'on'") } return nil @@ -472,10 +471,8 @@ func bundlePushStateAsStr(ctx context.Context, state enterpriseApi.BundlePushSta // setBundlePushState sets the bundle push state to the new state func setBundlePushState(ctx context.Context, afwPipeline *AppInstallPipeline, state enterpriseApi.BundlePushStageType) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("setBundlePushState") - - scopedLog.Info("Setting the bundle push state", "old state", bundlePushStateAsStr(ctx, afwPipeline.appDeployContext.BundlePushStatus.BundlePushStage), "new state", bundlePushStateAsStr(ctx, state)) + logger := logging.FromContext(ctx).With("func", "setBundlePushState") + logger.InfoContext(ctx, "Setting the bundle push state", "old state", bundlePushStateAsStr(ctx, afwPipeline.appDeployContext.BundlePushStatus.BundlePushStage), "new state", bundlePushStateAsStr(ctx, state)) afwPipeline.appDeployContext.BundlePushStatus.BundlePushStage = state } @@ -486,13 +483,12 @@ func getBundlePushState(afwPipeline *AppInstallPipeline) enterpriseApi.BundlePus // createAppDownloadDir creates the app download directory on the operator pod func createAppDownloadDir(ctx context.Context, path string) error { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("createAppDownloadDir").WithValues("path", path) _, err := os.Stat(path) if errors.Is(err, os.ErrNotExist) { errDir := os.MkdirAll(path, 0700) if errDir != nil { - scopedLog.Error(errDir, "Unable to create directory at path") + logger := logging.FromContext(ctx).With("func", "createAppDownloadDir") + logger.ErrorContext(ctx, "Unable to create directory at path", "path", path, "error", errDir) return errDir } } @@ -503,16 +499,15 @@ func createAppDownloadDir(ctx context.Context, path string) error { func getAvailableDiskSpace(ctx context.Context) (uint64, error) { var availDiskSpace uint64 var stat syscall.Statfs_t - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getAvailableDiskSpace").WithValues("volume mount", splcommon.AppDownloadVolume) + logger := logging.FromContext(ctx).With("func", "getAvailableDiskSpace") err := syscall.Statfs(splcommon.AppDownloadVolume, &stat) if err != nil { - scopedLog.Error(err, "There is no default volume configured for the App framework, use the temporary location", "dir", TmpAppDownloadDir) + logger.ErrorContext(ctx, "There is no default volume configured for the App framework, use the temporary location", "dir", TmpAppDownloadDir, "error", err) splcommon.AppDownloadVolume = TmpAppDownloadDir err = os.MkdirAll(splcommon.AppDownloadVolume, 0700) if err != nil { - scopedLog.Error(err, "Unable to create the directory", "dir", splcommon.AppDownloadVolume) + logger.ErrorContext(ctx, "Unable to create the directory", "dir", splcommon.AppDownloadVolume, "error", err) return 0, err } } @@ -523,7 +518,7 @@ func getAvailableDiskSpace(ctx context.Context) (uint64, error) { } availDiskSpace = stat.Bavail * uint64(stat.Bsize) - scopedLog.Info("current available disk space in GB", "availableDiskSpace(GB)", availDiskSpace/1024/1024/1024) + logger.InfoContext(ctx, "current available disk space in GB", "availableDiskSpace(GB)", availDiskSpace/1024/1024/1024) return availDiskSpace, err } @@ -533,18 +528,17 @@ func getRemoteObjectKey(ctx context.Context, cr splcommon.MetaObject, appFramewo var remoteObjectKey string var vol enterpriseApi.VolumeSpec - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("getRemoteObjectKey").WithValues("crName", cr.GetName(), "namespace", cr.GetNamespace(), "appSrcName", appSrcName, "appName", appName) + logger := logging.FromContext(ctx).With("func", "getRemoteObjectKey") appSrc, err := getAppSrcSpec(appFrameworkConfig.AppSources, appSrcName) if err != nil { - scopedLog.Error(err, "unable to get appSourceSpec") + logger.ErrorContext(ctx, "unable to get appSourceSpec", "error", err) return remoteObjectKey, err } vol, err = splclient.GetAppSrcVolume(ctx, *appSrc, appFrameworkConfig) if err != nil { - scopedLog.Error(err, "unable to get volume spec") + logger.ErrorContext(ctx, "unable to get volume spec", "error", err) return remoteObjectKey, err } @@ -566,18 +560,17 @@ func getRemoteObjectKey(ctx context.Context, cr splcommon.MetaObject, appFramewo // getRemoteDataClientMgr gets the RemoteDataClientMgr instance to download apps func getRemoteDataClientMgr(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, appFrameworkConfig *enterpriseApi.AppFrameworkSpec, appSrcName string) (*RemoteDataClientManager, error) { - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("RemoteDataClientMgr").WithValues("crName", cr.GetName(), "namespace", cr.GetNamespace(), "appSrcName", appSrcName) + logger := logging.FromContext(ctx).With("func", "getRemoteDataClientMgr") var vol enterpriseApi.VolumeSpec appSrc, err := getAppSrcSpec(appFrameworkConfig.AppSources, appSrcName) if err != nil { - scopedLog.Error(err, "unable to get appSrcSpc") + logger.ErrorContext(ctx, "unable to get appSrcSpec", "error", err) return nil, err } vol, err = splclient.GetAppSrcVolume(ctx, *appSrc, appFrameworkConfig) if err != nil { - scopedLog.Error(err, "unable to get volume spec") + logger.ErrorContext(ctx, "unable to get volume spec", "error", err) return nil, err } @@ -624,8 +617,7 @@ func ApplySmartstoreConfigMap(ctx context.Context, client splcommon.ControllerCl var configMapDataChanged bool crKind = cr.GetObjectKind().GroupVersionKind().Kind - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ApplySmartStoreConfigMap").WithValues("kind", crKind, "name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "ApplySmartstoreConfigMap") // 1. Prepare the indexes.conf entries mapSplunkConfDetails := make(map[string]string) @@ -637,14 +629,14 @@ func ApplySmartstoreConfigMap(ctx context.Context, client splcommon.ControllerCl } if volumesConfIni == "" { - scopedLog.Info("Volume stanza list is empty") + logger.DebugContext(ctx, "Volume stanza list is empty") } // Get the list of indexes in INI format indexesConfIni := GetSmartstoreIndexesConfig(smartstore.IndexList) if indexesConfIni == "" { - scopedLog.Info("Index stanza list is empty") + logger.DebugContext(ctx, "Index stanza list is empty") } else if volumesConfIni == "" { return nil, configMapDataChanged, fmt.Errorf("indexes without Volume configuration is not allowed") } @@ -675,7 +667,7 @@ func ApplySmartstoreConfigMap(ctx context.Context, client splcommon.ControllerCl configMapDataChanged, err = splctrl.ApplyConfigMap(ctx, client, SplunkOperatorAppConfigMap) if err != nil { - scopedLog.Error(err, "config map create/update failed", "error", err.Error()) + logger.ErrorContext(ctx, "config map create/update failed", "error", err) return nil, configMapDataChanged, err } else if configMapDataChanged { // Create a token to check if the config is really populated to the pod @@ -695,7 +687,7 @@ func ApplySmartstoreConfigMap(ctx context.Context, client splcommon.ControllerCl } } if err != nil { - scopedLog.Error(err, "config map update failed", "error", err.Error()) + logger.ErrorContext(ctx, "config map update failed", "error", err) return nil, configMapDataChanged, err } } @@ -708,8 +700,7 @@ func ApplySmartstoreConfigMap(ctx context.Context, client splcommon.ControllerCl // are wiped out due to bundle push and hence we need to reinstate it in case of any smartstore changes. var resetSymbolicLinks = func(ctx context.Context, client splcommon.ControllerClient, cr splcommon.MetaObject, replicas int32, podExecClient splutil.PodExecClientImpl) error { crKind := cr.GetObjectKind().GroupVersionKind().Kind - reqLogger := log.FromContext(ctx) - scopedLog := reqLogger.WithName("ResetSymbolicLinks").WithValues("kind", crKind, "name", cr.GetName(), "namespace", cr.GetNamespace()) + logger := logging.FromContext(ctx).With("func", "resetSymbolicLinks") // Create command for symbolic link creation var command string @@ -722,11 +713,11 @@ var resetSymbolicLinks = func(ctx context.Context, client splcommon.ControllerCl // Run the commands on Splunk pods err := runCustomCommandOnSplunkPods(ctx, cr, replicas, command, podExecClient) if err != nil { - scopedLog.Error(err, "unable to run command on splunk pod") + logger.ErrorContext(ctx, "unable to run command on splunk pod", "error", err) return err } - scopedLog.Info("Reset symbolic links successfully") + logger.InfoContext(ctx, "Reset symbolic links successfully") // All good return nil