fix(build, buildah): stop builds failing when a cached layer vanishes

.github/workflows/test_daily.yml

@@ -270,8 +270,9 @@ jobs:
 
       - name: E2E tests (simple per-k8s)
         run: |
+          echo loadavg: $(cat /proc/loadavg)
           export GOCOVERDIR="$WERF_TEST_COVER_DIR"
-          task -p --yes test:e2e:simple -- --keep-going
+          task -p --yes test:e2e:simple -- --flake-attempts=2 --keep-going --timeout=110m --poll-progress-after=10m --poll-progress-interval=2m
           echo loadavg: $(cat /proc/loadavg)
 
       - name: Upload coverage artifact
@@ -288,6 +289,12 @@ jobs:
       - kind_setup
     runs-on: delivery-github-runner
     timeout-minutes: 120
+    # Native Buildah jobs share one runner host and one containers-storage; running them
+    # concurrently across PRs (and against the daily run) pushes them past the suite timeout.
+    concurrency:
+      group: buildah-e2e
+      cancel-in-progress: false
+      queue: max
     env:
       DEBIAN_FRONTEND: noninteractive
       TASK_X_REMOTE_TASKFILES: 1
@@ -308,7 +315,7 @@ jobs:
         uses: ./.github/actions/set-up-prebuilt-werf-test-binary
         with:
           coverage: "true"
-          raceDetectorEnabled: "true"
+          raceDetectorEnabled: "false"
 
       - name: Set up git config
         uses: ./.github/actions/set-up-git-config
@@ -318,8 +325,9 @@ jobs:
 
       - name: E2E tests (complex per-k8s)
         run: |
+          echo loadavg: $(cat /proc/loadavg)
           export GOCOVERDIR="$WERF_TEST_COVER_DIR"
-          task -p --yes test:e2e:complex -- --keep-going
+          task -p --yes test:e2e:complex -- --procs=6 --flake-attempts=2 --keep-going --timeout=110m --poll-progress-after=10m --poll-progress-interval=2m
           echo loadavg: $(cat /proc/loadavg)
 
       - name: Upload coverage artifact
@@ -336,6 +344,12 @@ jobs:
       - kind_setup
     runs-on: delivery-github-runner
     timeout-minutes: 120
+    # Native Buildah jobs share one runner host and one containers-storage; running them
+    # concurrently across PRs (and against the daily run) pushes them past the suite timeout.
+    concurrency:
+      group: buildah-e2e
+      cancel-in-progress: false
+      queue: max
     env:
       DEBIAN_FRONTEND: noninteractive
       TASK_X_REMOTE_TASKFILES: 1
@@ -356,7 +370,7 @@ jobs:
         uses: ./.github/actions/set-up-prebuilt-werf-test-binary
         with:
           coverage: "true"
-          raceDetectorEnabled: "true"
+          raceDetectorEnabled: "false"
 
       - name: Set up git config
         uses: ./.github/actions/set-up-git-config
@@ -366,8 +380,9 @@ jobs:
 
       - name: E2E tests (extra per-k8s)
         run: |
+          echo loadavg: $(cat /proc/loadavg)
           export GOCOVERDIR="$WERF_TEST_COVER_DIR"
-          task -p --yes test:e2e:extra -- --keep-going
+          task -p --yes test:e2e:extra -- --procs=6 --flake-attempts=2 --keep-going --timeout=110m --poll-progress-after=10m --poll-progress-interval=2m
           echo loadavg: $(cat /proc/loadavg)
 
       - name: Upload coverage artifact

.github/workflows/tests.yml

@@ -240,7 +240,8 @@ jobs:
 
       - name: E2E tests (simple)
         run: |
-          task -p --yes test:e2e:simple -- --keep-going --timeout=85m --poll-progress-after=10m --poll-progress-interval=2m
+          echo loadavg: $(cat /proc/loadavg)
+          task -p --yes test:e2e:simple -- --flake-attempts=2 --keep-going --timeout=85m --poll-progress-after=10m --poll-progress-interval=2m
           echo loadavg: $(cat /proc/loadavg)
 
   e2e_complex:
@@ -257,6 +258,12 @@ jobs:
       - kind_setup
     runs-on: delivery-github-runner
     timeout-minutes: 90
+    # Native Buildah jobs share one runner host and one containers-storage; running them
+    # concurrently across PRs (and against the daily run) pushes them past the suite timeout.
+    concurrency:
+      group: buildah-e2e
+      cancel-in-progress: false
+      queue: max
     env:
       DEBIAN_FRONTEND: noninteractive
       TASK_X_REMOTE_TASKFILES: 1
@@ -286,7 +293,8 @@ jobs:
 
       - name: E2E tests (complex)
         run: |
-          task -p --yes test:e2e:complex -- --keep-going --timeout=85m --poll-progress-after=10m --poll-progress-interval=2m
+          echo loadavg: $(cat /proc/loadavg)
+          task -p --yes test:e2e:complex -- --procs=6 --flake-attempts=2 --keep-going --timeout=85m --poll-progress-after=10m --poll-progress-interval=2m
           echo loadavg: $(cat /proc/loadavg)
 
   e2e_extra:
@@ -303,6 +311,12 @@ jobs:
       - kind_setup
     runs-on: delivery-github-runner
     timeout-minutes: 90
+    # Native Buildah jobs share one runner host and one containers-storage; running them
+    # concurrently across PRs (and against the daily run) pushes them past the suite timeout.
+    concurrency:
+      group: buildah-e2e
+      cancel-in-progress: false
+      queue: max
     env:
       DEBIAN_FRONTEND: noninteractive
       TASK_X_REMOTE_TASKFILES: 1
@@ -332,7 +346,8 @@ jobs:
 
       - name: E2E tests (extra)
         run: |
-          task -p --yes test:e2e:extra -- --keep-going --timeout=85m --poll-progress-after=10m --poll-progress-interval=2m
+          echo loadavg: $(cat /proc/loadavg)
+          task -p --yes test:e2e:extra -- --procs=6 --flake-attempts=2 --keep-going --timeout=85m --poll-progress-after=10m --poll-progress-interval=2m
           echo loadavg: $(cat /proc/loadavg)
 
   integration_git:

pkg/buildah/native_linux.go

@@ -47,6 +47,7 @@ import (
 	"go.podman.io/storage/pkg/unshare"
 
 	"github.com/werf/common-go/pkg/util"
+	"github.com/werf/logboek"
 	"github.com/werf/werf/v2/pkg/buildah/thirdparty"
 	"github.com/werf/werf/v2/pkg/container_backend/filter"
 	"github.com/werf/werf/v2/pkg/container_backend/info"
@@ -467,13 +468,27 @@ func (b *NativeBuildah) BuildFromDockerfile(ctx context.Context, dockerfile stri
 	buildOpts.ContextDirectory = opts.ContextDir
 
 	imageId, _, err := imagebuildah.BuildDockerfiles(ctx, b.Store, buildOpts, dockerfile)
+	if err != nil && !buildOpts.NoCache && isStorageRaceError(err) {
+		// imagebuildah walks every local image looking for a cache hit and
+		// fails when one of their layers is removed underneath it by another
+		// process sharing the storage. The build itself is fine; redo it
+		// without consulting the local cache.
+		logboek.Context(ctx).Warn().LogF("Local image cache lookup hit a layer that no longer exists, rebuilding without cache: %s\n", err)
+		buildOpts.NoCache = true
+		buildOpts.Out, buildOpts.Err, stderrBuf = generateStdoutStderr(opts.LogWriter, nil, nil)
+		imageId, _, err = imagebuildah.BuildDockerfiles(ctx, b.Store, buildOpts, dockerfile)
+	}
 	if err != nil {
 		return "", wrapStderrError(fmt.Sprintf("unable to build Dockerfile %q", dockerfile), stderrBuf, err)
 	}
 
 	return imageId, nil
 }
 
+func isStorageRaceError(err error) bool {
+	return errors.Is(err, storage.ErrLayerUnknown)
+}
+
 func (b *NativeBuildah) Mount(ctx context.Context, container string, opts MountOpts) (string, error) {
 	builder, err := b.openContainerBuilder(ctx, container)
 	if err != nil {

pkg/buildah/native_linux_test.go

@@ -14,6 +14,7 @@ import (
 	. "github.com/onsi/ginkgo/v2"
 	. "github.com/onsi/gomega"
 	"github.com/opencontainers/runtime-spec/specs-go"
+	"go.podman.io/storage"
 
 	"github.com/werf/common-go/pkg/util"
 )
@@ -39,6 +40,19 @@ var _ = Describe("buildah", func() {
 		),
 	)
 
+	DescribeTable("isStorageRaceError",
+		func(err error, expected bool) {
+			Expect(isStorageRaceError(err)).To(Equal(expected))
+		},
+		Entry("nil", nil, false),
+		Entry("unrelated error", errors.New("boom"), false),
+		Entry("layer unknown", storage.ErrLayerUnknown, true),
+		Entry("image unknown is a genuine lookup failure, not a race", storage.ErrImageUnknown, false),
+		Entry("wrapped layer unknown, as imagebuildah returns it",
+			fmt.Errorf("checking if cached image exists from a previous build: %w", fmt.Errorf("getting top layer info: %w", storage.ErrLayerUnknown)),
+			true),
+	)
+
 	Describe("generateStdoutStderr", func() {
 		It("should read stderr while it is written", func() {
 			_, stderr, stderrBuf := generateStdoutStderr(nil, nil, nil)

test/e2e/build/suite_test.go

@@ -39,6 +39,7 @@ var (
 	_ = SuiteData.SetupWerfBinary(suite_init.NewWerfBinaryData(SuiteData.SynchronizedSuiteCallbacksData))
 	_ = SuiteData.SetupProjectName(suite_init.NewProjectNameData(SuiteData.StubsData))
 	_ = SuiteData.SetupTmp(suite_init.NewTmpDirData())
+	_ = SuiteData.SetupContainersStorage(suite_init.NewContainersStorageData(SuiteData.SynchronizedSuiteCallbacksData))
 
 	_ = SuiteData.AppendSynchronizedBeforeSuiteAllNodesFunc(func(ctx context.Context, _ []byte) {
 		SuiteData.TempFiles = append([]string{}, utils.CreateTmpFileInHome("secret_file_in_home", "secret"))

test/e2e/kube-run/simple_test.go

@@ -94,6 +94,7 @@ var _ = Describe("Simple kube-run", Label("e2e", "kube-run", "simple"), func() {
 					ShouldFail:            true,
 					ExtraArgs:             []string{}, // be able to work without "-it" options
 					CancelOnOutput:        "Looping ...",
+					CancelOnOutputAfter:   "Executing into pod",
 					CancelOnOutputTimeout: time.Minute,
 				},
 			},
@@ -102,7 +103,7 @@ var _ = Describe("Simple kube-run", Label("e2e", "kube-run", "simple"), func() {
 				Expect(out).To(ContainSubstring("Signal handled"))   // from script
 				Expect(out).To(ContainSubstring("Script completed")) // from script
 			},
-			SpecTimeout(time.Minute*3),
+			SpecTimeout(time.Minute*10),
 		),
 	)
 
@@ -198,6 +199,7 @@ var _ = Describe("Simple kube-run", Label("e2e", "kube-run", "simple"), func() {
 					ShouldFail:            true,
 					ExtraArgs:             []string{}, // be able to work without "-it" options
 					CancelOnOutput:        "Looping ...",
+					CancelOnOutputAfter:   "Executing into pod",
 					CancelOnOutputTimeout: time.Minute,
 				},
 			},
@@ -206,7 +208,7 @@ var _ = Describe("Simple kube-run", Label("e2e", "kube-run", "simple"), func() {
 				Expect(out).To(ContainSubstring("Signal handled"))   // from script
 				Expect(out).To(ContainSubstring("Script completed")) // from script
 			},
-			SpecTimeout(time.Minute*3),
+			SpecTimeout(time.Minute*10),
 		),
 	)
 })

test/pkg/contback/buildah.go

@@ -96,16 +96,19 @@ func (r *NativeBuildahBackend) SaveImageToStream(ctx context.Context, image stri
 }
 
 // RmiByRepoRef removes every local image tagged under repoRef from the containers storage.
+// An image that disappears between listing and removal is not an error: a sibling spec
+// sharing the storage may have removed it first.
 func (r *NativeBuildahBackend) RmiByRepoRef(ctx context.Context, repoRef string) {
-	listArgs := append(append([]string{}, r.CommonCliArgs...), "images", "--format", "{{.Name}}:{{.Tag}}")
+	listArgs := append(append([]string{}, r.CommonCliArgs...), "images", "--filter", "reference="+repoRef+":*", "--format", "{{.Name}}:{{.Tag}}")
 	output := utils.SucceedCommandOutputString(ctx, "/", "buildah", listArgs...)
 
 	for _, ref := range strings.Fields(output) {
-		if !strings.HasPrefix(ref, repoRef+":") {
+		rmiArgs := append(append([]string{}, r.CommonCliArgs...), "rmi", "--force", ref)
+		rmiOut, err := utils.RunCommand(ctx, "/", "buildah", rmiArgs...)
+		if err != nil && strings.Contains(string(rmiOut), "image not known") {
 			continue
 		}
-		rmiArgs := append(append([]string{}, r.CommonCliArgs...), "rmi", "--force", ref)
-		utils.RunSucceedCommand(ctx, "/", "buildah", rmiArgs...)
+		Expect(err).NotTo(HaveOccurred(), string(rmiOut))
 	}
 }
 

test/pkg/suite_init/containers_storage_data.go

@@ -0,0 +1,56 @@
+package suite_init
+
+import (
+	"context"
+	"os"
+	"path/filepath"
+	"runtime"
+
+	. "github.com/onsi/gomega"
+
+	"github.com/werf/werf/v2/test/pkg/utils"
+)
+
+// ContainersStorageData gives every ginkgo process its own rootless
+// containers-storage. Native Buildah resolves the graph root from
+// XDG_DATA_HOME and the run root from XDG_RUNTIME_DIR, so without this every
+// parallel spec on the host shares one image graph and races on it.
+type ContainersStorageData struct {
+	Dir string
+}
+
+func NewContainersStorageData(callbacks *SynchronizedSuiteCallbacksData) *ContainersStorageData {
+	data := &ContainersStorageData{}
+
+	callbacks.AppendSynchronizedBeforeSuiteAllNodesFunc(func(_ context.Context, _ []byte) {
+		if runtime.GOOS != "linux" {
+			return
+		}
+
+		// Under $HOME rather than $TMPDIR: the latter is often tmpfs, and the
+		// overlay driver choice depends on the filesystem the graph lives on.
+		home, err := os.UserHomeDir()
+		Expect(err).NotTo(HaveOccurred())
+
+		data.Dir, err = os.MkdirTemp(home, ".werf-test-containers-storage-*")
+		Expect(err).NotTo(HaveOccurred())
+
+		dataHome := filepath.Join(data.Dir, "share")
+		runtimeDir := filepath.Join(data.Dir, "run")
+		Expect(os.Mkdir(dataHome, 0o755)).To(Succeed())
+		Expect(os.Mkdir(runtimeDir, 0o700)).To(Succeed())
+		Expect(os.Setenv("XDG_DATA_HOME", dataHome)).To(Succeed())
+		Expect(os.Setenv("XDG_RUNTIME_DIR", runtimeDir)).To(Succeed())
+	})
+
+	callbacks.AppendSynchronizedAfterSuiteAllNodesFunc(func(ctx context.Context) {
+		if data.Dir == "" {
+			return
+		}
+		// Rootless storage holds files owned by mapped sub-UIDs, which a plain
+		// RemoveAll from the parent process cannot delete.
+		utils.RunSucceedCommand(ctx, "", "buildah", "unshare", "rm", "-rf", data.Dir)
+	})
+
+	return data
+}

test/pkg/suite_init/suite_data.go

@@ -19,6 +19,7 @@ type SuiteData struct {
 	*TmpDirData
 	*WerfInitData
 	*ContainerRegistryPerImplementationData
+	*ContainersStorageData
 }
 
 func (data *SuiteData) SetupStubs(setupData *StubsData) bool {
@@ -61,6 +62,11 @@ func (data *SuiteData) SetupContainerRegistryPerImplementation(setupData *Contai
 	return true
 }
 
+func (data *SuiteData) SetupContainersStorage(setupData *ContainersStorageData) bool {
+	data.ContainersStorageData = setupData
+	return true
+}
+
 func (data *SuiteData) GetTestRepoPath(dirname string) string {
 	testReposDir := filepath.Join(data.TestDirPath, "repos")
 	Expect(os.MkdirAll(testReposDir, os.ModePerm)).To(Succeed())