Merge branch 'main' into instruqt

src/cmd/package.go

@@ -201,6 +201,7 @@ var packageInspectCmd = &cobra.Command{
 		}
 	},
 	RunE: func(cmd *cobra.Command, args []string) error {
+		// NOTE(mkcp): Gets user input with message
 		src, err := choosePackage(args)
 		if err != nil {
 			return err
@@ -234,6 +235,9 @@ var packageInspectCmd = &cobra.Command{
 		if err != nil {
 			return fmt.Errorf("failed to inspect package: %w", err)
 		}
+		// HACK(mkcp): This init call ensures we still can still print Yaml when message is disabled. Remove when we
+		// release structured logged and don't have to disable message globally in pre-run.
+		message.InitializePTerm(logger.DestinationDefault)
 		err = utils.ColorPrintYAML(output, nil, false)
 		if err != nil {
 			return err
@@ -275,7 +279,11 @@ var packageListCmd = &cobra.Command{
 			})
 		}
 
+		// NOTE(mkcp): Renders table with message.
 		header := []string{"Package", "Version", "Components"}
+		// HACK(mkcp): Similar to `package inspect`, we do want to use message here but we have to make sure our feature
+		// flagging doesn't disable this. Nothing happens after this so it's safe, but still very hacky.
+		message.InitializePTerm(logger.DestinationDefault)
 		message.Table(header, packageData)
 
 		// Print out any unmarshalling errors

src/internal/packager/images/pull.go

@@ -90,14 +90,7 @@ func Pull(ctx context.Context, cfg PullConfig) (map[transform.Image]v1.Image, er
 	// TODO(mkcp): Remove message on logger release
 	spinner := message.NewProgressSpinner("Fetching info for %d images. %s", imageCount, longer)
 	defer spinner.Stop()
-	switch c := len(cfg.ImageList); {
-	case c > 15:
-		l.Info("fetching info for images. This step may take a couple of minutes to complete", "count", c, "destination", cfg.DestinationDirectory)
-	case c > 5:
-		l.Info("fetching info for images. This step may take several seconds to complete", "count", c, "destination", cfg.DestinationDirectory)
-	default:
-		l.Info("fetching info for images", "count", c, "destination", cfg.DestinationDirectory)
-	}
+	l.Info("fetching info for images", "count", imageCount, "destination", cfg.DestinationDirectory)
 
 	logs.Warn.SetOutput(&message.DebugWriter{})
 	logs.Progress.SetOutput(&message.DebugWriter{})
@@ -113,13 +106,14 @@ func Pull(ctx context.Context, cfg PullConfig) (map[transform.Image]v1.Image, er
 
 	var counter, totalBytes atomic.Int64
 
+	// Spawn a goroutine for each
 	for _, refInfo := range cfg.ImageList {
 		refInfo := refInfo
 		eg.Go(func() error {
 			idx := counter.Add(1)
 			// TODO(mkcp): Remove message on logger release
 			spinner.Updatef("Fetching image info (%d of %d)", idx, imageCount)
-			l.Info("fetching image info", "name", refInfo.Name)
+			l.Debug("fetching image info", "name", refInfo.Name)
 
 			ref := refInfo.Reference
 			for k, v := range cfg.RegistryOverrides {
@@ -236,6 +230,7 @@ func Pull(ctx context.Context, cfg PullConfig) (map[transform.Image]v1.Image, er
 		})
 	}
 
+	// Wait until we're done fetching images
 	if err := eg.Wait(); err != nil {
 		return nil, err
 	}
@@ -254,11 +249,15 @@ func Pull(ctx context.Context, cfg PullConfig) (map[transform.Image]v1.Image, er
 
 	err = retry.Do(func() error {
 		saved, err := SaveConcurrent(ctx, cranePath, toPull)
+		// Done save, remove from download list.
 		for k := range saved {
 			delete(toPull, k)
 		}
 		return err
-	}, retry.Context(ctx), retry.Attempts(2))
+	},
+		retry.Context(ctx),
+		retry.Attempts(2),
+	)
 	if err != nil {
 		// TODO(mkcp): Remove message on logger release
 		message.Warnf("Failed to save images in parallel, falling back to sequential save: %s", err.Error())
@@ -269,7 +268,10 @@ func Pull(ctx context.Context, cfg PullConfig) (map[transform.Image]v1.Image, er
 				delete(toPull, k)
 			}
 			return err
-		}, retry.Context(ctx), retry.Attempts(2))
+		},
+			retry.Context(ctx),
+			retry.Attempts(2),
+		)
 		if err != nil {
 			return nil, err
 		}
@@ -354,24 +356,39 @@ func CleanupInProgressLayers(ctx context.Context, img v1.Image) error {
 
 // SaveSequential saves images sequentially.
 func SaveSequential(ctx context.Context, cl clayout.Path, m map[transform.Image]v1.Image) (map[transform.Image]v1.Image, error) {
+	l := logger.From(ctx)
 	saved := map[transform.Image]v1.Image{}
 	for info, img := range m {
 		annotations := map[string]string{
 			ocispec.AnnotationBaseImageName: info.Reference,
 		}
+		wStart := time.Now()
+		size, err := img.Size()
+		if err != nil {
+			return saved, err
+		}
+		l.Info("saving image", "ref", info.Reference, "size", size, "method", "sequential")
 		if err := cl.AppendImage(img, clayout.WithAnnotations(annotations)); err != nil {
 			if err := CleanupInProgressLayers(ctx, img); err != nil {
 				message.WarnErr(err, "failed to clean up in-progress layers, please run `zarf tools clear-cache`")
+				l.Error("failed to clean up in-progress layers. please run `zarf tools clear-cache`")
 			}
 			return saved, err
 		}
 		saved[info] = img
+		l.Debug("done saving image",
+			"ref", info.Reference,
+			"size", size,
+			"method", "sequential",
+			"duration", time.Since(wStart),
+		)
 	}
 	return saved, nil
 }
 
 // SaveConcurrent saves images in a concurrent, bounded manner.
 func SaveConcurrent(ctx context.Context, cl clayout.Path, m map[transform.Image]v1.Image) (map[transform.Image]v1.Image, error) {
+	l := logger.From(ctx)
 	saved := map[transform.Image]v1.Image{}
 
 	var mu sync.Mutex
@@ -391,12 +408,25 @@ func SaveConcurrent(ctx context.Context, cl clayout.Path, m map[transform.Image]
 					return err
 				}
 
+				size, err := img.Size()
+				if err != nil {
+					return err
+				}
+				wStart := time.Now()
+				l.Info("saving image", "ref", info.Reference, "size", size, "method", "concurrent")
 				if err := cl.WriteImage(img); err != nil {
 					if err := CleanupInProgressLayers(ectx, img); err != nil {
 						message.WarnErr(err, "failed to clean up in-progress layers, please run `zarf tools clear-cache`")
+						l.Error("failed to clean up in-progress layers. please run `zarf tools clear-cache`")
 					}
 					return err
 				}
+				l.Debug("done saving image",
+					"ref", info.Reference,
+					"size", size,
+					"method", "concurrent",
+					"duration", time.Since(wStart),
+				)
 
 				mu.Lock()
 				defer mu.Unlock()

src/internal/packager/sbom/tools.go

@@ -5,7 +5,9 @@
 package sbom
 
 import (
+	"context"
 	"fmt"
+	"github.com/zarf-dev/zarf/src/pkg/logger"
 	"path/filepath"
 
 	"github.com/AlecAivazis/survey/v2"
@@ -14,20 +16,23 @@ import (
 )
 
 // ViewSBOMFiles opens a browser to view the SBOM files and pauses for user input.
-func ViewSBOMFiles(directory string) error {
+func ViewSBOMFiles(ctx context.Context, directory string) error {
+	l := logger.From(ctx)
 	sbomViewFiles, err := filepath.Glob(filepath.Join(directory, "sbom-viewer-*"))
 	if err != nil {
 		return err
 	}
 
 	if len(sbomViewFiles) == 0 {
 		message.Note("There were no images with software bill-of-materials (SBOM) included.")
+		l.Info("there were no images with software bill-of-materials (SBOM) included.")
 		return nil
 	}
 
 	link := sbomViewFiles[0]
 	msg := fmt.Sprintf("This package has %d images with software bill-of-materials (SBOM) included. If your browser did not open automatically you can copy and paste this file location into your browser address bar to view them: %s\n\n", len(sbomViewFiles), link)
 	message.Note(msg)
+	l.Info("this package has images with software bill-of-materials (SBOM) included. If your browser did not open automatically you can copy and paste this file location into your browser address bar to view them", "SBOMCount", len(sbomViewFiles), "link", link)
 	if err := exec.LaunchURL(link); err != nil {
 		return err
 	}

src/internal/packager2/inspect.go

@@ -54,7 +54,7 @@ func InspectList(ctx context.Context, opt ZarfInspectOptions) ([]string, error)
 	if err != nil {
 		return nil, err
 	}
-	// Only list images if we have have components
+	// Only list images if we have components
 	if len(pkg.Components) > 0 {
 		for _, component := range pkg.Components {
 			imageList = append(imageList, component.Images...)
@@ -104,7 +104,7 @@ func handleSBOMOptions(ctx context.Context, opt ZarfInspectOptions) error {
 		return err
 	}
 	if opt.ViewSBOM {
-		err := sbom.ViewSBOMFiles(sbomPath)
+		err := sbom.ViewSBOMFiles(ctx, sbomPath)
 		if err != nil {
 			return err
 		}

src/internal/packager2/remove.go

@@ -7,6 +7,7 @@ import (
 	"context"
 	"errors"
 	"fmt"
+	"github.com/zarf-dev/zarf/src/pkg/logger"
 	"slices"
 
 	"helm.sh/helm/v3/pkg/action"
@@ -33,6 +34,7 @@ type RemoveOptions struct {
 
 // Remove removes a package that was already deployed onto a cluster, uninstalling all installed helm charts.
 func Remove(ctx context.Context, opt RemoveOptions) error {
+	l := logger.From(ctx)
 	pkg, err := packageFromSourceOrCluster(ctx, opt.Cluster, opt.Source, opt.SkipSignatureValidation, opt.PublicKeyPath)
 	if err != nil {
 		return err
@@ -109,6 +111,7 @@ func Remove(ctx context.Context, opt RemoveOptions) error {
 					}
 					if errors.Is(err, driver.ErrReleaseNotFound) {
 						message.Warnf("Helm release for helm chart '%s' in the namespace '%s' was not found.  Was it already removed?", chart.ChartName, chart.Namespace)
+						l.Warn("helm release was not found. was it already removed?", "name", chart.ChartName, "namespace", chart.Namespace)
 					}
 
 					// Pop the removed helm chart from the installed charts slice.
@@ -119,6 +122,7 @@ func Remove(ctx context.Context, opt RemoveOptions) error {
 					if err != nil {
 						// We warn and ignore errors because we may have removed the cluster that this package was inside of
 						message.Warnf("Unable to update the secret for package %s, this may be normal if the cluster was removed: %s", depPkg.Name, err.Error())
+						l.Warn("unable to update secret for package, this may be normal if the cluster was removed", "pkgName", depPkg.Name, "error", err.Error())
 					}
 				}
 			}
@@ -139,6 +143,7 @@ func Remove(ctx context.Context, opt RemoveOptions) error {
 				if err != nil {
 					// We warn and ignore errors because we may have removed the cluster that this package was inside of
 					message.Warnf("Unable to update the secret for package %s, this may be normal if the cluster was removed: %s", depPkg.Name, err.Error())
+					l.Warn("unable to update secret package, this may be normal if the cluster was removed", "pkgName", depPkg.Name, "error", err.Error())
 				}
 			}
 			return nil
@@ -157,6 +162,7 @@ func Remove(ctx context.Context, opt RemoveOptions) error {
 		err := opt.Cluster.DeleteDeployedPackage(ctx, depPkg.Name)
 		if err != nil {
 			message.Warnf("Unable to delete the secret for package %s, this may be normal if the cluster was removed: %s", depPkg.Name, err.Error())
+			l.Warn("unable to delete secret for package, this may be normal if the cluster was removed", "pkgName", depPkg.Name, "error", err.Error())
 		}
 	}
 

src/pkg/cluster/cluster.go

@@ -18,6 +18,7 @@ import (
 
 	"github.com/avast/retry-go/v4"
 
+	"github.com/zarf-dev/zarf/src/pkg/logger"
 	"github.com/zarf-dev/zarf/src/pkg/message"
 	"k8s.io/client-go/dynamic"
 	"k8s.io/client-go/tools/clientcmd"
@@ -40,8 +41,10 @@ type Cluster struct {
 
 // NewClusterWithWait creates a new Cluster instance and waits for the given timeout for the cluster to be ready.
 func NewClusterWithWait(ctx context.Context) (*Cluster, error) {
+	l := logger.From(ctx)
 	spinner := message.NewProgressSpinner("Waiting for cluster connection")
 	defer spinner.Stop()
+	l.Info("waiting for cluster connection")
 
 	c, err := NewCluster()
 	if err != nil {

src/pkg/packager/creator/normal.go

@@ -349,7 +349,7 @@ func (pc *PackageCreator) Output(ctx context.Context, dst *layout.PackagePaths,
 		}
 
 		if pc.createOpts.ViewSBOM {
-			err := sbom.ViewSBOMFiles(sbomDir)
+			err := sbom.ViewSBOMFiles(ctx, sbomDir)
 			if err != nil {
 				return err
 			}

src/pkg/packager/inspect.go

@@ -51,7 +51,7 @@ func (p *Packager) Inspect(ctx context.Context) error {
 	}
 
 	if p.cfg.InspectOpts.ViewSBOM {
-		err := sbom.ViewSBOMFiles(sbomDir)
+		err := sbom.ViewSBOMFiles(ctx, sbomDir)
 		if err != nil {
 			return err
 		}