diff --git a/.github/workflows/test_daily.yml b/.github/workflows/test_daily.yml index 9c10fb666e..64a969652a 100644 --- a/.github/workflows/test_daily.yml +++ b/.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 diff --git a/.github/workflows/tests.yml b/.github/workflows/tests.yml index cbbf624a64..1fc8668492 100644 --- a/.github/workflows/tests.yml +++ b/.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: diff --git a/pkg/buildah/native_linux.go b/pkg/buildah/native_linux.go index 5d4667dac3..e71e5c0e53 100644 --- a/pkg/buildah/native_linux.go +++ b/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,6 +468,16 @@ 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) } @@ -474,6 +485,10 @@ func (b *NativeBuildah) BuildFromDockerfile(ctx context.Context, dockerfile stri 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 { diff --git a/pkg/buildah/native_linux_test.go b/pkg/buildah/native_linux_test.go index 03eceeba71..499d1e8ae9 100644 --- a/pkg/buildah/native_linux_test.go +++ b/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) diff --git a/test/e2e/build/suite_test.go b/test/e2e/build/suite_test.go index b30f6ea33c..7c17d7d93a 100644 --- a/test/e2e/build/suite_test.go +++ b/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")) diff --git a/test/e2e/kube-run/simple_test.go b/test/e2e/kube-run/simple_test.go index 83ab5665e3..95815564bf 100644 --- a/test/e2e/kube-run/simple_test.go +++ b/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), ), ) }) diff --git a/test/pkg/contback/buildah.go b/test/pkg/contback/buildah.go index e8d787db17..65ec035798 100644 --- a/test/pkg/contback/buildah.go +++ b/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)) } } diff --git a/test/pkg/suite_init/containers_storage_data.go b/test/pkg/suite_init/containers_storage_data.go new file mode 100644 index 0000000000..8aa2b25bdc --- /dev/null +++ b/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 +} diff --git a/test/pkg/suite_init/suite_data.go b/test/pkg/suite_init/suite_data.go index 6276dabc31..a6d978f2a9 100644 --- a/test/pkg/suite_init/suite_data.go +++ b/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()) diff --git a/test/pkg/utils/command.go b/test/pkg/utils/command.go index bf2c0ce044..27760b2703 100644 --- a/test/pkg/utils/command.go +++ b/test/pkg/utils/command.go @@ -37,7 +37,12 @@ type RunCommandOptions struct { ShouldSucceed bool NoStderr bool + // CancelOnOutput cancels the command once this substring appears in its output. + // The wait is bounded by CancelOnOutputTimeout, counted from the moment + // CancelOnOutputAfter appears (or from start when it is empty); the wait for + // CancelOnOutputAfter itself is bounded only by ctx. CancelOnOutput string + CancelOnOutputAfter string CancelOnOutputTimeout time.Duration } @@ -55,7 +60,7 @@ func RunCommandWithOptions(ctx context.Context, dir, command string, args []stri cmd.Stdin = bytes.NewReader([]byte(options.ToStdin)) } - res := newCommandOutput(options.CancelOnOutput) + res := newCommandOutput(options.CancelOnOutput, options.CancelOnOutputAfter) cmd.Stdout = res if !options.NoStderr { cmd.Stderr = res @@ -64,15 +69,21 @@ func RunCommandWithOptions(ctx context.Context, dir, command string, args []stri Expect(cmd.Start()).To(Succeed()) if options.CancelOnOutput != "" { - res.waitForOutput(options.CancelOnOutputTimeout) - Expect(cmd.Cancel()).To(Succeed()) + if options.CancelOnOutputAfter != "" { + select { + case <-res.cancelWindowOpened: + case <-ctx.Done(): + } + } + if ctx.Err() == nil { + res.waitForOutput(options.CancelOnOutputTimeout) + Expect(cmd.Cancel()).To(Succeed()) + } } err := cmd.Wait() output := res.Bytes() - _, _ = GinkgoWriter.Write(output) - if options.ShouldSucceed { errorDesc := fmt.Sprintf("%[2]s %[3]s (dir: %[1]s)", dir, command, strings.Join(args, " ")) Expect(err).ShouldNot(HaveOccurred(), errorDesc) @@ -82,19 +93,24 @@ func RunCommandWithOptions(ctx context.Context, dir, command string, args []stri } type commandOutput struct { - mux sync.Mutex - buffer bytes.Buffer - cancelOnOutput string - outputDetected chan struct{} - outputOnce sync.Once + mux sync.Mutex + buffer bytes.Buffer + cancelOnOutput string + cancelAfter string + outputDetected chan struct{} + outputOnce sync.Once + cancelWindowOpened chan struct{} + cancelWindowOnce sync.Once } var _ io.Writer = (*commandOutput)(nil) -func newCommandOutput(cancelOnOutput string) *commandOutput { +func newCommandOutput(cancelOnOutput, cancelAfter string) *commandOutput { return &commandOutput{ - cancelOnOutput: cancelOnOutput, - outputDetected: make(chan struct{}), + cancelOnOutput: cancelOnOutput, + cancelAfter: cancelAfter, + outputDetected: make(chan struct{}), + cancelWindowOpened: make(chan struct{}), } } @@ -103,6 +119,12 @@ func (output *commandOutput) Write(p []byte) (int, error) { defer output.mux.Unlock() n, err := output.buffer.Write(p) + _, _ = GinkgoWriter.Write(p[:n]) + if output.cancelAfter != "" && bytes.Contains(output.buffer.Bytes(), []byte(output.cancelAfter)) { + output.cancelWindowOnce.Do(func() { + close(output.cancelWindowOpened) + }) + } if output.cancelOnOutput != "" && bytes.Contains(output.buffer.Bytes(), []byte(output.cancelOnOutput)) { output.outputOnce.Do(func() { close(output.outputDetected) diff --git a/test/pkg/utils/command_test.go b/test/pkg/utils/command_test.go index b3829b9cf0..645cf17757 100644 --- a/test/pkg/utils/command_test.go +++ b/test/pkg/utils/command_test.go @@ -7,6 +7,7 @@ import ( . "github.com/onsi/ginkgo/v2" . "github.com/onsi/gomega" + "github.com/onsi/gomega/gbytes" ) func TestUtils(t *testing.T) { @@ -24,4 +25,43 @@ var _ = Describe("RunCommandWithOptions", func() { Expect(err).NotTo(HaveOccurred()) Expect(string(output)).To(ContainSubstring("done")) }) + + It("forwards output to GinkgoWriter while the command is still running", func() { + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + + tee := gbytes.NewBuffer() + GinkgoWriter.TeeTo(tee) + DeferCleanup(GinkgoWriter.ClearTeeWriters) + + done := make(chan struct{}) + go func() { + defer GinkgoRecover() + defer close(done) + _, _ = RunCommandWithOptions(ctx, "", "sh", []string{"-c", "printf early; sleep 3"}, RunCommandOptions{}) + }() + + Eventually(tee, 2*time.Second).Should(gbytes.Say("early")) + Expect(done).NotTo(BeClosed()) + + Eventually(done, 5*time.Second).Should(BeClosed()) + }) + + It("starts the cancel timeout only after CancelOnOutputAfter appears", func() { + ctx, cancel := context.WithTimeout(context.Background(), 10*time.Second) + defer cancel() + + start := time.Now() + output, err := RunCommandWithOptions(ctx, "", "sh", []string{"-c", "sleep 2; echo ready; exec sleep 30"}, RunCommandOptions{ + CancelOnOutput: "late", + CancelOnOutputAfter: "ready", + CancelOnOutputTimeout: time.Second, + }) + + Expect(err).To(HaveOccurred()) + Expect(string(output)).To(ContainSubstring("ready")) + Expect(string(output)).NotTo(ContainSubstring("late")) + Expect(time.Since(start)).To(BeNumerically(">=", 3*time.Second)) + Expect(time.Since(start)).To(BeNumerically("<", 8*time.Second)) + }) }) diff --git a/test/pkg/werf/options.go b/test/pkg/werf/options.go index 339b952906..b4b58dcd03 100644 --- a/test/pkg/werf/options.go +++ b/test/pkg/werf/options.go @@ -8,6 +8,7 @@ type CommonOptions struct { Envs []string CancelOnOutput string + CancelOnOutputAfter string CancelOnOutputTimeout time.Duration } diff --git a/test/pkg/werf/project.go b/test/pkg/werf/project.go index cea0020de5..83b068cdf2 100644 --- a/test/pkg/werf/project.go +++ b/test/pkg/werf/project.go @@ -55,6 +55,7 @@ func (p *Project) BuildWithErr(ctx context.Context, opts *BuildOptions) (combine ShouldSucceed: false, ExtraEnv: opts.Envs, CancelOnOutput: opts.CancelOnOutput, + CancelOnOutputAfter: opts.CancelOnOutputAfter, CancelOnOutputTimeout: opts.CancelOnOutputTimeout, }) @@ -193,6 +194,7 @@ func (p *Project) RunCommand( ShouldSucceed: !opts.ShouldFail, ExtraEnv: opts.Envs, CancelOnOutput: opts.CancelOnOutput, + CancelOnOutputAfter: opts.CancelOnOutputAfter, CancelOnOutputTimeout: opts.CancelOnOutputTimeout, }) return string(outb) @@ -290,6 +292,7 @@ func (p *Project) SbomValidateWithErr(ctx context.Context, opts *SbomValidateOpt ShouldSucceed: false, ExtraEnv: opts.Envs, CancelOnOutput: opts.CancelOnOutput, + CancelOnOutputAfter: opts.CancelOnOutputAfter, CancelOnOutputTimeout: opts.CancelOnOutputTimeout, })