Recover corrupted volume cache (#1410)

* Restore succeeds (skipping over the layer) if layer contents are corrupted

Signed-off-by: Natalie Arellano <narellano@vmware.com>

* Exporter does not re-use layer from volume cache if layer contents are corrupted

Signed-off-by: Natalie Arellano <narellano@vmware.com>

* Fixes

Signed-off-by: Natalie Arellano <narellano@vmware.com>

---------

Signed-off-by: Natalie Arellano <narellano@vmware.com>

acceptance/acceptance_test.go

@@ -23,7 +23,6 @@ const (
 var (
 	latestPlatformAPI = api.Platform.Latest().String()
 	buildDir          string
-	cacheFixtureDir   string
 )
 
 func TestVersion(t *testing.T) {

acceptance/analyzer_test.go

@@ -37,7 +37,6 @@ func TestAnalyzer(t *testing.T) {
 
 	analyzeImage = analyzeTest.testImageRef
 	analyzerPath = analyzeTest.containerBinaryPath
-	cacheFixtureDir = filepath.Join("testdata", "cache-dir")
 	analyzeRegAuthConfig = analyzeTest.targetRegistry.authConfig
 	analyzeRegNetwork = analyzeTest.targetRegistry.network
 	analyzeDaemonFixtures = analyzeTest.targetDaemon.fixtures

acceptance/creator_test.go

@@ -40,7 +40,6 @@ func TestCreator(t *testing.T) {
 
 	createImage = createTest.testImageRef
 	creatorPath = createTest.containerBinaryPath
-	cacheFixtureDir = filepath.Join("testdata", "creator", "cache-dir")
 	createRegAuthConfig = createTest.targetRegistry.authConfig
 	createRegNetwork = createTest.targetRegistry.network
 	createDaemonFixtures = createTest.targetDaemon.fixtures

acceptance/restorer_test.go

@@ -165,7 +165,7 @@ func testRestorerFunc(platformAPI string) func(t *testing.T, when spec.G, it spe
 					h.AssertPathDoesNotExist(t, uncachedFile)
 				})
 
-				it("does not restore unused buildpack layer data", func() {
+				it("does not restore layer data from unused buildpacks", func() {
 					h.DockerRunAndCopy(t,
 						containerName,
 						copyDir,
@@ -179,6 +179,21 @@ func testRestorerFunc(platformAPI string) func(t *testing.T, when spec.G, it spe
 					unusedBpLayer := filepath.Join(copyDir, "layers", "unused_buildpack")
 					h.AssertPathDoesNotExist(t, unusedBpLayer)
 				})
+
+				it("does not restore corrupted layer data", func() {
+					h.DockerRunAndCopy(t,
+						containerName,
+						copyDir,
+						"/layers",
+						restoreImage,
+						h.WithFlags("--env", "CNB_PLATFORM_API="+platformAPI),
+						h.WithArgs("-cache-dir", "/cache"),
+					)
+
+					// check corrupted layer is not restored
+					corruptedFile := filepath.Join(copyDir, "layers", "corrupted_buildpack", "corrupted-layer")
+					h.AssertPathDoesNotExist(t, corruptedFile)
+				})
 			})
 		})
 

acceptance/testdata/exporter/cache-dir/committed/io.buildpacks.lifecycle.cache.metadata

@@ -0,0 +1,17 @@
+{
+  "buildpacks": [
+    {
+      "key": "corrupted_buildpack",
+      "version": "corrupted_v1",
+      "layers": {
+        "corrupted-layer": {
+          "sha": "sha256:258dfa0cc987efebc17559694866ebc91139e7c0e574f60d1d4092f53d7dff59",
+          "data": null,
+          "build": false,
+          "launch": true,
+          "cache": true
+        }
+      }
+    }
+  ]
+}

acceptance/testdata/exporter/container/layers/cacher_buildpack/cached-layer.sha

@@ -1 +1 @@
-sha256:b89860e2f9c62e6b5d66d3ce019e18cdabae30273c25150b7f20a82f7a70e494
+sha256:2d9c9c638d5c4f0df067eeae7b9c99ad05776a89d19ab863c28850a91e5f2944

acceptance/testdata/exporter/container/layers/corrupted_buildpack/corrupted-layer.toml

@@ -0,0 +1,3 @@
+[types]
+  cache = true
+  launch = true

acceptance/testdata/exporter/container/layers/corrupted_buildpack/corrupted-layer/data

@@ -0,0 +1 @@
+digest-not-match-data

acceptance/testdata/exporter/container/layers/group.toml

@@ -7,3 +7,8 @@
   id = "cacher_buildpack"
   version = "cacher_v1"
   api = "0.8"
+
+[[group]]
+  id = "corrupted_buildpack"
+  version = "corrupted_v1"
+  api = "0.8"

acceptance/testdata/restorer/Dockerfile

@@ -8,10 +8,10 @@ ENV CNB_GROUP_ID=${cnb_gid}
 
 COPY ./container/ /
 
-# turn /to_cache/<buildpack> directories into cache tarballs
-# these are referenced by sha in /cache/committed/io.buildpacks.lifecycle.cache.metadata
-RUN tar cvf /cache/committed/sha256:b89860e2f9c62e6b5d66d3ce019e18cdabae30273c25150b7f20a82f7a70e494.tar -C /to_cache/cacher_buildpack layers
-RUN tar cvf /cache/committed/sha256:58bafa1e79c8e44151141c95086beb37ca85b69578fc890bce33bb4c6c8e851f.tar -C /to_cache/unused_buildpack layers
+# We have to pre-create the tar files so that their digests do not change due to timestamps
+# But, ':' in the filepath on Windows is not allowed
+RUN mv /cache/committed/sha256_2d9c9c638d5c4f0df067eeae7b9c99ad05776a89d19ab863c28850a91e5f2944.tar /cache/committed/sha256:2d9c9c638d5c4f0df067eeae7b9c99ad05776a89d19ab863c28850a91e5f2944.tar
+RUN mv /cache/committed/sha256_430338f576c11e5236669f9c843599d96afe28784cffcb2d46ddb07beb00df78.tar /cache/committed/sha256:430338f576c11e5236669f9c843599d96afe28784cffcb2d46ddb07beb00df78.tar
 
 ENTRYPOINT ["/cnb/lifecycle/restorer"]
 

acceptance/testdata/restorer/container/cache/committed/io.buildpacks.lifecycle.cache.metadata

@@ -1 +1,43 @@
-{"buildpacks":[{"key":"cacher_buildpack","version":"cacher_v1","layers":{"cached-layer":{"sha":"sha256:b89860e2f9c62e6b5d66d3ce019e18cdabae30273c25150b7f20a82f7a70e494","data":null,"build":false,"launch":false,"cache":true}}},{"key":"unused_buildpack","version":"v1","layers":{"cached-layer":{"sha":"sha256:58bafa1e79c8e44151141c95086beb37ca85b69578fc890bce33bb4c6c8e851f","data":null,"build":false,"launch":false,"cache":true}}}]}
+{
+  "buildpacks": [
+    {
+      "key": "cacher_buildpack",
+      "version": "cacher_v1",
+      "layers": {
+        "cached-layer": {
+          "sha": "sha256:2d9c9c638d5c4f0df067eeae7b9c99ad05776a89d19ab863c28850a91e5f2944",
+          "data": null,
+          "build": false,
+          "launch": false,
+          "cache": true
+        }
+      }
+    },
+    {
+      "key": "corrupted_buildpack",
+      "version": "corrupted_v1",
+      "layers": {
+        "corrupted-layer": {
+          "sha": "sha256:b5bb9d8014a0f9b1d61e21e796d78dccdf1352f23cd32812f4850b878ae4944c",
+          "data": null,
+          "build": false,
+          "launch": false,
+          "cache": true
+        }
+      }
+    },
+    {
+      "key": "unused_buildpack",
+      "version": "v1",
+      "layers": {
+        "cached-layer": {
+          "sha": "sha256:430338f576c11e5236669f9c843599d96afe28784cffcb2d46ddb07beb00df78",
+          "data": null,
+          "build": false,
+          "launch": false,
+          "cache": true
+        }
+      }
+    }
+  ]
+}

acceptance/testdata/restorer/container/layers/cacher_buildpack/cached-layer.sha

@@ -1 +1 @@
-sha256:b89860e2f9c62e6b5d66d3ce019e18cdabae30273c25150b7f20a82f7a70e494
+sha256:2d9c9c638d5c4f0df067eeae7b9c99ad05776a89d19ab863c28850a91e5f2944

acceptance/testdata/restorer/container/layers/group.toml

@@ -8,6 +8,11 @@
   version = "cacher_v1"
   api = "0.10"
 
+[[group]]
+  id = "corrupted_buildpack"
+  version = "corrupted_v1"
+  api = "0.11"
+
 [[group-extensions]]
     id = "some-extension-id"
     version = "v1"

acceptance/testdata/restorer/container/to_cache/corrupted_buildpack/layers/corrupted_buildpack/corrupted-layer/data

@@ -0,0 +1 @@
+digest-not-match-data

cache/image_cache.go

@@ -158,3 +158,9 @@ func (c *ImageCache) Commit() error {
 
 	return nil
 }
+
+// VerifyLayer returns an error if the layer contents do not match the provided sha.
+func (c *ImageCache) VerifyLayer(_ string) error {
+	// we assume the registry is verifying digests for us
+	return nil
+}

cache/volume_cache.go

@@ -1,6 +1,7 @@
 package cache
 
 import (
+	"crypto/sha256"
 	"encoding/json"
 	"fmt"
 	"io"
@@ -143,11 +144,8 @@ func (c *VolumeCache) ReuseLayer(diffID string) error {
 	stagingPath := diffIDPath(c.stagingDir, diffID)
 
 	if _, err := os.Stat(committedPath); err != nil {
-		if os.IsNotExist(err) {
-			return NewReadErr(fmt.Sprintf("failed to find cache layer with SHA '%s'", diffID))
-		}
-		if os.IsPermission(err) {
-			return NewReadErr(fmt.Sprintf("failed to read cache layer with SHA '%s' due to insufficient permissions", diffID))
+		if err = handleFileError(err, diffID); errors.Is(err, ReadErr{}) {
+			return err
 		}
 		return fmt.Errorf("failed to re-use cache layer with SHA '%s': %w", diffID, err)
 	}
@@ -165,11 +163,8 @@ func (c *VolumeCache) RetrieveLayer(diffID string) (io.ReadCloser, error) {
 	}
 	file, err := os.Open(path)
 	if err != nil {
-		if os.IsPermission(err) {
-			return nil, NewReadErr(fmt.Sprintf("failed to read cache layer with SHA '%s' due to insufficient permissions", diffID))
-		}
-		if os.IsNotExist(err) {
-			return nil, NewReadErr(fmt.Sprintf("failed to find cache layer with SHA '%s'", diffID))
+		if err = handleFileError(err, diffID); errors.Is(err, ReadErr{}) {
+			return nil, err
 		}
 		return nil, fmt.Errorf("failed to get cache layer with SHA '%s'", diffID)
 	}
@@ -189,8 +184,8 @@ func (c *VolumeCache) HasLayer(diffID string) (bool, error) {
 func (c *VolumeCache) RetrieveLayerFile(diffID string) (string, error) {
 	path := diffIDPath(c.committedDir, diffID)
 	if _, err := os.Stat(path); err != nil {
-		if os.IsNotExist(err) {
-			return "", NewReadErr(fmt.Sprintf("failed to find cache layer with SHA '%s'", diffID))
+		if err = handleFileError(err, diffID); errors.Is(err, ReadErr{}) {
+			return "", err
 		}
 		return "", errors.Wrapf(err, "retrieving layer with SHA '%s'", diffID)
 	}
@@ -231,3 +226,33 @@ func (c *VolumeCache) setupStagingDir() error {
 	}
 	return os.MkdirAll(c.stagingDir, 0777)
 }
+
+// VerifyLayer returns an error if the layer contents do not match the provided sha.
+func (c *VolumeCache) VerifyLayer(diffID string) error {
+	layerRC, err := c.RetrieveLayer(diffID)
+	if err != nil {
+		return err
+	}
+	defer func() {
+		_ = layerRC.Close()
+	}()
+	hasher := sha256.New()
+	if _, err := io.Copy(hasher, layerRC); err != nil {
+		return errors.Wrap(err, "hashing layer")
+	}
+	foundDiffID := fmt.Sprintf("sha256:%x", hasher.Sum(nil))
+	if diffID != foundDiffID {
+		return NewReadErr(fmt.Sprintf("expected layer contents to have SHA '%s'; found '%s'", diffID, foundDiffID))
+	}
+	return err
+}
+
+func handleFileError(err error, diffID string) error {
+	if os.IsNotExist(err) {
+		return NewReadErr(fmt.Sprintf("failed to find cache layer with SHA '%s'", diffID))
+	}
+	if os.IsPermission(err) {
+		return NewReadErr(fmt.Sprintf("failed to read cache layer with SHA '%s' due to insufficient permissions", diffID))
+	}
+	return err
+}

cmd/lifecycle/restorer.go

@@ -119,7 +119,7 @@ func (r *restoreCmd) Exec() error {
 				return cmd.FailErr(err, "get digest reference for builder image")
 			}
 			analyzedMD.BuildImage = &files.ImageIdentifier{Reference: digestRef.String()}
-			cmd.DefaultLogger.Debugf("Adding build image info to analyzed metadata: ")
+			cmd.DefaultLogger.Debug("Adding build image info to analyzed metadata: ")
 			cmd.DefaultLogger.Debug(encoding.ToJSONMaybe(analyzedMD.BuildImage))
 		}
 		var (
@@ -187,11 +187,11 @@ func (r *restoreCmd) updateAnalyzedMD(analyzedMD *files.Analyzed, runImage imgut
 			return cmd.FailErr(err, "read target data from run image")
 		}
 	}
-	cmd.DefaultLogger.Debugf("Run image info in analyzed metadata was: ")
+	cmd.DefaultLogger.Debug("Run image info in analyzed metadata was: ")
 	cmd.DefaultLogger.Debug(encoding.ToJSONMaybe(analyzedMD.RunImage))
 	analyzedMD.RunImage.Reference = digestRef.String()
 	analyzedMD.RunImage.TargetMetadata = targetData
-	cmd.DefaultLogger.Debugf("Run image info in analyzed metadata is: ")
+	cmd.DefaultLogger.Debug("Run image info in analyzed metadata is: ")
 	cmd.DefaultLogger.Debug(encoding.ToJSONMaybe(analyzedMD.RunImage))
 	return nil
 }

phase/cache.go

@@ -99,15 +99,23 @@ func (e *Exporter) addOrReuseCacheLayer(cache Cache, layerDir LayerDir, previous
 		return "", errors.Wrapf(err, "creating layer '%s'", layerDir.Identifier())
 	}
 	if layer.Digest == previousSHA {
-		e.Logger.Infof("Reusing cache layer '%s'\n", layer.ID)
-		e.Logger.Debugf("Layer '%s' SHA: %s\n", layer.ID, layer.Digest)
-		err = cache.ReuseLayer(previousSHA)
-		if err != nil {
-			isReadErr, readErr := c.IsReadErr(err)
-			if !isReadErr {
-				return "", errors.Wrapf(err, "reusing layer %s", layer.ID)
+		if err = cache.VerifyLayer(previousSHA); err == nil {
+			e.Logger.Infof("Reusing cache layer '%s'\n", layer.ID)
+			e.Logger.Debugf("Layer '%s' SHA: %s\n", layer.ID, layer.Digest)
+			if err = cache.ReuseLayer(previousSHA); err != nil {
+				if isReadErr, readErr := c.IsReadErr(err); isReadErr {
+					// we shouldn't get here, as VerifyLayer would've returned an error
+					e.Logger.Warnf("Skipping re-use for layer %s: %s", layer.ID, readErr.Error())
+				} else {
+					return "", errors.Wrapf(err, "reusing layer %s", layer.ID)
+				}
+			}
+		} else {
+			if isReadErr, readErr := c.IsReadErr(err); isReadErr {
+				e.Logger.Warnf("Skipping reuse for layer %s: %s", layer.ID, readErr.Error())
+			} else {
+				return "", errors.Wrapf(err, "verifying layer '%s'", layerDir.Identifier())
 			}
-			e.Logger.Warnf("Skipping re-use for layer %s: %s", layer.ID, readErr.Error())
 		}
 	}
 	e.Logger.Infof("Adding cache layer '%s'\n", layer.ID)

phase/exporter.go

@@ -35,6 +35,7 @@ type Cache interface {
 	ReuseLayer(sha string) error
 	RetrieveLayer(sha string) (io.ReadCloser, error)
 	Commit() error
+	VerifyLayer(sha string) error
 }
 
 type Exporter struct {

phase/rebaser.go

@@ -202,7 +202,7 @@ func (r *Rebaser) validateTarget(appImg imgutil.Image, newBaseImg imgutil.Image)
 	}
 	if rebasable == "false" {
 		if !r.Force {
-			return fmt.Errorf("%s; %s", msgAppImageNotMarkedRebasable, msgProvideForceToOverride)
+			return errors.New(msgAppImageNotMarkedRebasable + "; " + msgProvideForceToOverride)
 		}
 		r.Logger.Warn(msgAppImageNotMarkedRebasable)
 	}

phase/restorer.go

@@ -140,6 +140,9 @@ func (r *Restorer) restoreCacheLayer(cache Cache, sha string) error {
 		return errors.New("restoring layer: cache not provided")
 	}
 	r.Logger.Debugf("Retrieving data for %q", sha)
+	if err := cache.VerifyLayer(sha); err != nil {
+		return err
+	}
 	rc, err := cache.RetrieveLayer(sha)
 	if err != nil {
 		return err