Fix inconsistent rebuild

pkg/cnab/config-adapter/stamp.go

@@ -8,13 +8,15 @@ import (
 	"encoding/json"
 	"errors"
 	"fmt"
+	"sort"
 
 	"get.porter.sh/porter/pkg"
 	"get.porter.sh/porter/pkg/cnab"
 	"get.porter.sh/porter/pkg/config"
 	"get.porter.sh/porter/pkg/manifest"
 	"get.porter.sh/porter/pkg/portercontext"
 	"get.porter.sh/porter/pkg/tracing"
+	"github.com/Masterminds/semver/v3"
 )
 
 // Stamp contains Porter specific metadata about a bundle that we can place
@@ -69,10 +71,48 @@ func (s Stamp) WriteManifest(cxt *portercontext.Context, path string) error {
 // MixinRecord contains information about a mixin used in a bundle
 // For now it is a placeholder for data that we would like to include in the future.
 type MixinRecord struct {
+	// Name of the mixin used in the bundle. This is used for sorting only, and
+	// should not be written to the Porter's stamp in bundle.json because we are
+	// storing these mixin records in a map, keyed by the mixin name.
+	Name string `json:"-"`
+
 	// Version of the mixin used in the bundle.
 	Version string `json:"version"`
 }
 
+type MixinRecords []MixinRecord
+
+func (m MixinRecords) Len() int {
+	return len(m)
+}
+
+func (m MixinRecords) Less(i, j int) bool {
+	// Currently there can only be a single version of a mixin used in a bundle
+	// I'm considering version as well for sorting in case that changes in the future once mixins are bundles
+	// referenced by a bundle, and not embedded binaries
+	iRecord := m[i]
+	jRecord := m[j]
+	if iRecord.Name == jRecord.Name {
+		// Try to sort by the mixin's semantic version
+		// If it doesn't parse, just fall through and sort as a string instead
+		iVersion, iErr := semver.NewVersion(iRecord.Version)
+		jVersion, jErr := semver.NewVersion(jRecord.Version)
+		if iErr == nil && jErr == nil {
+			return iVersion.LessThan(jVersion)
+		} else {
+			return iRecord.Version < jRecord.Version
+		}
+	}
+
+	return iRecord.Name < jRecord.Name
+}
+
+func (m MixinRecords) Swap(i, j int) {
+	tmp := m[i]
+	m[i] = m[j]
+	m[j] = tmp
+}
+
 func (c *ManifestConverter) GenerateStamp(ctx context.Context) (Stamp, error) {
 	log := tracing.LoggerFromContext(ctx)
 
@@ -86,11 +126,9 @@ func (c *ManifestConverter) GenerateStamp(ctx context.Context) (Stamp, error) {
 	stamp.EncodedManifest = base64.StdEncoding.EncodeToString(rawManifest)
 
 	stamp.Mixins = make(map[string]MixinRecord, len(c.Manifest.Mixins))
-	usedMixinsVersion := c.getUsedMixinsVersion()
-	for usedMixinName, usedMixinVersion := range usedMixinsVersion {
-		stamp.Mixins[usedMixinName] = MixinRecord{
-			Version: usedMixinVersion,
-		}
+	usedMixins := c.getUsedMixinRecords()
+	for _, record := range usedMixins {
+		stamp.Mixins[record.Name] = record
 	}
 
 	digest, err := c.DigestManifest()
@@ -122,9 +160,10 @@ func (c *ManifestConverter) DigestManifest() (string, error) {
 	v := pkg.Version
 	data = append(data, v...)
 
-	usedMixinsVersion := c.getUsedMixinsVersion()
-	for usedMixinName, usedMixinVersion := range usedMixinsVersion {
-		data = append(append(data, usedMixinName...), usedMixinVersion...)
+	usedMixins := c.getUsedMixinRecords()
+	sort.Sort(usedMixins) // Ensure that this is sorted so the digest is consistent
+	for _, mixinRecord := range usedMixins {
+		data = append(append(data, mixinRecord.Name...), mixinRecord.Version...)
 	}
 
 	digest := sha256.Sum256(data)
@@ -152,17 +191,22 @@ func LoadStamp(bun cnab.ExtendedBundle) (Stamp, error) {
 	return stamp, nil
 }
 
-// getUsedMixinsVersion compare the mixins defined in the manifest and the ones installed and then retrieve the mixin's version info
-func (c *ManifestConverter) getUsedMixinsVersion() map[string]string {
-	usedMixinsVersion := make(map[string]string)
+// getUsedMixinRecords returns a list of the mixins used by the bundle, including
+// information about the installed mixin, such as its version.
+func (c *ManifestConverter) getUsedMixinRecords() MixinRecords {
+	usedMixins := make(MixinRecords, 0)
 
 	for _, usedMixin := range c.Manifest.Mixins {
 		for _, installedMixin := range c.InstalledMixins {
 			if usedMixin.Name == installedMixin.Name {
-				usedMixinsVersion[usedMixin.Name] = installedMixin.GetVersionInfo().Version
+				usedMixins = append(usedMixins, MixinRecord{
+					Name:    installedMixin.Name,
+					Version: installedMixin.GetVersionInfo().Version,
+				})
 			}
 		}
 	}
 
-	return usedMixinsVersion
+	sort.Sort(usedMixins)
+	return usedMixins
 }

pkg/cnab/config-adapter/stamp_test.go

@@ -2,6 +2,7 @@ package configadapter
 
 import (
 	"context"
+	"sort"
 	"testing"
 
 	"get.porter.sh/porter/pkg"
@@ -36,7 +37,7 @@ func TestConfig_GenerateStamp(t *testing.T) {
 	stamp, err := a.GenerateStamp(ctx)
 	require.NoError(t, err, "DigestManifest failed")
 	assert.Equal(t, simpleManifestDigest, stamp.ManifestDigest)
-	assert.Equal(t, map[string]MixinRecord{"exec": {Version: "v1.2.3"}}, stamp.Mixins, "Stamp.Mixins was not populated properly")
+	assert.Equal(t, map[string]MixinRecord{"exec": {Name: "exec", Version: "v1.2.3"}}, stamp.Mixins, "Stamp.Mixins was not populated properly")
 	assert.Equal(t, pkg.Version, stamp.Version)
 	assert.Equal(t, pkg.Commit, stamp.Commit)
 
@@ -181,3 +182,52 @@ func TestConfig_GenerateStamp_IncludeVersion(t *testing.T) {
 	assert.Equal(t, "v1.2.3", stamp.Version)
 	assert.Equal(t, "abc123", stamp.Commit)
 }
+
+func TestMixinRecord_Sort(t *testing.T) {
+	records := MixinRecords{
+		{Name: "helm", Version: "0.1.13"},
+		{Name: "helm", Version: "v0.1.2"},
+		{Name: "testmixin", Version: "1.2.3"},
+		{Name: "exec", Version: "2.1.0"},
+		// These won't parse as valid semver, so just sort them by the string representation instead
+		{
+			Name:    "az",
+			Version: "invalid-version2",
+		},
+		{
+			Name:    "az",
+			Version: "invalid-version1",
+		},
+	}
+
+	sort.Sort(records)
+
+	wantRecords := MixinRecords{
+		{
+			Name:    "az",
+			Version: "invalid-version1",
+		},
+		{
+			Name:    "az",
+			Version: "invalid-version2",
+		},
+		{
+			Name:    "exec",
+			Version: "2.1.0",
+		},
+		{
+			Name:    "helm",
+			Version: "v0.1.2",
+		},
+		{
+			Name:    "helm",
+			Version: "0.1.13",
+		},
+		{
+			Name:    "testmixin",
+			Version: "1.2.3",
+		},
+	}
+
+	assert.Equal(t, wantRecords, records)
+}

pkg/porter/lifecycle.go

@@ -211,7 +211,11 @@ func (p *Porter) resolveBundleReference(ctx context.Context, opts *BundleReferen
 			return cnab.BundleReference{}, err
 		}
 	} else if opts.File != "" { // load the local bundle source
-		localBundle, err := p.ensureLocalBundleIsUpToDate(ctx, opts.BundleDefinitionOptions)
+		buildOpts := BuildOptions{
+			BundleDefinitionOptions: opts.BundleDefinitionOptions,
+			InsecureRegistry:        opts.InsecureRegistry,
+		}
+		localBundle, err := p.ensureLocalBundleIsUpToDate(ctx, buildOpts)
 		if err != nil {
 			return cnab.BundleReference{}, err
 		}

pkg/porter/publish.go

@@ -99,7 +99,11 @@ func (p *Porter) publishFromFile(ctx context.Context, opts PublishOptions) error
 	ctx, log := tracing.StartSpan(ctx)
 	defer log.EndSpan()
 
-	_, err := p.ensureLocalBundleIsUpToDate(ctx, opts.BundleDefinitionOptions)
+	buildOpts := BuildOptions{
+		BundleDefinitionOptions: opts.BundleDefinitionOptions,
+		InsecureRegistry:        opts.InsecureRegistry,
+	}
+	_, err := p.ensureLocalBundleIsUpToDate(ctx, buildOpts)
 	if err != nil {
 		return err
 	}

pkg/porter/stamp.go

@@ -2,6 +2,7 @@ package porter
 
 import (
 	"context"
+	"encoding/json"
 	"errors"
 	"fmt"
 	"os"
@@ -18,7 +19,7 @@ import (
 
 // ensureLocalBundleIsUpToDate ensures that the bundle is up-to-date with the porter manifest,
 // if it is out-of-date, performs a build of the bundle.
-func (p *Porter) ensureLocalBundleIsUpToDate(ctx context.Context, opts BundleDefinitionOptions) (cnab.BundleReference, error) {
+func (p *Porter) ensureLocalBundleIsUpToDate(ctx context.Context, opts BuildOptions) (cnab.BundleReference, error) {
 	ctx, log := tracing.StartSpan(ctx,
 		attribute.Bool("autobuild-disabled", opts.AutoBuildDisabled))
 	defer log.EndSpan()
@@ -27,7 +28,7 @@ func (p *Porter) ensureLocalBundleIsUpToDate(ctx context.Context, opts BundleDef
 		return cnab.BundleReference{}, nil
 	}
 
-	upToDate, err := p.IsBundleUpToDate(ctx, opts)
+	upToDate, err := p.IsBundleUpToDate(ctx, opts.BundleDefinitionOptions)
 	if err != nil {
 		log.Warnf("WARNING: %w", err)
 	}
@@ -36,12 +37,15 @@ func (p *Porter) ensureLocalBundleIsUpToDate(ctx context.Context, opts BundleDef
 		if opts.AutoBuildDisabled {
 			log.Warn("WARNING: The bundle is out-of-date. Skipping autobuild because --autobuild-disabled was specified")
 		} else {
+			log.Info("Changes have been detected and the previously built bundle is out-of-date, rebuilding the bundle before proceeding...")
 			log.Info("Building bundle ===>")
 			// opts.File is non-empty, which overrides opts.CNABFile if set
 			// (which may be if a cached bundle is fetched e.g. when running an action)
 			opts.CNABFile = ""
-			buildOpts := BuildOptions{BundleDefinitionOptions: opts}
-			buildOpts.Validate(p)
+			buildOpts := opts
+			if err = buildOpts.Validate(p); err != nil {
+				return cnab.BundleReference{}, log.Errorf("Validation of build options when autobuilding the bundle failed: %w", err)
+			}
 			err := p.Build(ctx, buildOpts)
 			if err != nil {
 				return cnab.BundleReference{}, err
@@ -67,62 +71,99 @@ func (p *Porter) IsBundleUpToDate(ctx context.Context, opts BundleDefinitionOpti
 	ctx, span := tracing.StartSpan(ctx)
 	defer span.EndSpan()
 
+	span.Debugf("Checking if the bundle is up-to-date...")
+
+	// This is a prefix for any message that explains why the bundle is out-of-date
+	const rebuildMessagePrefix = "Bundle is out-of-date and must be rebuilt"
+
 	if opts.File == "" {
-		return false, span.Error(errors.New("File is required"))
+		span.Debugf("%s because the current bundle was not specified. Please report this as a bug!", rebuildMessagePrefix)
+		return false, span.Errorf("File is required")
 	}
 	m, err := manifest.LoadManifestFrom(ctx, p.Config, opts.File)
 	if err != nil {
-		return false, err
+		err = fmt.Errorf("the current bundle could not be read: %w", err)
+		span.Debugf("%s: %w", rebuildMessagePrefix, err)
+		return false, span.Error(err)
 	}
 
 	if exists, _ := p.FileSystem.Exists(opts.CNABFile); exists {
 		bun, err := cnab.LoadBundle(p.Context, opts.CNABFile)
 		if err != nil {
-			return false, span.Error(fmt.Errorf("could not marshal data from %s: %w", opts.CNABFile, err))
+			err = fmt.Errorf("the previously built bundle at %s could not be read: %w", opts.CNABFile, err)
+			span.Debugf("%s: %w", rebuildMessagePrefix, err)
+			return false, span.Error(err)
 		}
 
 		// Check whether invocation images exist in host registry.
 		for _, invocationImage := range bun.InvocationImages {
 			// if the invocationImage is built before using a random string tag,
 			// we should rebuild it with the new format
 			if strings.HasSuffix(invocationImage.Image, "-installer") {
+				span.Debugf("%s because it uses the old -installer suffixed image name (%s)", invocationImage.Image)
 				return false, nil
 			}
 
 			imgRef, err := cnab.ParseOCIReference(invocationImage.Image)
 			if err != nil {
-				return false, span.Errorf("error parsing %s as an OCI image reference: %w", invocationImage.Image, err)
+				err = fmt.Errorf("error parsing %s as an OCI image reference: %w", invocationImage.Image, err)
+				span.Debugf("%s: %w", rebuildMessagePrefix, err)
+				return false, span.Error(err)
 			}
 
 			_, err = p.Registry.GetCachedImage(ctx, imgRef)
 			if err != nil {
 				if errors.Is(err, cnabtooci.ErrNotFound{}) {
-					span.Debugf("Invocation image %s doesn't exist in the local image cache, will need to build first", invocationImage.Image)
+					span.Debugf("%s because the invocation image %s doesn't exist in the local image cache", rebuildMessagePrefix, invocationImage.Image)
 					return false, nil
 				}
-				return false, err
-
+				err = fmt.Errorf("an error occurred checking the Docker cache for the invocation image: %w", err)
+				span.Debugf("%s: %w", rebuildMessagePrefix, err)
+				return false, span.Error(err)
 			}
 		}
 
 		oldStamp, err := configadapter.LoadStamp(bun)
 		if err != nil {
-			return false, span.Error(fmt.Errorf("could not load stamp from %s: %w", opts.CNABFile, err))
+			err = fmt.Errorf("could not load stamp from %s: %w", opts.CNABFile, err)
+			span.Debugf("%s: %w", rebuildMessagePrefix)
+			return false, span.Error(err)
 		}
 
 		mixins, err := p.getUsedMixins(ctx, m)
 		if err != nil {
-			return false, fmt.Errorf("error while listing used mixins: %w", err)
+			err = fmt.Errorf("an error occurred while listing used mixins: %w", err)
+			span.Debugf("%s: %w", rebuildMessagePrefix, err)
+			return false, span.Error(err)
 		}
 
 		converter := configadapter.NewManifestConverter(p.Config, m, nil, mixins)
 		newDigest, err := converter.DigestManifest()
 		if err != nil {
-			span.Debugf("could not determine if the bundle is up-to-date so will rebuild just in case: %w", err)
+			err = fmt.Errorf("the current manifest digest cannot be calculated: %w", err)
+			span.Debugf("%s: %w", rebuildMessagePrefix, err)
+			return false, span.Error(err)
+		}
+
+		manifestChanged := oldStamp.ManifestDigest != newDigest
+		if manifestChanged {
+			span.Debugf("%s because the cached bundle is stale", rebuildMessagePrefix)
+			if span.IsTracingEnabled() {
+				previousStampB, _ := json.Marshal(oldStamp)
+				currentStamp, _ := converter.GenerateStamp(ctx)
+				currentStampB, _ := json.Marshal(currentStamp)
+				span.SetAttributes(
+					attribute.String("previous-stamp", string(previousStampB)),
+					attribute.String("current-stamp", string(currentStampB)),
+				)
+			}
 			return false, nil
 		}
-		return oldStamp.ManifestDigest == newDigest, nil
+
+		span.Debugf("Bundle is up-to-date!")
+		return true, nil
 	}
 
+	span.Debugf("%s because a previously built bundle was not found", rebuildMessagePrefix)
 	return false, nil
 }