asset/store: clean up logging and logic

pkg/asset/ignition/bootstrap/bootstrap.go

@@ -12,7 +12,7 @@ import (
 	"github.com/coreos/ignition/config/util"
 	igntypes "github.com/coreos/ignition/config/v2_2/types"
 	"github.com/pkg/errors"
-	log "github.com/sirupsen/logrus"
+	"github.com/sirupsen/logrus"
 
 	"github.com/openshift/installer/pkg/asset"
 	"github.com/openshift/installer/pkg/asset/ignition"
@@ -148,7 +148,7 @@ func (a *Bootstrap) getTemplateData(installConfig *types.InstallConfig) (*bootst
 
 	releaseImage := defaultReleaseImage
 	if ri, ok := os.LookupEnv("OPENSHIFT_INSTALL_RELEASE_IMAGE_OVERRIDE"); ok && ri != "" {
-		log.Warn("Found override for ReleaseImage. Please be warned, this is not advised")
+		logrus.Warn("Found override for ReleaseImage. Please be warned, this is not advised")
 		releaseImage = ri
 	}
 

pkg/asset/store.go

@@ -81,7 +81,7 @@ func (s *StoreImpl) load(dir string) error {
 	}
 	err = json.Unmarshal(data, &assets)
 	if err != nil {
-		return errors.Wrapf(err, "failed to unmarshal state file %s", path)
+		return errors.Wrapf(err, "failed to unmarshal state file %q", path)
 	}
 	s.stateFileAssets = assets
 	return nil
@@ -91,7 +91,7 @@ func (s *StoreImpl) load(dir string) error {
 func (s *StoreImpl) LoadAssetFromState(asset Asset) error {
 	bytes, ok := s.stateFileAssets[reflect.TypeOf(asset).String()]
 	if !ok {
-		return errors.Errorf("asset %s is not found in the state file", asset.Name())
+		return errors.Errorf("asset %q is not found in the state file", asset.Name())
 	}
 	return json.Unmarshal(bytes, asset)
 }
@@ -123,93 +123,80 @@ func (s *StoreImpl) Save(dir string) error {
 	return nil
 }
 
-// fetch retrieves the state of the given asset, generating it and its
-// dependencies if necessary.
-// It returns dirty if the asset or any of its parents is loaded from on-disk files.
-func (s *StoreImpl) fetch(asset Asset, indent string) (dirty bool, err error) {
-	logrus.Debugf("%sFetching %s...", indent, asset.Name())
+// fetch populates the given asset, generating it and its dependencies if
+// necessary, and returns whether or not the asset had to be regenerated and
+// any errors.
+func (s *StoreImpl) fetch(asset Asset, indent string) (bool, error) {
+	logrus.Debugf("%sFetching %q...", indent, asset.Name())
 
 	// Return immediately if the asset is found in the cache,
 	// this is because we are doing a depth-first-search, it's guaranteed
 	// that we always fetch the parent before children, so we don't need
 	// to worry about invalidating anything in the cache.
 	storedAsset, ok := s.assets[reflect.TypeOf(asset)]
 	if ok {
-		logrus.Debugf("%sFound %s...", indent, asset.Name())
+		logrus.Debugf("%sReusing previously-fetched %q", indent, asset.Name())
 		reflect.ValueOf(asset).Elem().Set(reflect.ValueOf(storedAsset.asset).Elem())
 		return storedAsset.dirty, nil
 	}
 
 	dependencies := asset.Dependencies()
 	parents := make(Parents, len(dependencies))
 	if len(dependencies) > 0 {
-		logrus.Debugf("%sGenerating dependencies of %s...", indent, asset.Name())
+		logrus.Debugf("%sFetching dependencies of %q...", indent, asset.Name())
 	}
 
 	var anyParentsDirty bool
 	for _, d := range dependencies {
-		dt, err := s.fetch(d, indent+"  ")
+		dirty, err := s.fetch(d, indent+"  ")
 		if err != nil {
-			return false, errors.Wrapf(err, "failed to fetch dependency for %s", asset.Name())
+			return false, errors.Wrapf(err, "failed to fetch dependency of %q", asset.Name())
 		}
-		if dt {
+		if dirty {
 			anyParentsDirty = true
 		}
 		parents.Add(d)
 	}
 
 	// Try to find the asset from the state file.
-	logrus.Debugf("%sLooking up asset from state file: %s", indent, reflect.TypeOf(asset).String())
 	foundInStateFile := s.IsAssetInState(asset)
+	if foundInStateFile {
+		logrus.Debugf("%sFound %q in state file", indent, asset.Name())
+	}
 
-	// Try to load from on-disk files first.
+	// Try to load from the provided files.
 	var foundOnDisk bool
-	as, ok := asset.(WritableAsset)
-	if ok {
-		logrus.Debugf("%sLooking up asset %s from disk", indent, asset.Name())
+	if as, ok := asset.(WritableAsset); ok {
+		var err error
 		foundOnDisk, err = as.Load(s.fileFetcher)
 		if err != nil {
-			return false, errors.Wrapf(err, "unexpected error when loading asset %s", asset.Name())
+			return false, errors.Wrapf(err, "failed to load asset %q", asset.Name())
 		}
 		if foundOnDisk {
-			logrus.Debugf("%sFound %s on disk...", indent, asset.Name())
+			logrus.Infof("Consuming %q from target directory", asset.Name())
 			s.onDiskAssets = append(s.onDiskAssets, as)
 		}
 	}
 
-	dirty = anyParentsDirty || foundOnDisk
+	if anyParentsDirty && foundOnDisk {
+		logrus.Warningf("%sDiscarding the %q that was provided in the target directory because its dependencies are dirty and it needs to be regenerated", indent, asset.Name())
+	}
 
-	switch {
-	case anyParentsDirty && foundOnDisk:
-		// TODO(yifan): We should check the content to make sure there's no conflict.
-		logrus.Warningf("%sBoth parent assets and current asset %s are on disk, Re-generating ...", indent, asset.Name())
+	if anyParentsDirty || (!foundOnDisk && !foundInStateFile) {
+		logrus.Debugf("%sGenerating %q...", indent, asset.Name())
 		if err := asset.Generate(parents); err != nil {
-			return dirty, errors.Wrapf(err, "failed to generate asset %s", asset.Name())
-		}
-	case anyParentsDirty:
-		if foundInStateFile {
-			logrus.Warningf("%sRe-generating %s...", indent, asset.Name())
-		} else {
-			logrus.Debugf("%sGenerating %s...", indent, asset.Name())
+			return false, errors.Wrapf(err, "failed to generate asset %q", asset.Name())
 		}
-		if err := asset.Generate(parents); err != nil {
-			return dirty, errors.Wrapf(err, "failed to generate asset %s", asset.Name())
-		}
-	case foundOnDisk:
-		logrus.Debugf("%sUsing on-disk asset %s", indent, asset.Name())
-	default: // !anyParentsDirty && !foundOnDisk
-		if foundInStateFile {
-			if err := s.LoadAssetFromState(asset); err != nil {
-				return dirty, errors.Wrapf(err, "failed to load asset from state file %s", asset.Name())
-			}
-		} else {
-			logrus.Debugf("%sAsset %s not found in state file. Generating ...", indent, asset.Name())
-			if err := asset.Generate(parents); err != nil {
-				return dirty, errors.Wrapf(err, "failed to generate asset %s", asset.Name())
-			}
+	} else if foundInStateFile {
+		logrus.Debugf("%sLoading %q from state file", indent, asset.Name())
+		if err := s.LoadAssetFromState(asset); err != nil {
+			return false, errors.Wrapf(err, "failed to load asset %q from state file", asset.Name())
 		}
+	} else if foundOnDisk {
+		logrus.Debugf("%sLoading %q from target directory", indent, asset.Name())
 	}
 
+	dirty := anyParentsDirty || foundOnDisk
 	s.assets[reflect.TypeOf(asset)] = assetState{asset: asset, dirty: dirty}
 	return dirty, nil
 }