From 320bf7cd3964bcb46553c1ece23a4cdc0953d840 Mon Sep 17 00:00:00 2001 From: Philip Laine Date: Mon, 29 Jul 2024 10:56:34 +0200 Subject: [PATCH] refactor: replace message.Debug with context logger Signed-off-by: Philip Laine --- src/cmd/dev.go | 8 +-- src/cmd/initialize.go | 2 +- src/cmd/package.go | 23 ++++---- src/cmd/root.go | 6 +++ src/cmd/tools/wait.go | 4 +- src/config/lang/english.go | 5 +- src/internal/git/repository.go | 11 ++-- src/internal/packager/helm/chart.go | 3 +- src/internal/packager/helm/post-render.go | 7 ++- src/internal/packager/helm/repo.go | 5 +- src/internal/packager/images/pull.go | 2 +- src/internal/packager/images/push.go | 2 - src/internal/packager/sbom/catalog.go | 6 ++- src/pkg/cluster/cluster.go | 9 ++-- src/pkg/cluster/data.go | 18 ++++--- src/pkg/cluster/secrets.go | 3 +- src/pkg/cluster/state.go | 11 ++-- src/pkg/cluster/tunnel.go | 21 ++++---- src/pkg/cluster/zarf.go | 3 +- src/pkg/layout/component.go | 7 +-- src/pkg/layout/package.go | 4 -- src/pkg/logging/handler.go | 66 +++++++++++++++++++++++ src/pkg/logging/logging.go | 32 +++++++++++ src/pkg/packager/actions/actions.go | 9 ++-- src/pkg/packager/common.go | 5 +- src/pkg/packager/composer/oci.go | 6 +-- src/pkg/packager/creator/normal.go | 7 +-- src/pkg/packager/deploy.go | 19 ++++--- src/pkg/packager/deploy_test.go | 3 +- src/pkg/packager/prepare.go | 17 +++--- src/pkg/packager/remove.go | 3 +- src/pkg/packager/sources/validate.go | 4 +- src/pkg/utils/bytes.go | 10 ++-- src/pkg/utils/cosign.go | 9 ++-- src/pkg/utils/wait.go | 24 +++++---- src/pkg/zoci/pull.go | 2 +- 36 files changed, 257 insertions(+), 119 deletions(-) create mode 100644 src/pkg/logging/handler.go create mode 100644 src/pkg/logging/logging.go diff --git a/src/cmd/dev.go b/src/cmd/dev.go index 322b82fb84..f561260f45 100644 --- a/src/cmd/dev.go +++ b/src/cmd/dev.go @@ -53,7 +53,7 @@ var devDeployCmd = &cobra.Command{ pkgConfig.PkgOpts.SetVariables = helpers.TransformAndMergeMap( v.GetStringMapString(common.VPkgDeploySet), pkgConfig.PkgOpts.SetVariables, strings.ToUpper) - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -78,7 +78,7 @@ var devGenerateCmd = &cobra.Command{ pkgConfig.CreateOpts.BaseDir = "." pkgConfig.FindImagesOpts.RepoHelmChartPath = pkgConfig.GenerateOpts.GitPath - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -229,7 +229,7 @@ var devFindImagesCmd = &cobra.Command{ v.GetStringMapString(common.VPkgCreateSet), pkgConfig.CreateOpts.SetVariables, strings.ToUpper) pkgConfig.PkgOpts.SetVariables = helpers.TransformAndMergeMap( v.GetStringMapString(common.VPkgDeploySet), pkgConfig.PkgOpts.SetVariables, strings.ToUpper) - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -276,7 +276,7 @@ var devLintCmd = &cobra.Command{ pkgConfig.CreateOpts.SetVariables = helpers.TransformAndMergeMap( v.GetStringMapString(common.VPkgCreateSet), pkgConfig.CreateOpts.SetVariables, strings.ToUpper) - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } diff --git a/src/cmd/initialize.go b/src/cmd/initialize.go index 4d1c61363b..17e98b4bf5 100644 --- a/src/cmd/initialize.go +++ b/src/cmd/initialize.go @@ -63,7 +63,7 @@ var initCmd = &cobra.Command{ pkgConfig.PkgOpts.SetVariables = helpers.TransformAndMergeMap( v.GetStringMapString(common.VPkgDeploySet), pkgConfig.PkgOpts.SetVariables, strings.ToUpper) - pkgClient, err := packager.New(&pkgConfig, packager.WithSource(src)) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig, packager.WithSource(src)) if err != nil { return err } diff --git a/src/cmd/package.go b/src/cmd/package.go index 8b1405e25c..b98331610f 100644 --- a/src/cmd/package.go +++ b/src/cmd/package.go @@ -14,6 +14,7 @@ import ( "github.com/zarf-dev/zarf/src/cmd/common" "github.com/zarf-dev/zarf/src/config/lang" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/packager/sources" "github.com/zarf-dev/zarf/src/types" @@ -54,7 +55,7 @@ var packageCreateCmd = &cobra.Command{ pkgConfig.CreateOpts.SetVariables = helpers.TransformAndMergeMap( v.GetStringMapString(common.VPkgCreateSet), pkgConfig.CreateOpts.SetVariables, strings.ToUpper) - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -84,7 +85,7 @@ var packageDeployCmd = &cobra.Command{ pkgConfig.PkgOpts.SetVariables = helpers.TransformAndMergeMap( v.GetStringMapString(common.VPkgDeploySet), pkgConfig.PkgOpts.SetVariables, strings.ToUpper) - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -112,7 +113,7 @@ var packageMirrorCmd = &cobra.Command{ return err } pkgConfig.PkgOpts.PackageSource = packageSource - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -136,11 +137,11 @@ var packageInspectCmd = &cobra.Command{ return err } pkgConfig.PkgOpts.PackageSource = packageSource - src, err := identifyAndFallbackToClusterSource() + src, err := identifyAndFallbackToClusterSource(cmd.Context()) if err != nil { return err } - pkgClient, err := packager.New(&pkgConfig, packager.WithSource(src)) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig, packager.WithSource(src)) if err != nil { return err } @@ -208,11 +209,11 @@ var packageRemoveCmd = &cobra.Command{ return err } pkgConfig.PkgOpts.PackageSource = packageSource - src, err := identifyAndFallbackToClusterSource() + src, err := identifyAndFallbackToClusterSource(cmd.Context()) if err != nil { return err } - pkgClient, err := packager.New(&pkgConfig, packager.WithSource(src)) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig, packager.WithSource(src)) if err != nil { return err } @@ -253,7 +254,7 @@ var packagePublishCmd = &cobra.Command{ pkgConfig.PublishOpts.PackageDestination = ref.String() - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -273,7 +274,7 @@ var packagePullCmd = &cobra.Command{ Args: cobra.ExactArgs(1), RunE: func(cmd *cobra.Command, args []string) error { pkgConfig.PkgOpts.PackageSource = args[0] - pkgClient, err := packager.New(&pkgConfig) + pkgClient, err := packager.New(cmd.Context(), &pkgConfig) if err != nil { return err } @@ -311,10 +312,10 @@ func choosePackage(args []string) (string, error) { } // TODO: This code does not seem to do what it was intended. -func identifyAndFallbackToClusterSource() (sources.PackageSource, error) { +func identifyAndFallbackToClusterSource(ctx context.Context) (sources.PackageSource, error) { identifiedSrc := sources.Identify(pkgConfig.PkgOpts.PackageSource) if identifiedSrc == "" { - message.Debugf(lang.CmdPackageClusterSourceFallback, pkgConfig.PkgOpts.PackageSource) + logging.FromContextOrDiscard(ctx).Debug("package source does not satisfy any current sources, assuming it is a package deployed to a cluster", "source", pkgConfig.PkgOpts.PackageSource) src, err := sources.NewClusterSource(&pkgConfig.PkgOpts) if err != nil { return nil, fmt.Errorf("unable to identify source from %s: %w", pkgConfig.PkgOpts.PackageSource, err) diff --git a/src/cmd/root.go b/src/cmd/root.go index 876efdf20e..494bb0f0f7 100644 --- a/src/cmd/root.go +++ b/src/cmd/root.go @@ -7,6 +7,7 @@ package cmd import ( "context" "fmt" + "log/slog" "os" "slices" "strings" @@ -19,6 +20,7 @@ import ( "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/config/lang" "github.com/zarf-dev/zarf/src/pkg/layout" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/types" ) @@ -87,6 +89,10 @@ var rootCmd = &cobra.Command{ // Execute is the entrypoint for the CLI. func Execute(ctx context.Context) { + handler := logging.NewPtermHandler() + log := slog.New(handler) + ctx = logging.NewContext(ctx, log) + cmd, err := rootCmd.ExecuteContextC(ctx) if err == nil { return diff --git a/src/cmd/tools/wait.go b/src/cmd/tools/wait.go index fda0344fbc..ad5184dd20 100644 --- a/src/cmd/tools/wait.go +++ b/src/cmd/tools/wait.go @@ -29,7 +29,7 @@ var waitForCmd = &cobra.Command{ Long: lang.CmdToolsWaitForLong, Example: lang.CmdToolsWaitForExample, Args: cobra.MinimumNArgs(1), - RunE: func(_ *cobra.Command, args []string) error { + RunE: func(cmd *cobra.Command, args []string) error { // Parse the timeout string timeout, err := time.ParseDuration(waitTimeout) if err != nil { @@ -51,7 +51,7 @@ var waitForCmd = &cobra.Command{ } // Execute the wait command. - if err := utils.ExecuteWait(waitTimeout, waitNamespace, condition, kind, identifier, timeout); err != nil { + if err := utils.ExecuteWait(cmd.Context(), waitTimeout, waitNamespace, condition, kind, identifier, timeout); err != nil { return err } return err diff --git a/src/config/lang/english.go b/src/config/lang/english.go index 8e821b03f2..7b84e5a033 100644 --- a/src/config/lang/english.go +++ b/src/config/lang/english.go @@ -314,9 +314,8 @@ $ zarf package pull oci://ghcr.io/defenseunicorns/packages/dos-games:1.0.0 -a ar $ zarf package pull oci://ghcr.io/defenseunicorns/packages/dos-games:1.0.0 -a skeleton` CmdPackagePullFlagOutputDirectory = "Specify the output directory for the pulled Zarf package" - CmdPackageChoose = "Choose or type the package file" - CmdPackageClusterSourceFallback = "%q does not satisfy any current sources, assuming it is a package deployed to a cluster" - CmdPackageInvalidSource = "Unable to identify source from %q: %s" + CmdPackageChoose = "Choose or type the package file" + CmdPackageInvalidSource = "Unable to identify source from %q: %s" // zarf dev (prepare is an alias for dev) CmdDevShort = "Commands useful for developing packages" diff --git a/src/internal/git/repository.go b/src/internal/git/repository.go index 9d2b2d4918..d694f307a9 100644 --- a/src/internal/git/repository.go +++ b/src/internal/git/repository.go @@ -18,6 +18,7 @@ import ( "github.com/go-git/go-git/v5/plumbing/transport" "github.com/go-git/go-git/v5/plumbing/transport/http" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/transform" "github.com/zarf-dev/zarf/src/pkg/utils" @@ -146,6 +147,8 @@ func (r *Repository) Path() string { // Push pushes the repository to the remote git server. func (r *Repository) Push(ctx context.Context, address, username, password string) error { + log := logging.FromContextOrDiscard(ctx) + repo, err := git.PlainOpen(r.path) if err != nil { return fmt.Errorf("not a valid git repo or unable to open: %w", err) @@ -194,11 +197,11 @@ func (r *Repository) Push(ctx context.Context, address, username, password strin } err = repo.FetchContext(ctx, fetchOptions) if errors.Is(err, transport.ErrRepositoryNotFound) { - message.Debugf("Repo not yet available offline, skipping fetch...") + log.Debug("repository not yet available offling, skipping fetch") } else if errors.Is(err, git.ErrForceNeeded) { - message.Debugf("Repo fetch requires force, skipping fetch...") + log.Debug("repositoy fetch requires force, skipping fetch") } else if errors.Is(err, git.NoErrAlreadyUpToDate) { - message.Debugf("Repo already up-to-date, skipping fetch...") + log.Debug("repository already update-to date, skipping fetch") } else if err != nil { return fmt.Errorf("unable to fetch the git repo prior to push: %w", err) } @@ -216,7 +219,7 @@ func (r *Repository) Push(ctx context.Context, address, username, password strin }, }) if errors.Is(err, git.NoErrAlreadyUpToDate) { - message.Debug("Repo already up-to-date") + logging.FromContextOrDiscard(ctx).Debug("Repository already up-to-date") } else if errors.Is(err, plumbing.ErrObjectNotFound) { return fmt.Errorf("unable to push repo due to likely shallow clone: %s", err.Error()) } else if err != nil { diff --git a/src/internal/packager/helm/chart.go b/src/internal/packager/helm/chart.go index 26f81e1a9b..6c473828b4 100644 --- a/src/internal/packager/helm/chart.go +++ b/src/internal/packager/helm/chart.go @@ -195,8 +195,7 @@ func (h *Helm) RemoveChart(namespace string, name string, spinner *message.Spinn // Establish a new actionConfig for the namespace. _ = h.createActionConfig(namespace, spinner) // Perform the uninstall. - response, err := h.uninstallChart(name) - message.Debug(response) + _, err := h.uninstallChart(name) return err } diff --git a/src/internal/packager/helm/post-render.go b/src/internal/packager/helm/post-render.go index c316375acb..309c281092 100644 --- a/src/internal/packager/helm/post-render.go +++ b/src/internal/packager/helm/post-render.go @@ -16,6 +16,7 @@ import ( "github.com/defenseunicorns/pkg/helpers/v2" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/pkg/cluster" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/utils" "github.com/zarf-dev/zarf/src/types" @@ -208,6 +209,8 @@ func (r *renderer) adoptAndUpdateNamespaces(ctx context.Context) error { } func (r *renderer) editHelmResources(ctx context.Context, resources []releaseutil.Manifest, finalManifestsOutput *bytes.Buffer) error { + log := logging.FromContextOrDiscard(ctx) + dc, err := dynamic.NewForConfig(r.cluster.RestConfig) if err != nil { return err @@ -232,7 +235,7 @@ func (r *renderer) editHelmResources(ctx context.Context, resources []releaseuti if err := runtime.DefaultUnstructuredConverter.FromUnstructured(rawData.UnstructuredContent(), namespace); err != nil { message.WarnErrf(err, "could not parse namespace %s", rawData.GetName()) } else { - message.Debugf("Matched helm namespace %s for zarf annotation", namespace.Name) + log.Debug("matched Helm namespace for Zarf annotation", "namespace", namespace.Name) namespace.Labels = cluster.AdoptZarfManagedLabels(namespace.Labels) // Add it to the stack r.namespaces[namespace.Name] = namespace @@ -252,7 +255,7 @@ func (r *renderer) editHelmResources(ctx context.Context, resources []releaseuti } if key, keyExists := labels[cluster.ZarfConnectLabelName]; keyExists { // If there is a zarf-connect label - message.Debugf("Match helm service %s for zarf connection %s", rawData.GetName(), key) + log.Debug("match Helm service for Zarf connection", "service", rawData.GetName(), "connection", key) // Add the connectString for processing later in the deployment r.connectStrings[key] = types.ConnectString{ diff --git a/src/internal/packager/helm/repo.go b/src/internal/packager/helm/repo.go index 24f3a7f4b0..13a35b3cd9 100644 --- a/src/internal/packager/helm/repo.go +++ b/src/internal/packager/helm/repo.go @@ -16,6 +16,7 @@ import ( "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/config/lang" "github.com/zarf-dev/zarf/src/internal/git" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/transform" "github.com/zarf-dev/zarf/src/pkg/utils" @@ -39,7 +40,7 @@ func (h *Helm) PackageChart(ctx context.Context, cosignKeyPath string) error { // check if the chart is a git url with a ref (if an error is returned url will be empty) isGitURL := strings.HasSuffix(url, ".git") if err != nil { - message.Debugf("unable to parse the url, continuing with %s", h.chart.URL) + logging.FromContextOrDiscard(ctx).Debug("continuing with original url as the url could not be parsed", "url", h.chart.URL, "error", err) } if isGitURL { @@ -147,7 +148,7 @@ func (h *Helm) DownloadPublishedChart(ctx context.Context, cosignKeyPath string) // Not returning the error here since the repo file is only needed if we are pulling from a repo that requires authentication if err != nil { - message.Debugf("Unable to load the repo file at %q: %s", pull.Settings.RepositoryConfig, err.Error()) + logging.FromContextOrDiscard(ctx).Debug("unable to load the repository file", "path", pull.Settings.RepositoryConfig, "error", err) } var username string diff --git a/src/internal/packager/images/pull.go b/src/internal/packager/images/pull.go index 7a313c5db0..84b310b286 100644 --- a/src/internal/packager/images/pull.go +++ b/src/internal/packager/images/pull.go @@ -220,7 +220,7 @@ func Pull(ctx context.Context, cfg PullConfig) (map[transform.Image]v1.Image, er doneSaving := make(chan error) updateText := fmt.Sprintf("Pulling %d images", imageCount) - go utils.RenderProgressBarForLocalDirWrite(cfg.DestinationDirectory, totalBytes.Load(), doneSaving, updateText, updateText) + go utils.RenderProgressBarForLocalDirWrite(ctx, cfg.DestinationDirectory, totalBytes.Load(), doneSaving, updateText, updateText) toPull := maps.Clone(fetched) diff --git a/src/internal/packager/images/push.go b/src/internal/packager/images/push.go index 0d0752f9fe..41bbe668f5 100644 --- a/src/internal/packager/images/push.go +++ b/src/internal/packager/images/push.go @@ -113,8 +113,6 @@ func Push(ctx context.Context, cfg PushConfig) error { return err } - message.Debugf("push %s -> %s)", refInfo.Reference, offlineName) - if err = pushImage(img, offlineName); err != nil { return err } diff --git a/src/internal/packager/sbom/catalog.go b/src/internal/packager/sbom/catalog.go index aadeeea257..a25f532731 100755 --- a/src/internal/packager/sbom/catalog.go +++ b/src/internal/packager/sbom/catalog.go @@ -5,6 +5,7 @@ package sbom import ( + "context" "embed" "fmt" "os" @@ -27,6 +28,7 @@ import ( v1 "github.com/google/go-containerregistry/pkg/v1" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/pkg/layout" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/transform" "github.com/zarf-dev/zarf/src/pkg/utils" @@ -48,7 +50,7 @@ var transformRegex = regexp.MustCompile(`(?m)[^a-zA-Z0-9\.\-]`) var componentPrefix = "zarf-component-" // Catalog catalogs the given components and images to create an SBOM. -func Catalog(componentSBOMs map[string]*layout.ComponentSBOM, imageList []transform.Image, paths *layout.PackagePaths) error { +func Catalog(ctx context.Context, componentSBOMs map[string]*layout.ComponentSBOM, imageList []transform.Image, paths *layout.PackagePaths) error { imageCount := len(imageList) componentCount := len(componentSBOMs) builder := Builder{ @@ -103,7 +105,7 @@ func Catalog(componentSBOMs map[string]*layout.ComponentSBOM, imageList []transf builder.spinner.Updatef("Creating component file SBOMs (%d of %d): %s", currComponent, componentCount, component) if componentSBOMs[component] == nil { - message.Debugf("Component %s has invalid SBOM, skipping", component) + logging.FromContextOrDiscard(ctx).Debug("component has invalid SBOM, skipping", "component", component) continue } diff --git a/src/pkg/cluster/cluster.go b/src/pkg/cluster/cluster.go index 801fd50173..70f6467ccf 100644 --- a/src/pkg/cluster/cluster.go +++ b/src/pkg/cluster/cluster.go @@ -18,6 +18,7 @@ import ( pkgkubernetes "github.com/defenseunicorns/pkg/kubernetes" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" ) @@ -80,6 +81,8 @@ func NewCluster() (*Cluster, error) { // WaitForHealthyCluster checks for an available K8s cluster every second until timeout. func waitForHealthyCluster(ctx context.Context, client kubernetes.Interface) error { + log := logging.FromContextOrDiscard(ctx) + const waitDuration = 1 * time.Second timer := time.NewTimer(0) @@ -93,7 +96,7 @@ func waitForHealthyCluster(ctx context.Context, client kubernetes.Interface) err // Make sure there is at least one running Node nodeList, err := client.CoreV1().Nodes().List(ctx, metav1.ListOptions{}) if err != nil || len(nodeList.Items) < 1 { - message.Debugf("No nodes reporting healthy yet: %v\n", err) + log.Debug("no nodes reporting healthy yet", "error", err) timer.Reset(waitDuration) continue } @@ -101,7 +104,7 @@ func waitForHealthyCluster(ctx context.Context, client kubernetes.Interface) err // Get the cluster pod list pods, err := client.CoreV1().Pods(corev1.NamespaceAll).List(ctx, metav1.ListOptions{}) if err != nil { - message.Debugf("Could not get the pod list: %v", err) + log.Debug("could not get the pod list", "error", err) timer.Reset(waitDuration) continue } @@ -113,7 +116,7 @@ func waitForHealthyCluster(ctx context.Context, client kubernetes.Interface) err } } - message.Debug("No pods reported 'succeeded' or 'running' state yet.") + log.Debug("No pods are in succeeded or running state yet") timer.Reset(waitDuration) } } diff --git a/src/pkg/cluster/data.go b/src/pkg/cluster/data.go index 8f1687123a..601de38523 100644 --- a/src/pkg/cluster/data.go +++ b/src/pkg/cluster/data.go @@ -24,7 +24,7 @@ import ( "github.com/zarf-dev/zarf/src/api/v1alpha1" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/pkg/layout" - "github.com/zarf-dev/zarf/src/pkg/message" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/utils" "github.com/zarf-dev/zarf/src/pkg/utils/exec" ) @@ -32,6 +32,8 @@ import ( // HandleDataInjection waits for the target pod(s) to come up and inject the data into them // todo: this currently requires kubectl but we should have enough k8s work to make this native now. func (c *Cluster) HandleDataInjection(ctx context.Context, data v1alpha1.ZarfDataInjection, componentPath *layout.ComponentPaths, dataIdx int) error { + log := logging.FromContextOrDiscard(ctx) + injectionCompletionMarker := filepath.Join(componentPath.DataInjections, config.GetDataInjectionMarker()) if err := os.WriteFile(injectionCompletionMarker, []byte("🦄"), helpers.ReadWriteUser); err != nil { return fmt.Errorf("unable to create the data injection completion marker: %w", err) @@ -64,7 +66,7 @@ func (c *Cluster) HandleDataInjection(ctx context.Context, data v1alpha1.ZarfDat case <-ctx.Done(): return ctx.Err() default: - message.Debugf("Attempting to inject data into %s", data.Target) + log.Debug("attempting to inject data into container", "target", data.Target) source := filepath.Join(componentPath.DataInjections, filepath.Base(data.Target.Path)) if helpers.InvalidPath(source) { // The path is likely invalid because of how we compose OCI components, add an index suffix to the filename @@ -95,7 +97,7 @@ func (c *Cluster) HandleDataInjection(ctx context.Context, data v1alpha1.ZarfDat zarfCommand, err := utils.GetFinalExecutableCommand() kubectlBinPath := "kubectl" if err != nil { - message.Warnf("Unable to get the zarf executable path, falling back to host kubectl: %s", err) + log.Debug("unable to get the Zarf executable path, falling back to host kubectl", "error", err) } else { kubectlBinPath = fmt.Sprintf("%s tools kubectl", zarfCommand) } @@ -178,6 +180,8 @@ type podFilter func(pod corev1.Pod) bool // If the timeout is reached, an empty list will be returned. // TODO: Test, refactor and/or remove. func waitForPodsAndContainers(ctx context.Context, clientset kubernetes.Interface, target podLookup, include podFilter) ([]corev1.Pod, error) { + log := logging.FromContextOrDiscard(ctx) + waitCtx, cancel := context.WithTimeout(ctx, 90*time.Second) defer cancel() @@ -197,7 +201,7 @@ func waitForPodsAndContainers(ctx context.Context, clientset kubernetes.Interfac return nil, err } - message.Debugf("Found %d pods for target %#v", len(podList.Items), target) + log.Debug("found pods for container", "count", len(podList.Items), "target", target) var readyPods = []corev1.Pod{} @@ -207,7 +211,7 @@ func waitForPodsAndContainers(ctx context.Context, clientset kubernetes.Interfac }) for _, pod := range podList.Items { - message.Debugf("Testing pod %q", pod.Name) + log.Debug("testing pod", "pod", pod.Name) // If an include function is provided, only keep pods that return true if include != nil && !include(pod) { @@ -216,7 +220,7 @@ func waitForPodsAndContainers(ctx context.Context, clientset kubernetes.Interfac // Handle container targeting if target.Container != "" { - message.Debugf("Testing pod %q for container %q", pod.Name, target.Container) + log.Debug("testing pod for container", "pod", pod.Name, "container", target.Container) // Check the status of initContainers for a running match for _, initContainer := range pod.Status.InitContainerStatuses { @@ -238,7 +242,7 @@ func waitForPodsAndContainers(ctx context.Context, clientset kubernetes.Interfac } } else { status := pod.Status.Phase - message.Debugf("Testing pod %q phase, want (%q) got (%q)", pod.Name, corev1.PodRunning, status) + log.Debug("testing pod phase", "pod", pod.Name, "wanted", corev1.PodRunning, "got", status) // Regular status checking without a container if status == corev1.PodRunning { readyPods = append(readyPods, pod) diff --git a/src/pkg/cluster/secrets.go b/src/pkg/cluster/secrets.go index 43c3402b64..623199af57 100644 --- a/src/pkg/cluster/secrets.go +++ b/src/pkg/cluster/secrets.go @@ -16,6 +16,7 @@ import ( metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" "github.com/zarf-dev/zarf/src/config" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/types" ) @@ -196,7 +197,7 @@ func (c *Cluster) GetServiceInfoFromRegistryAddress(ctx context.Context, stateRe // If this is an internal service then we need to look it up and svc, port, err := serviceInfoFromNodePortURL(serviceList.Items, stateRegistryAddress) if err != nil { - message.Debugf("registry appears to not be a nodeport service, using original address %q", stateRegistryAddress) + logging.FromContextOrDiscard(ctx).Debug("registry appears to not be a node port service, using original address", "address", stateRegistryAddress) return stateRegistryAddress, nil } diff --git a/src/pkg/cluster/state.go b/src/pkg/cluster/state.go index 7ce8a3fa6d..5f95442cea 100644 --- a/src/pkg/cluster/state.go +++ b/src/pkg/cluster/state.go @@ -19,6 +19,7 @@ import ( "github.com/defenseunicorns/pkg/helpers/v2" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/config/lang" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/pki" "github.com/zarf-dev/zarf/src/types" @@ -141,7 +142,7 @@ func (c *Cluster) InitZarfState(ctx context.Context, initOptions types.ZarfInitO return err } if kerrors.IsNotFound(err) { - message.Debug("Service account %s/%s not found, retrying...", ns, name) + logging.FromContextOrDiscard(ctx).Debug("Service account not found, retrying", "namespace", ns, "name", name) timer.Reset(1 * time.Second) continue } @@ -216,7 +217,7 @@ func (c *Cluster) LoadZarfState(ctx context.Context) (state *types.ZarfState, er if err != nil { return nil, fmt.Errorf("%w: %w", stateErr, err) } - c.debugPrintZarfState(state) + c.debugPrintZarfState(ctx, state) return state, nil } @@ -241,7 +242,7 @@ func (c *Cluster) sanitizeZarfState(state *types.ZarfState) *types.ZarfState { return state } -func (c *Cluster) debugPrintZarfState(state *types.ZarfState) { +func (c *Cluster) debugPrintZarfState(ctx context.Context, state *types.ZarfState) { if state == nil { return } @@ -252,12 +253,12 @@ func (c *Cluster) debugPrintZarfState(state *types.ZarfState) { if err != nil { return } - message.Debugf("ZarfState - %s", string(b)) + logging.FromContextOrDiscard(ctx).Debug("ZarfState", "state", string(b)) } // SaveZarfState takes a given state and persists it to the Zarf/zarf-state secret. func (c *Cluster) SaveZarfState(ctx context.Context, state *types.ZarfState) error { - c.debugPrintZarfState(state) + c.debugPrintZarfState(ctx, state) data, err := json.Marshal(&state) if err != nil { diff --git a/src/pkg/cluster/tunnel.go b/src/pkg/cluster/tunnel.go index 61fd090546..a778ac963b 100644 --- a/src/pkg/cluster/tunnel.go +++ b/src/pkg/cluster/tunnel.go @@ -23,7 +23,7 @@ import ( "k8s.io/client-go/transport/spdy" "github.com/defenseunicorns/pkg/helpers/v2" - "github.com/zarf-dev/zarf/src/pkg/message" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/types" ) @@ -218,8 +218,6 @@ func (c *Cluster) checkForZarfConnectLabel(ctx context.Context, name string) (Tu // Add the url suffix too. zt.urlSuffix = svc.Annotations[ZarfConnectAnnotationURL] - - message.Debugf("tunnel connection match: %s/%s on port %d", svc.Namespace, svc.Name, zt.RemotePort) } else { return zt, fmt.Errorf("no matching services found for %s", name) } @@ -365,8 +363,7 @@ func (tunnel *Tunnel) Connect(ctx context.Context) (string, error) { // Otherwise, retry the connection but delay increasing intervals between attempts. delay := tunnel.attempt * 10 - message.Debugf("%s", err.Error()) - message.Debugf("Delay creating tunnel, waiting %d seconds...", delay) + logging.FromContextOrDiscard(ctx).Debug("failed to create tunnel, retrying after delay", "delay", delay, "error", err) timer := time.NewTimer(0) defer timer.Stop() @@ -414,6 +411,8 @@ func (tunnel *Tunnel) Close() { // establish opens a tunnel to a kubernetes resource, as specified by the provided tunnel struct. func (tunnel *Tunnel) establish(ctx context.Context) (string, error) { + log := logging.FromContextOrDiscard(ctx) + var err error // Track this locally as we may need to retry if the tunnel fails. @@ -426,12 +425,12 @@ func (tunnel *Tunnel) establish(ctx context.Context) (string, error) { // since there is a brief moment between `GetAvailablePort` and `forwarder.ForwardPorts` where the selected port // is available for selection again. if localPort == 0 { - message.Debugf("Requested local port is 0. Selecting an open port on host system") + log.Debug("requested local port is 0, selection an open port on host system") localPort, err = helpers.GetAvailablePort() if err != nil { return "", fmt.Errorf("unable to find an available port: %w", err) } - message.Debugf("Selected port %d", localPort) + log.Debug("selected port", "port", localPort) globalMutex.Lock() defer globalMutex.Unlock() } @@ -443,14 +442,14 @@ func (tunnel *Tunnel) establish(ctx context.Context) (string, error) { tunnel.resourceName, tunnel.namespace, ) - message.Debugf(msg) + log.Debug(msg) // Find the pod to port forward to podName, err := tunnel.getAttachablePodForResource(ctx) if err != nil { return "", fmt.Errorf("unable to find pod attached to given resource: %w", err) } - message.Debugf("Selected pod %s to open port forward to", podName) + log.Debug("selected pod to open port forward to", "pod", podName) // Build url to the port forward endpoint. // Example: http://localhost:8080/api/v1/namespaces/helm/pods/tiller-deploy-9itlq/portforward. @@ -463,7 +462,7 @@ func (tunnel *Tunnel) establish(ctx context.Context) (string, error) { SubResource("portforward"). URL() - message.Debugf("Using URL %s to create portforward", portForwardCreateURL) + log.Debug("using URL to create port forward", "url", portForwardCreateURL) // Construct the spdy client required by the client-go portforward library. transport, upgrader, err := spdy.RoundTripperFor(tunnel.restConfig) @@ -498,7 +497,7 @@ func (tunnel *Tunnel) establish(ctx context.Context) (string, error) { // Store the error channel to listen for errors tunnel.errChan = errChan - message.Debugf("Creating port forwarding tunnel at %s", url) + log.Debug("creation for forwarding tunnel", "url", url) return url, nil } } diff --git a/src/pkg/cluster/zarf.go b/src/pkg/cluster/zarf.go index 6172e3fa78..8bdaabe2bb 100644 --- a/src/pkg/cluster/zarf.go +++ b/src/pkg/cluster/zarf.go @@ -19,6 +19,7 @@ import ( "github.com/zarf-dev/zarf/src/api/v1alpha1" "github.com/zarf-dev/zarf/src/config" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/types" ) @@ -187,7 +188,7 @@ func (c *Cluster) RecordPackageDeployment(ctx context.Context, pkg v1alpha1.Zarf var componentWebhooks map[string]map[string]types.Webhook existingPackageSecret, err := c.GetDeployedPackage(ctx, packageName) if err != nil { - message.Debugf("Unable to fetch existing secret for package '%s': %s", packageName, err.Error()) + logging.FromContextOrDiscard(ctx).Debug("unable to fetch existing secret for package", "package", packageName, "error", err) } if existingPackageSecret != nil { componentWebhooks = existingPackageSecret.ComponentWebhooks diff --git a/src/pkg/layout/component.go b/src/pkg/layout/component.go index fee2d90082..39c9b8ed93 100644 --- a/src/pkg/layout/component.go +++ b/src/pkg/layout/component.go @@ -12,8 +12,8 @@ import ( "github.com/defenseunicorns/pkg/helpers/v2" "github.com/mholt/archiver/v3" + "github.com/zarf-dev/zarf/src/api/v1alpha1" - "github.com/zarf-dev/zarf/src/pkg/message" ) // ComponentPaths contains paths for a component. @@ -58,7 +58,6 @@ func (c *Components) Archive(component v1alpha1.ZarfComponent, cleanupTemp bool) } if size > 0 { tb := fmt.Sprintf("%s.tar", base) - message.Debugf("Archiving %q", name) if err := helpers.CreateReproducibleTarballFromDir(base, name, tb); err != nil { return err } @@ -66,8 +65,6 @@ func (c *Components) Archive(component v1alpha1.ZarfComponent, cleanupTemp bool) c.Tarballs = make(map[string]string) } c.Tarballs[name] = tb - } else { - message.Debugf("Component %q is empty, skipping archiving", name) } delete(c.Dirs, name) @@ -126,11 +123,9 @@ func (c *Components) Unarchive(component v1alpha1.ZarfComponent) (err error) { // if the component is already unarchived, skip if !helpers.InvalidPath(cs.Base) { - message.Debugf("Component %q already unarchived", name) return nil } - message.Debugf("Unarchiving %q", filepath.Base(tb)) if err := archiver.Unarchive(tb, c.Base); err != nil { return err } diff --git a/src/pkg/layout/package.go b/src/pkg/layout/package.go index a38ec599a1..5437836c0d 100644 --- a/src/pkg/layout/package.go +++ b/src/pkg/layout/package.go @@ -99,7 +99,6 @@ func (pp *PackagePaths) MigrateLegacy() (err error) { legacySBOMs := filepath.Join(base, "sboms") if !helpers.InvalidPath(legacySBOMs) { pp = pp.AddSBOMs() - message.Debugf("Migrating %q to %q", legacySBOMs, pp.SBOMs.Path) if err := os.Rename(legacySBOMs, pp.SBOMs.Path); err != nil { return err } @@ -109,7 +108,6 @@ func (pp *PackagePaths) MigrateLegacy() (err error) { legacyImagesTar := filepath.Join(base, "images.tar") if !helpers.InvalidPath(legacyImagesTar) { pp = pp.AddImages() - message.Debugf("Migrating %q to %q", legacyImagesTar, pp.Images.Base) defer os.Remove(legacyImagesTar) imgTags := []string{} for _, component := range pkg.Components { @@ -309,8 +307,6 @@ func (pp *PackagePaths) SetFromPaths(paths []string) { pp.Components.Tarballs = make(map[string]string) } pp.Components.Tarballs[componentName] = filepath.Join(pp.Base, path) - default: - message.Debug("ignoring path", path) } } } diff --git a/src/pkg/logging/handler.go b/src/pkg/logging/handler.go new file mode 100644 index 0000000000..3b524a6772 --- /dev/null +++ b/src/pkg/logging/handler.go @@ -0,0 +1,66 @@ +// SPDX-License-Identifier: Apache-2.0 +// SPDX-FileCopyrightText: 2021-Present The Zarf Authors + +package logging + +import ( + "context" + "fmt" + "log/slog" + "strings" + + "github.com/zarf-dev/zarf/src/pkg/message" +) + +// PtermHandler is a slog handler that prints using Pterm. +type PtermHandler struct { + attrs []slog.Attr + group string +} + +// NewPtermHandler returns a new instance of PtermHandler. +func NewPtermHandler() *PtermHandler { + return &PtermHandler{} +} + +//nolint:revive // ignore +func (h *PtermHandler) Enabled(context.Context, slog.Level) bool { + return true +} + +//nolint:revive // ignore +func (h *PtermHandler) Handle(ctx context.Context, r slog.Record) error { + attrs := []string{} + r.Attrs(func(a slog.Attr) bool { + attrs = append(attrs, a.String()) + return true + }) + out := fmt.Sprintf("%s %s", r.Message, strings.Join(attrs, " ")) + switch r.Level { + case slog.LevelDebug: + message.Debug(out) + case slog.LevelInfo: + message.Info(out) + case slog.LevelWarn: + message.Warn(out) + case slog.LevelError: + message.Warn(out) + } + return nil +} + +//nolint:revive // ignore +func (h *PtermHandler) WithAttrs(attrs []slog.Attr) slog.Handler { + return &PtermHandler{ + attrs: append(h.attrs, attrs...), + group: h.group, + } +} + +//nolint:revive // ignore +func (h *PtermHandler) WithGroup(name string) slog.Handler { + return &PtermHandler{ + attrs: h.attrs, + group: name, + } +} diff --git a/src/pkg/logging/logging.go b/src/pkg/logging/logging.go new file mode 100644 index 0000000000..b9be19b8a8 --- /dev/null +++ b/src/pkg/logging/logging.go @@ -0,0 +1,32 @@ +// SPDX-License-Identifier: Apache-2.0 +// SPDX-FileCopyrightText: 2021-Present The Zarf Authors + +// Package logging contains logging related functionality. +package logging + +import ( + "context" + "io" + "log/slog" +) + +type contextKey struct{} + +// NewContext returns a child context containing the given logger. +func NewContext(ctx context.Context, log *slog.Logger) context.Context { + return context.WithValue(ctx, contextKey{}, log) +} + +// FromContextOrDiscard returns the logger stored in the context. +func FromContextOrDiscard(ctx context.Context) *slog.Logger { + v := ctx.Value(contextKey{}) + if v == nil { + return slog.New(slog.NewJSONHandler(io.Discard, nil)) + } + log, ok := v.(*slog.Logger) + if !ok { + // This should never happen. + panic("unexpected logger type") + } + return log +} diff --git a/src/pkg/packager/actions/actions.go b/src/pkg/packager/actions/actions.go index 4fdf71fdd5..d4aa418414 100644 --- a/src/pkg/packager/actions/actions.go +++ b/src/pkg/packager/actions/actions.go @@ -15,6 +15,7 @@ import ( "github.com/defenseunicorns/pkg/helpers/v2" "github.com/zarf-dev/zarf/src/api/v1alpha1" "github.com/zarf-dev/zarf/src/internal/packager/template" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/utils" "github.com/zarf-dev/zarf/src/pkg/utils/exec" @@ -204,7 +205,7 @@ func convertWaitToCmd(_ context.Context, wait v1alpha1.ZarfComponentActionWait, } // Perform some basic string mutations to make commands more useful. -func actionCmdMutation(_ context.Context, cmd string, shellPref exec.Shell) (string, error) { +func actionCmdMutation(ctx context.Context, cmd string, shellPref exec.Shell) (string, error) { zarfCommand, err := utils.GetFinalExecutableCommand() if err != nil { return cmd, err @@ -226,7 +227,7 @@ func actionCmdMutation(_ context.Context, cmd string, shellPref exec.Shell) (str get, err := helpers.MatchRegex(envVarRegex, cmd) if err == nil { newCmd := strings.ReplaceAll(cmd, get("envIndicator"), fmt.Sprintf("$Env:%s", get("varName"))) - message.Debugf("Converted command \"%s\" to \"%s\" t", cmd, newCmd) + logging.FromContextOrDiscard(ctx).Debug("converted command", "old", cmd, "new", newCmd) cmd = newCmd } } @@ -277,7 +278,7 @@ func actionGetCfg(_ context.Context, cfg v1alpha1.ZarfComponentActionDefaults, a func actionRun(ctx context.Context, cfg v1alpha1.ZarfComponentActionDefaults, cmd string, shellPref exec.Shell, spinner *message.Spinner) (string, error) { shell, shellArgs := exec.GetOSShell(shellPref) - message.Debugf("Running command in %s: %s", shell, cmd) + logging.FromContextOrDiscard(ctx).Debug("running command", "shell", shell, "command", cmd) execCfg := exec.Config{ Env: cfg.Env, @@ -292,7 +293,7 @@ func actionRun(ctx context.Context, cfg v1alpha1.ZarfComponentActionDefaults, cm out, errOut, err := exec.CmdWithContext(ctx, execCfg, shell, append(shellArgs, cmd)...) // Dump final complete output (respect mute to prevent sensitive values from hitting the logs). if !cfg.Mute { - message.Debug(cmd, out, errOut) + logging.FromContextOrDiscard(ctx).Debug(cmd, "stdout", out, "stderr", errOut) } return out, err diff --git a/src/pkg/packager/common.go b/src/pkg/packager/common.go index 6a3ec004e7..a04922d602 100644 --- a/src/pkg/packager/common.go +++ b/src/pkg/packager/common.go @@ -20,6 +20,7 @@ import ( "github.com/zarf-dev/zarf/src/internal/packager/template" "github.com/zarf-dev/zarf/src/pkg/cluster" "github.com/zarf-dev/zarf/src/pkg/layout" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/packager/deprecated" "github.com/zarf-dev/zarf/src/pkg/packager/sources" @@ -71,7 +72,7 @@ New creates a new package instance with the provided config. Note: This function creates a tmp directory that should be cleaned up with p.ClearTempPaths(). */ -func New(cfg *types.PackagerConfig, mods ...Modifier) (*Packager, error) { +func New(ctx context.Context, cfg *types.PackagerConfig, mods ...Modifier) (*Packager, error) { if cfg == nil { return nil, fmt.Errorf("no config provided") } @@ -110,7 +111,7 @@ func New(cfg *types.PackagerConfig, mods ...Modifier) (*Packager, error) { if err != nil { return nil, fmt.Errorf("unable to create package temp paths: %w", err) } - message.Debug("Using temporary directory:", dir) + logging.FromContextOrDiscard(ctx).Debug("Using temporary directory", "directory", dir) pkgr.layout = layout.New(dir) } diff --git a/src/pkg/packager/composer/oci.go b/src/pkg/packager/composer/oci.go index 2541e45f32..05299ca03e 100644 --- a/src/pkg/packager/composer/oci.go +++ b/src/pkg/packager/composer/oci.go @@ -17,7 +17,7 @@ import ( ocispec "github.com/opencontainers/image-spec/specs-go/v1" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/pkg/layout" - "github.com/zarf-dev/zarf/src/pkg/message" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/utils" "github.com/zarf-dev/zarf/src/pkg/zoci" ocistore "oras.land/oras-go/v2/content/oci" @@ -80,7 +80,7 @@ func (ic *ImportChain) fetchOCISkeleton(ctx context.Context) error { dir = filepath.Join(cache, "dirs", id) - message.Debug("creating empty directory for remote component:", filepath.Join("", "oci", "dirs", id)) + logging.FromContextOrDiscard(ctx).Debug("Creaing empty directory for remote component", "path", filepath.Join("", "oci", "dirs", id)) } else { tb = filepath.Join(cache, "blobs", "sha256", componentDesc.Digest.Encoded()) dir = filepath.Join(cache, "dirs", componentDesc.Digest.Encoded()) @@ -97,7 +97,7 @@ func (ic *ImportChain) fetchOCISkeleton(ctx context.Context) error { } else if !exists { doneSaving := make(chan error) successText := fmt.Sprintf("Pulling %q", helpers.OCIURLPrefix+remote.Repo().Reference.String()) - go utils.RenderProgressBarForLocalDirWrite(cache, componentDesc.Size, doneSaving, "Pulling", successText) + go utils.RenderProgressBarForLocalDirWrite(ctx, cache, componentDesc.Size, doneSaving, "Pulling", successText) err = remote.CopyToTarget(ctx, []ocispec.Descriptor{componentDesc}, store, remote.GetDefaultCopyOpts()) doneSaving <- err <-doneSaving diff --git a/src/pkg/packager/creator/normal.go b/src/pkg/packager/creator/normal.go index 79c58250c0..b752f3c845 100644 --- a/src/pkg/packager/creator/normal.go +++ b/src/pkg/packager/creator/normal.go @@ -28,6 +28,7 @@ import ( "github.com/zarf-dev/zarf/src/internal/packager/kustomize" "github.com/zarf-dev/zarf/src/internal/packager/sbom" "github.com/zarf-dev/zarf/src/pkg/layout" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/packager/actions" "github.com/zarf-dev/zarf/src/pkg/packager/filters" @@ -138,7 +139,7 @@ func (pc *PackageCreator) Assemble(ctx context.Context, dst *layout.PackagePaths onFailure := func() { if err := actions.Run(ctx, onCreate.Defaults, onCreate.OnFailure, nil); err != nil { - message.Debugf("unable to run component failure action: %s", err.Error()) + logging.FromContextOrDiscard(ctx).Debug("unable to run component failure action", "error", err) } } @@ -213,10 +214,10 @@ func (pc *PackageCreator) Assemble(ctx context.Context, dst *layout.PackagePaths // Ignore SBOM creation if the flag is set. if skipSBOMFlagUsed { - message.Debug("Skipping image SBOM processing per --skip-sbom flag") + logging.FromContextOrDiscard(ctx).Debug("Skipping image SBOm processing per --skip-sbom flag") } else { dst.AddSBOMs() - if err := sbom.Catalog(componentSBOMs, sbomImageList, dst); err != nil { + if err := sbom.Catalog(ctx, componentSBOMs, sbomImageList, dst); err != nil { return fmt.Errorf("unable to create an SBOM catalog for the package: %w", err) } } diff --git a/src/pkg/packager/deploy.go b/src/pkg/packager/deploy.go index 86c2f43349..d5a76ec95a 100644 --- a/src/pkg/packager/deploy.go +++ b/src/pkg/packager/deploy.go @@ -33,6 +33,7 @@ import ( "github.com/zarf-dev/zarf/src/internal/packager/template" "github.com/zarf-dev/zarf/src/pkg/cluster" "github.com/zarf-dev/zarf/src/pkg/layout" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/packager/actions" "github.com/zarf-dev/zarf/src/pkg/packager/filters" @@ -48,7 +49,7 @@ var ( func (p *Packager) resetRegistryHPA(ctx context.Context) { if p.isConnectedToCluster() && p.hpaModified { if err := p.cluster.EnableRegHPAScaleDown(ctx); err != nil { - message.Debugf("unable to reenable the registry HPA scale down: %s", err.Error()) + logging.FromContextOrDiscard(ctx).Error("Unable to reenable the registry HPA scale down", "error", err) } } } @@ -139,6 +140,8 @@ func (p *Packager) Deploy(ctx context.Context) error { // deployComponents loops through a list of ZarfComponents and deploys them. func (p *Packager) deployComponents(ctx context.Context) (deployedComponents []types.DeployedComponent, err error) { + log := logging.FromContextOrDiscard(ctx) + // Process all the components we are deploying for _, component := range p.cfg.Pkg.Components { // Connect to cluster if a component requires it. @@ -170,7 +173,7 @@ func (p *Packager) deployComponents(ctx context.Context) (deployedComponents []t if p.isConnectedToCluster() { deployedComponent.InstalledCharts, err = p.cluster.GetInstalledChartsForComponent(ctx, p.cfg.Pkg.Metadata.Name, component) if err != nil { - message.Debugf("Unable to fetch installed Helm charts for component '%s': %s", component.Name, err.Error()) + log.Debug("unable to fetch installed Helm charts for the component", "component", component.Name, "error", err) } } @@ -180,7 +183,7 @@ func (p *Packager) deployComponents(ctx context.Context) (deployedComponents []t // Update the package secret to indicate that we are attempting to deploy this component if p.isConnectedToCluster() { if _, err := p.cluster.RecordPackageDeploymentAndWait(ctx, p.cfg.Pkg, deployedComponents, p.connectStrings, packageGeneration, component, p.cfg.DeployOpts.SkipWebhooks); err != nil { - message.Debugf("Unable to record package deployment for component %s: this will affect features like `zarf package remove`: %s", component.Name, err.Error()) + log.Debug("unable to record package deployment for component", "component", component.Name, "error", err) } } @@ -197,7 +200,7 @@ func (p *Packager) deployComponents(ctx context.Context) (deployedComponents []t onFailure := func() { if err := actions.Run(ctx, onDeploy.Defaults, onDeploy.OnFailure, p.variableConfig); err != nil { - message.Debugf("unable to run component failure action: %s", err.Error()) + log.Debug("unable to run component failure action", "error", err) } } @@ -208,7 +211,7 @@ func (p *Packager) deployComponents(ctx context.Context) (deployedComponents []t deployedComponents[idx].Status = types.ComponentStatusFailed if p.isConnectedToCluster() { if _, err := p.cluster.RecordPackageDeploymentAndWait(ctx, p.cfg.Pkg, deployedComponents, p.connectStrings, packageGeneration, component, p.cfg.DeployOpts.SkipWebhooks); err != nil { - message.Debugf("Unable to record package deployment for component %q: this will affect features like `zarf package remove`: %s", component.Name, err.Error()) + log.Debug("unable to record package deployment for component", "component", component.Name, "error", err) } } @@ -220,7 +223,7 @@ func (p *Packager) deployComponents(ctx context.Context) (deployedComponents []t deployedComponents[idx].Status = types.ComponentStatusSucceeded if p.isConnectedToCluster() { if _, err := p.cluster.RecordPackageDeploymentAndWait(ctx, p.cfg.Pkg, deployedComponents, p.connectStrings, packageGeneration, component, p.cfg.DeployOpts.SkipWebhooks); err != nil { - message.Debugf("Unable to record package deployment for component %q: this will affect features like `zarf package remove`: %s", component.Name, err.Error()) + log.Debug("unable to record package deployment for component", "component", component.Name, "error", err) } } @@ -288,6 +291,8 @@ func (p *Packager) deployInitComponent(ctx context.Context, component v1alpha1.Z // Deploy a Zarf Component. func (p *Packager) deployComponent(ctx context.Context, component v1alpha1.ZarfComponent, noImgChecksum bool, noImgPush bool) (charts []types.InstalledChart, err error) { + log := logging.FromContextOrDiscard(ctx) + // Toggles for general deploy operations componentPath := p.layout.Components.Dirs[component.Name] @@ -314,7 +319,7 @@ func (p *Packager) deployComponent(ctx context.Context, component v1alpha1.ZarfC // Disable the registry HPA scale down if we are deploying images and it is not already disabled if hasImages && !p.hpaModified && p.state.RegistryInfo.IsInternal() { if err := p.cluster.DisableRegHPAScaleDown(ctx); err != nil { - message.Debugf("unable to disable the registry HPA scale down: %s", err.Error()) + log.Error("Unable to disable the registry HPA scale down", "error", err.Error()) } else { p.hpaModified = true } diff --git a/src/pkg/packager/deploy_test.go b/src/pkg/packager/deploy_test.go index d0802a4ac5..2ffd063f9c 100644 --- a/src/pkg/packager/deploy_test.go +++ b/src/pkg/packager/deploy_test.go @@ -10,6 +10,7 @@ import ( "github.com/zarf-dev/zarf/src/api/v1alpha1" "github.com/zarf-dev/zarf/src/pkg/packager/sources" "github.com/zarf-dev/zarf/src/pkg/variables" + "github.com/zarf-dev/zarf/src/test/testutil" "github.com/zarf-dev/zarf/src/types" ) @@ -213,7 +214,7 @@ func TestGenerateValuesOverrides(t *testing.T) { for _, tt := range tests { tt := tt t.Run(tt.name, func(t *testing.T) { - p, err := New(&types.PackagerConfig{DeployOpts: tt.deployOpts}, WithSource(&sources.TarballSource{})) + p, err := New(testutil.TestContext(t), &types.PackagerConfig{DeployOpts: tt.deployOpts}, WithSource(&sources.TarballSource{})) require.NoError(t, err) for k, v := range tt.setVariables { p.variableConfig.SetVariable(k, v, false, false, variables.RawVariableType) diff --git a/src/pkg/packager/prepare.go b/src/pkg/packager/prepare.go index d007e862bd..70916b3d7a 100644 --- a/src/pkg/packager/prepare.go +++ b/src/pkg/packager/prepare.go @@ -23,6 +23,7 @@ import ( "github.com/zarf-dev/zarf/src/internal/packager/images" "github.com/zarf-dev/zarf/src/internal/packager/kustomize" "github.com/zarf-dev/zarf/src/pkg/layout" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/packager/creator" "github.com/zarf-dev/zarf/src/pkg/utils" @@ -75,6 +76,8 @@ func (p *Packager) FindImages(ctx context.Context) (map[string][]string, error) } func (p *Packager) findImages(ctx context.Context) (imgMap map[string][]string, err error) { + log := logging.FromContextOrDiscard(ctx) + repoHelmChartPath := p.cfg.FindImagesOpts.RepoHelmChartPath kubeVersionOverride := p.cfg.FindImagesOpts.KubeVersionOverride whyImage := p.cfg.FindImagesOpts.Why @@ -275,7 +278,7 @@ func (p *Packager) findImages(ctx context.Context) (imgMap map[string][]string, defer spinner.Stop() for _, resource := range resources { - if matchedImages, maybeImages, err = p.processUnstructuredImages(resource, matchedImages, maybeImages); err != nil { + if matchedImages, maybeImages, err = p.processUnstructuredImages(ctx, resource, matchedImages, maybeImages); err != nil { message.WarnErrf(err, "Problem processing K8s resource %s", resource.GetName()) } } @@ -296,10 +299,10 @@ func (p *Packager) findImages(ctx context.Context) (imgMap map[string][]string, for _, image := range sortedImages { if descriptor, err := crane.Head(image, images.WithGlobalInsecureFlag()...); err != nil { // Test if this is a real image, if not just quiet log to debug, this is normal - message.Debugf("Suspected image does not appear to be valid: %#v", err) + log.Error("Suspected image does not appear to be valid", "error", err) } else { // Otherwise, add to the list of images - message.Debugf("Imaged digest found: %s", descriptor.Digest) + log.Debug("Image digest found", "digest", descriptor.Digest) validImages = append(validImages, image) } } @@ -371,7 +374,9 @@ func (p *Packager) findImages(ctx context.Context) (imgMap map[string][]string, return imagesMap, nil } -func (p *Packager) processUnstructuredImages(resource *unstructured.Unstructured, matchedImages, maybeImages imageMap) (imageMap, imageMap, error) { +func (p *Packager) processUnstructuredImages(ctx context.Context, resource *unstructured.Unstructured, matchedImages, maybeImages imageMap) (imageMap, imageMap, error) { + log := logging.FromContextOrDiscard(ctx) + var imageSanityCheck = regexp.MustCompile(`(?mi)"image":"([^"]+)"`) var imageFuzzyCheck = regexp.MustCompile(`(?mi)["|=]([a-z0-9\-.\/:]+:[\w.\-]*[a-z\.\-][\w.\-]*)"`) var json string @@ -420,7 +425,7 @@ func (p *Packager) processUnstructuredImages(resource *unstructured.Unstructured // Capture any custom images matches := imageSanityCheck.FindAllStringSubmatch(json, -1) for _, group := range matches { - message.Debugf("Found unknown match, Kind: %s, Value: %s", resource.GetKind(), group[1]) + log.Debug("Found unknown match", "kind", resource.GetKind(), "value", group[1]) matchedImages[group[1]] = true } } @@ -428,7 +433,7 @@ func (p *Packager) processUnstructuredImages(resource *unstructured.Unstructured // Capture "maybe images" too for all kinds because they might be in unexpected places.... 👀 matches := imageFuzzyCheck.FindAllStringSubmatch(json, -1) for _, group := range matches { - message.Debugf("Found possible fuzzy match, Kind: %s, Value: %s", resource.GetKind(), group[1]) + log.Debug("FOund possible fuzzy match", "kind", resource.GetKind(), "group", group[1]) maybeImages[group[1]] = true } diff --git a/src/pkg/packager/remove.go b/src/pkg/packager/remove.go index 4edcdd5b05..54fd983ae6 100644 --- a/src/pkg/packager/remove.go +++ b/src/pkg/packager/remove.go @@ -22,6 +22,7 @@ import ( "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/internal/packager/helm" "github.com/zarf-dev/zarf/src/pkg/cluster" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/zarf-dev/zarf/src/pkg/packager/actions" "github.com/zarf-dev/zarf/src/pkg/packager/filters" @@ -171,7 +172,7 @@ func (p *Packager) removeComponent(ctx context.Context, deployedPackage *types.D onRemove := c.Actions.OnRemove onFailure := func() { if err := actions.Run(ctx, onRemove.Defaults, onRemove.OnFailure, nil); err != nil { - message.Debugf("Unable to run the failure action: %s", err) + logging.FromContextOrDiscard(ctx).Error("unable to run the failure action", "error", err) } } diff --git a/src/pkg/packager/sources/validate.go b/src/pkg/packager/sources/validate.go index 1c7914ea69..d6a2e4ba39 100644 --- a/src/pkg/packager/sources/validate.go +++ b/src/pkg/packager/sources/validate.go @@ -17,7 +17,7 @@ import ( "github.com/defenseunicorns/pkg/helpers/v2" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/pkg/layout" - "github.com/zarf-dev/zarf/src/pkg/message" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/utils" ) @@ -36,7 +36,7 @@ func ValidatePackageSignature(ctx context.Context, paths *layout.PackagePaths, p } if publicKeyPath != "" { - message.Debugf("Using public key %q for signature validation", publicKeyPath) + logging.FromContextOrDiscard(ctx).Debug("using public key for signature validation", "path", publicKeyPath) } // Handle situations where there is no signature within the package diff --git a/src/pkg/utils/bytes.go b/src/pkg/utils/bytes.go index 7dd159b91f..2fc7930d47 100644 --- a/src/pkg/utils/bytes.go +++ b/src/pkg/utils/bytes.go @@ -7,12 +7,14 @@ package utils import ( + "context" "fmt" "math" "strconv" "time" "github.com/defenseunicorns/pkg/helpers/v2" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" ) @@ -59,7 +61,9 @@ func ByteFormat(inputNum float64, precision int) string { // RenderProgressBarForLocalDirWrite creates a progress bar that continuously tracks the progress of writing files to a local directory and all of its subdirectories. // NOTE: This function runs infinitely until either completeChan or errChan is triggered, this function should be run in a goroutine while a different thread/process is writing to the directory. -func RenderProgressBarForLocalDirWrite(filepath string, expectedTotal int64, completeChan chan error, updateText string, successText string) { +func RenderProgressBarForLocalDirWrite(ctx context.Context, filepath string, expectedTotal int64, completeChan chan error, updateText string, successText string) { + log := logging.FromContextOrDiscard(ctx) + // Create a progress bar title := fmt.Sprintf("%s (%s of %s)", updateText, ByteFormat(float64(0), 2), ByteFormat(float64(expectedTotal), 2)) progressBar := message.NewProgressBar(expectedTotal, title) @@ -74,7 +78,7 @@ func RenderProgressBarForLocalDirWrite(filepath string, expectedTotal int64, com return } else { if err := progressBar.Close(); err != nil { - message.Debugf("unable to close progress bar: %s", err.Error()) + log.Error("Unable to close progress bar", "error", err) } completeChan <- nil return @@ -83,7 +87,7 @@ func RenderProgressBarForLocalDirWrite(filepath string, expectedTotal int64, com // Read the directory size currentBytes, dirErr := helpers.GetDirSize(filepath) if dirErr != nil { - message.Debugf("unable to get updated progress: %s", dirErr.Error()) + log.Error("Unable to get updated progress", "error", dirErr) time.Sleep(200 * time.Millisecond) continue } diff --git a/src/pkg/utils/cosign.go b/src/pkg/utils/cosign.go index eb16d6159f..043c7ed12b 100644 --- a/src/pkg/utils/cosign.go +++ b/src/pkg/utils/cosign.go @@ -18,6 +18,7 @@ import ( "github.com/pkg/errors" "github.com/zarf-dev/zarf/src/config" "github.com/zarf-dev/zarf/src/config/lang" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/message" "github.com/sigstore/cosign/v2/cmd/cosign/cli/fulcio" @@ -39,6 +40,8 @@ import ( // // Forked from https://github.com/sigstore/cosign/blob/v1.7.1/pkg/sget/sget.go func Sget(ctx context.Context, image, key string, out io.Writer) error { + log := logging.FromContextOrDiscard(ctx) + message.Warnf(lang.WarnSGetDeprecation) // If this is a DefenseUnicorns package, use an internal sget public key @@ -139,11 +142,11 @@ func Sget(ctx context.Context, image, key string, out io.Writer) error { for _, sig := range sp { if cert, err := sig.Cert(); err == nil && cert != nil { - message.Debugf("Certificate subject: %s", cert.Subject) + log.Info("Certificate subject", "subject", cert.Subject) ce := cosign.CertExtensions{Cert: cert} if issuerURL := ce.GetIssuer(); issuerURL != "" { - message.Debugf("Certificate issuer URL: %s", issuerURL) + log.Debug("Certificate issues", "url", issuerURL) } } @@ -152,7 +155,7 @@ func Sget(ctx context.Context, image, key string, out io.Writer) error { spinner.Errorf(err, "Error getting payload") return err } - message.Debug(string(p)) + log.Debug(string(p)) } // TODO(mattmoor): Depending on what this is, use the higher-level stuff. diff --git a/src/pkg/utils/wait.go b/src/pkg/utils/wait.go index a6727d9e35..905b77d414 100644 --- a/src/pkg/utils/wait.go +++ b/src/pkg/utils/wait.go @@ -5,6 +5,7 @@ package utils import ( + "context" "errors" "fmt" "net" @@ -14,6 +15,7 @@ import ( "strings" "time" + "github.com/zarf-dev/zarf/src/pkg/logging" "github.com/zarf-dev/zarf/src/pkg/utils/exec" "github.com/zarf-dev/zarf/src/pkg/message" @@ -29,11 +31,13 @@ func isJSONPathWaitType(condition string) bool { } // ExecuteWait executes the wait-for command. -func ExecuteWait(waitTimeout, waitNamespace, condition, kind, identifier string, timeout time.Duration) error { +func ExecuteWait(ctx context.Context, waitTimeout, waitNamespace, condition, kind, identifier string, timeout time.Duration) error { + log := logging.FromContextOrDiscard(ctx) + // Handle network endpoints. switch kind { case "http", "https", "tcp": - return waitForNetworkEndpoint(kind, identifier, condition, timeout) + return waitForNetworkEndpoint(ctx, kind, identifier, condition, timeout) } // Type of wait, condition or JSONPath @@ -95,13 +99,13 @@ func ExecuteWait(waitTimeout, waitNamespace, condition, kind, identifier string, zarfKubectlGet := fmt.Sprintf("%s tools kubectl get %s %s %s", zarfCommand, namespaceFlag, kind, identifier) stdout, stderr, err := exec.Cmd(shell, append(shellArgs, zarfKubectlGet)...) if err != nil { - message.Debug(stdout, stderr, err) + log.Debug(zarfKubectlGet, "stdout", stdout, "stderr", stderr, "error", err) continue } resourceNotFound := strings.Contains(stderr, "No resources found") && identifier == "" if resourceNotFound { - message.Debug(stdout, stderr, err) + log.Debug("could not get Kubernetes resource", "stdout", stdout, "stderr", stderr, "error", err) continue } @@ -119,7 +123,7 @@ func ExecuteWait(waitTimeout, waitNamespace, condition, kind, identifier string, // If there is an error, log it and try again. if stdout, stderr, err := exec.Cmd(shell, append(shellArgs, zarfKubectlWait)...); err != nil { - message.Debug(stdout, stderr, err) + log.Debug("could not wait for Kubernetes resource", "stdout", stdout, "stderr", stderr, "error", err) continue } @@ -131,7 +135,9 @@ func ExecuteWait(waitTimeout, waitNamespace, condition, kind, identifier string, } // waitForNetworkEndpoint waits for a network endpoint to respond. -func waitForNetworkEndpoint(resource, name, condition string, timeout time.Duration) error { +func waitForNetworkEndpoint(ctx context.Context, resource, name, condition string, timeout time.Duration) error { + log := logging.FromContextOrDiscard(ctx) + // Set the timeout for the wait-for command. expired := time.After(timeout) @@ -166,7 +172,7 @@ func waitForNetworkEndpoint(resource, name, condition string, timeout time.Durat // If the status code is not in the 2xx range, try again. if err != nil || resp.StatusCode < 200 || resp.StatusCode > 299 { - message.Debug(err) + log.Debug("network request failed", "error", err) continue } @@ -186,14 +192,14 @@ func waitForNetworkEndpoint(resource, name, condition string, timeout time.Durat // Try to get the URL and check the status code. resp, err := http.Get(url) if err != nil || resp.StatusCode != code { - message.Debug(err) + log.Debug("network request failed", "error", err) continue } default: // Fallback to any generic protocol using net.Dial conn, err := net.Dial(resource, name) if err != nil { - message.Debug(err) + log.Debug("network connection failed", "error", err) continue } defer conn.Close() diff --git a/src/pkg/zoci/pull.go b/src/pkg/zoci/pull.go index 9fd76e9ccc..90f3fa5ebc 100644 --- a/src/pkg/zoci/pull.go +++ b/src/pkg/zoci/pull.go @@ -56,7 +56,7 @@ func (r *Remote) PullPackage(ctx context.Context, destinationDir string, concurr successText := fmt.Sprintf("Pulling %q", helpers.OCIURLPrefix+r.Repo().Reference.String()) layerSize := oci.SumDescsSize(layersToPull) - go utils.RenderProgressBarForLocalDirWrite(destinationDir, layerSize, doneSaving, "Pulling", successText) + go utils.RenderProgressBarForLocalDirWrite(ctx, destinationDir, layerSize, doneSaving, "Pulling", successText) dst, err := file.New(destinationDir) if err != nil {