Debugging the integration testing.

It seems to be consistently failing (also fix a typo in the file/leg name).

I'm disabling `-v` for `go test` because it interleaves the test output in ways that make it painful to read a single failing test's output when `t.Parallel` is involved.

.github/workflows/integration_k8_tests.yaml

@@ -1,6 +1,6 @@
-name: Intergration tests (K8s)
+name: Integration tests (K8s)
 
-# Triggers the workflow on push or pull request events
+# Triggers the workflow on pull request events
 on: [pull_request]
 
 concurrency:

integration/benchmark_test.go

@@ -59,7 +59,7 @@ func TestSnapshotBenchmark(t *testing.T) {
  kanikoImage := fmt.Sprintf("%s_%d", GetKanikoImage(config.imageRepo, dockerfile), num)
  buildArgs := []string{"--build-arg", fmt.Sprintf("NUM=%d", num)}
  var benchmarkDir string
- benchmarkDir, *err = buildKanikoImage("", dockerfile,
+ benchmarkDir, *err = buildKanikoImage(t.Logf, "", dockerfile,
  buildArgs, []string{}, kanikoImage, contextDir, config.gcsBucket,
  config.serviceAccount, false)
  if *err != nil {
@@ -77,11 +77,11 @@ func TestSnapshotBenchmark(t *testing.T) {
  }
  wg.Wait()
 
- fmt.Println("Number of Files,Total Build Time,Walking Filesystem, Resolving Files")
+ t.Log("Number of Files,Total Build Time,Walking Filesystem, Resolving Files")
  timeMap.Range(func(key interface{}, value interface{}) bool {
  d, _ := key.(int)
  v, _ := value.(result)
- fmt.Println(fmt.Sprintf("%d,%f,%f,%f", d, v.totalBuildTime, v.walkingFiles, v.resolvingFiles))
+ t.Logf("%d,%f,%f,%f", d, v.totalBuildTime, v.walkingFiles, v.resolvingFiles)
  return true
  })
 
@@ -111,7 +111,7 @@ func newResult(t *testing.T, f string) result {
  if c, ok := current["Hashing files"]; ok {
  r.hashingFiles = c.Seconds()
  }
- fmt.Println(r)
+ t.Log(r)
  return r
 }
 
@@ -128,7 +128,7 @@ func TestSnapshotBenchmarkGcloud(t *testing.T) {
  nums := []int{10000, 50000, 100000, 200000, 300000, 500000, 700000}
 
  var wg sync.WaitGroup
- fmt.Println("Number of Files,Total Build Time,Walking Filesystem, Resolving Files")
+ t.Log("Number of Files,Total Build Time,Walking Filesystem, Resolving Files")
  for _, num := range nums {
  t.Run(fmt.Sprintf("test_benchmark_%d", num), func(t *testing.T) {
  wg.Add(1)
@@ -139,7 +139,7 @@ func TestSnapshotBenchmarkGcloud(t *testing.T) {
  return
  }
  r := newResult(t, filepath.Join(dir, "results"))
- fmt.Println(fmt.Sprintf("%d,%f,%f,%f, %f", num, r.totalBuildTime, r.walkingFiles, r.resolvingFiles, r.hashingFiles))
+ t.Log(fmt.Sprintf("%d,%f,%f,%f, %f", num, r.totalBuildTime, r.walkingFiles, r.resolvingFiles, r.hashingFiles))
  wg.Done()
  defer os.Remove(dir)
  defer os.Chdir(cwd)

integration/images.go

@@ -27,6 +27,7 @@ import (
  "runtime"
  "strconv"
  "strings"
+ "testing"
  "time"
 
  "github.com/GoogleContainerTools/kaniko/pkg/timing"
@@ -177,16 +178,22 @@ func FindDockerFiles(dockerfilesPath string) ([]string, error) {
 // DockerFileBuilder knows how to build docker files using both Kaniko and Docker and
 // keeps track of which files have been built.
 type DockerFileBuilder struct {
+ logf Logger
  // Holds all available docker files and whether or not they've been built
  filesBuilt map[string]struct{}
  DockerfilesToIgnore map[string]struct{}
  TestCacheDockerfiles map[string]struct{}
 }
 
+type Logger func(string, ...interface{})
+
 // NewDockerFileBuilder will create a DockerFileBuilder initialized with dockerfiles, which
 // it will assume are all as yet unbuilt.
-func NewDockerFileBuilder() *DockerFileBuilder {
- d := DockerFileBuilder{filesBuilt: map[string]struct{}{}}
+func NewDockerFileBuilder(logf Logger) *DockerFileBuilder {
+ d := DockerFileBuilder{
+ logf: logf,
+ filesBuilt: map[string]struct{}{},
+ }
  d.DockerfilesToIgnore = map[string]struct{}{
  "Dockerfile_test_add_404": {},
  // TODO: remove test_user_run from this when https://github.com/GoogleContainerTools/container-diff/issues/237 is fixed
@@ -218,8 +225,8 @@ func addServiceAccountFlags(flags []string, serviceAccount string) []string {
  return flags
 }
 
-func (d *DockerFileBuilder) BuildDockerImage(imageRepo, dockerfilesPath, dockerfile, contextDir string) error {
- fmt.Printf("Building image for Dockerfile %s\n", dockerfile)
+func (d *DockerFileBuilder) BuildDockerImage(t *testing.T, imageRepo, dockerfilesPath, dockerfile, contextDir string) error {
+ t.Logf("Building image for Dockerfile %s\n", dockerfile)
 
  var buildArgs []string
  buildArgFlag := "--build-arg"
@@ -252,21 +259,21 @@ func (d *DockerFileBuilder) BuildDockerImage(imageRepo, dockerfilesPath, dockerf
  if err != nil {
  return fmt.Errorf("Failed to build image %s with docker command \"%s\": %s %s", dockerImage, dockerCmd.Args, err, string(out))
  }
- fmt.Printf("Build image for Dockerfile %s as %s. docker build output: %s \n", dockerfile, dockerImage, out)
+ t.Logf("Build image for Dockerfile %s as %s. docker build output: %s \n", dockerfile, dockerImage, out)
  return nil
 }
 
 // BuildImage will build dockerfile (located at dockerfilesPath) using both kaniko and docker.
 // The resulting image will be tagged with imageRepo. If the dockerfile will be built with
 // context (i.e. it is in `buildContextTests`) the context will be pulled from gcsBucket.
-func (d *DockerFileBuilder) BuildImage(config *integrationTestConfig, dockerfilesPath, dockerfile string) error {
+func (d *DockerFileBuilder) BuildImage(t *testing.T, config *integrationTestConfig, dockerfilesPath, dockerfile string) error {
  _, ex, _, _ := runtime.Caller(0)
  cwd := filepath.Dir(ex)
 
- return d.BuildImageWithContext(config, dockerfilesPath, dockerfile, cwd)
+ return d.BuildImageWithContext(t, config, dockerfilesPath, dockerfile, cwd)
 }
 
-func (d *DockerFileBuilder) BuildImageWithContext(config *integrationTestConfig, dockerfilesPath, dockerfile, contextDir string) error {
+func (d *DockerFileBuilder) BuildImageWithContext(t *testing.T, config *integrationTestConfig, dockerfilesPath, dockerfile, contextDir string) error {
  if _, present := d.filesBuilt[dockerfile]; present {
  return nil
  }
@@ -279,7 +286,7 @@ func (d *DockerFileBuilder) BuildImageWithContext(config *integrationTestConfig,
  }
 
  timer := timing.Start(dockerfile + "_docker")
- d.BuildDockerImage(imageRepo, dockerfilesPath, dockerfile, contextDir)
+ d.BuildDockerImage(t, imageRepo, dockerfilesPath, dockerfile, contextDir)
  timing.DefaultRun.Stop(timer)
 
  contextFlag := "-c"
@@ -302,7 +309,7 @@ func (d *DockerFileBuilder) BuildImageWithContext(config *integrationTestConfig,
 
  kanikoImage := GetKanikoImage(imageRepo, dockerfile)
  timer = timing.Start(dockerfile + "_kaniko")
- if _, err := buildKanikoImage(dockerfilesPath, dockerfile, buildArgs, additionalKanikoFlags, kanikoImage,
+ if _, err := buildKanikoImage(d.logf, dockerfilesPath, dockerfile, buildArgs, additionalKanikoFlags, kanikoImage,
  contextDir, gcsBucket, serviceAccount, true); err != nil {
  return err
  }
@@ -420,6 +427,7 @@ func (d *DockerFileBuilder) buildRelativePathsImage(imageRepo, dockerfile, servi
 }
 
 func buildKanikoImage(
+ logf Logger,
  dockerfilesPath string,
  dockerfile string,
  buildArgs []string,
@@ -447,7 +455,7 @@ func buildKanikoImage(
 
  // build kaniko image
  additionalFlags := append(buildArgs, kanikoArgs...)
- fmt.Printf("Going to build image with kaniko: %s, flags: %s \n", kanikoImage, additionalFlags)
+ logf("Going to build image with kaniko: %s, flags: %s \n", kanikoImage, additionalFlags)
 
  dockerRunFlags := []string{"run", "--net=host",
  "-e", benchmarkEnv,

integration/integration_test.go

@@ -87,8 +87,8 @@ func getDockerMajorVersion() int {
  }
  return ver
 }
-func launchTests(m *testing.M) (int, error) {
 
+func launchTests(m *testing.M) (int, error) {
  if config.isGcrRepository() {
  contextFile, err := CreateIntegrationTarball()
  if err != nil {
@@ -111,7 +111,7 @@ func launchTests(m *testing.M) (int, error) {
  return 1, errors.Wrap(err, "Error while building images")
  }
 
- imageBuilder = NewDockerFileBuilder()
+ imageBuilder = NewDockerFileBuilder(log.Printf)
 
  return m.Run(), nil
 }
@@ -141,32 +141,25 @@ func buildRequiredImages() error {
  setupCommands := []struct {
  name string
  command []string
- }{
- {
- name: "Building kaniko image",
- command: []string{"docker", "build", "-t", ExecutorImage, "-f", "../deploy/Dockerfile", ".."},
- },
- {
- name: "Building cache warmer image",
- command: []string{"docker", "build", "-t", WarmerImage, "-f", "../deploy/Dockerfile_warmer", ".."},
- },
- {
- name: "Building onbuild base image",
- command: []string{"docker", "build", "-t", config.onbuildBaseImage, "-f", fmt.Sprintf("%s/Dockerfile_onbuild_base", dockerfilesPath), "."},
- },
- {
- name: "Pushing onbuild base image",
- command: []string{"docker", "push", config.onbuildBaseImage},
- },
- {
- name: "Building hardlink base image",
- command: []string{"docker", "build", "-t", config.hardlinkBaseImage, "-f", fmt.Sprintf("%s/Dockerfile_hardlink_base", dockerfilesPath), "."},
- },
- {
- name: "Pushing hardlink base image",
- command: []string{"docker", "push", config.hardlinkBaseImage},
- },
- }
+ }{{
+ name: "Building kaniko image",
+ command: []string{"docker", "build", "-t", ExecutorImage, "-f", "../deploy/Dockerfile", ".."},
+ }, {
+ name: "Building cache warmer image",
+ command: []string{"docker", "build", "-t", WarmerImage, "-f", "../deploy/Dockerfile_warmer", ".."},
+ }, {
+ name: "Building onbuild base image",
+ command: []string{"docker", "build", "-t", config.onbuildBaseImage, "-f", fmt.Sprintf("%s/Dockerfile_onbuild_base", dockerfilesPath), "."},
+ }, {
+ name: "Pushing onbuild base image",
+ command: []string{"docker", "push", config.onbuildBaseImage},
+ }, {
+ name: "Building hardlink base image",
+ command: []string{"docker", "build", "-t", config.hardlinkBaseImage, "-f", fmt.Sprintf("%s/Dockerfile_hardlink_base", dockerfilesPath), "."},
+ }, {
+ name: "Pushing hardlink base image",
+ command: []string{"docker", "push", config.hardlinkBaseImage},
+ }}
 
  for _, setupCmd := range setupCommands {
  fmt.Println(setupCmd.name)
@@ -522,7 +515,7 @@ func TestLayers(t *testing.T) {
 }
 
 func buildImage(t *testing.T, dockerfile string, imageBuilder *DockerFileBuilder) {
- if err := imageBuilder.BuildImage(config, dockerfilesPath, dockerfile); err != nil {
+ if err := imageBuilder.BuildImage(t, config, dockerfilesPath, dockerfile); err != nil {
  t.Errorf("Error building image: %s", err)
  t.FailNow()
  }

integration/integration_with_context_test.go

@@ -37,7 +37,7 @@ func TestWithContext(t *testing.T) {
  t.Fatal(err)
  }
 
- builder := NewDockerFileBuilder()
+ builder := NewDockerFileBuilder(t.Logf)
 
  for _, tdInfo := range testDirs {
  name := tdInfo.Name()
@@ -47,7 +47,7 @@ func TestWithContext(t *testing.T) {
  t.Parallel()
 
  if err := builder.BuildImageWithContext(
- config, "", name, testDir,
+ t, config, "", name, testDir,
  ); err != nil {
  t.Fatal(err)
  }

integration/k8s_test.go

@@ -46,7 +46,7 @@ func TestK8s(t *testing.T) {
  t.Fatal(err)
  }
 
- builder := NewDockerFileBuilder()
+ builder := NewDockerFileBuilder(t.Logf)
 
  for _, tdInfo := range testDirs {
  name := tdInfo.Name()
@@ -56,7 +56,7 @@ func TestK8s(t *testing.T) {
  t.Parallel()
 
  if err := builder.BuildDockerImage(
- config.imageRepo, "", name, testDir,
+ t, config.imageRepo, "", name, testDir,
  ); err != nil {
  t.Fatal(err)
  }
@@ -75,21 +75,21 @@ func TestK8s(t *testing.T) {
  t.Fatal(err)
  }
 
- fmt.Printf("Testing K8s based Kaniko building of dockerfile %s and push to %s \n",
+ t.Logf("Testing K8s based Kaniko building of dockerfile %s and push to %s \n",
  testDir, kanikoImage)
  content, err := ioutil.ReadFile(tmpfile.Name())
  if err != nil {
  log.Fatal(err)
  }
- fmt.Printf("K8s template %s:\n%s\n", tmpfile.Name(), content)
+ t.Logf("K8s template %s:\n%s\n", tmpfile.Name(), content)
 
  kubeCmd := exec.Command("kubectl", "apply", "-f", tmpfile.Name())
  RunCommand(kubeCmd, t)
 
- fmt.Printf("Waiting for K8s kaniko build job to finish: %s\n",
+ t.Logf("Waiting for K8s kaniko build job to finish: %s\n",
  "job/kaniko-test-"+job.Name)
 
- kubeWaitCmd := exec.Command("kubectl", "wait", "--for=condition=complete", "--timeout=120s",
+ kubeWaitCmd := exec.Command("kubectl", "wait", "--for=condition=complete", "--timeout=5m",
  "job/kaniko-test-"+job.Name)
  if out, errR := RunCommandWithoutTest(kubeWaitCmd); errR != nil {
  t.Log(kubeWaitCmd.Args)
@@ -100,9 +100,25 @@ func TestK8s(t *testing.T) {
  t.Error(errD)
  } else {
  t.Log(string(outD))
- t.Error(errR)
  }
- t.FailNow()
+
+ descCmd = exec.Command("kubectl", "describe", "pods", "--selector", "job-name=kaniko-test-"+job.Name)
+ outD, errD = RunCommandWithoutTest(descCmd)
+ if errD != nil {
+ t.Error(errD)
+ } else {
+ t.Log(string(outD))
+ }
+
+ logsCmd := exec.Command("kubectl", "logs", "job/kaniko-test-"+job.Name)
+ outL, errL := RunCommandWithoutTest(logsCmd)
+ if errL != nil {
+ t.Error(errL)
+ } else {
+ t.Log(string(outL))
+ }
+
+ t.Fatal(errR)
  }
 
  diff := containerDiff(t, daemonPrefix+dockerImage, kanikoImage, "--no-cache")

scripts/integration-test.sh

@@ -24,4 +24,4 @@ docker version
 echo "Running integration tests..."
 make out/executor
 make out/warmer
-go test ./integration/... -v --bucket "${GCS_BUCKET}" --repo "${IMAGE_REPO}" --timeout 50m "$@"
+go test ./integration/... --bucket "${GCS_BUCKET}" --repo "${IMAGE_REPO}" --timeout 50m "$@"