From f2c3d59166dcddde8158af386bdbef511d5e9f42 Mon Sep 17 00:00:00 2001 From: gabemontero Date: Thu, 21 Apr 2016 14:10:39 -0400 Subject: [PATCH] more catching of build errors, dump of logs, etc.; add registry pod disk usage analysis --- test/extended/builds/docker_pullsecret.go | 8 +++- test/extended/builds/image_source.go | 3 ++ test/extended/builds/labels.go | 8 +++- test/extended/builds/secrets.go | 15 +++---- test/extended/builds/start.go | 50 +++++++++++++---------- test/extended/images/sample_repos.go | 2 +- test/extended/util/framework.go | 49 +++++++++++++++++++--- 7 files changed, 96 insertions(+), 39 deletions(-) diff --git a/test/extended/builds/docker_pullsecret.go b/test/extended/builds/docker_pullsecret.go index 119a86ba1424..98562fa1d3db 100644 --- a/test/extended/builds/docker_pullsecret.go +++ b/test/extended/builds/docker_pullsecret.go @@ -44,7 +44,9 @@ var _ = g.Describe("[builds][pullsecret][Conformance] docker build using a pull g.By("expecting the build succeeds") err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "docker-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) if err != nil { - logs, _ := oc.Run("build-logs").Args("docker-build-1").Output() + logs, _ := oc.Run("logs").Args("-f", "bc/docker-build").Output() + exutil.ExamineDiskUsage() + exutil.ExaminePodDiskUsage(oc) e2e.Failf("build failed: %s", logs) } @@ -55,7 +57,9 @@ var _ = g.Describe("[builds][pullsecret][Conformance] docker build using a pull g.By("expecting the build succeeds") err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "docker-build-pull-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) if err != nil { - logs, _ := oc.Run("build-logs").Args("docker-build-pull-1").Output() + logs, _ := oc.Run("logs").Args("-f", "bc/docker-build-pull").Output() + exutil.ExamineDiskUsage() + exutil.ExaminePodDiskUsage(oc) e2e.Failf("build failed: %s", logs) } }) diff --git a/test/extended/builds/image_source.go b/test/extended/builds/image_source.go index b9c53c326f30..732878739209 100644 --- a/test/extended/builds/image_source.go +++ b/test/extended/builds/image_source.go @@ -66,6 +66,9 @@ var _ = g.Describe("[builds][Slow] build can have Docker image source", func() { o.Expect(err).NotTo(o.HaveOccurred()) g.By("expect the builds to complete successfully") err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "imagedockerbuild-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("imagedockerbuild", oc) + } o.Expect(err).NotTo(o.HaveOccurred()) g.By("expect the pod to deploy successfully") diff --git a/test/extended/builds/labels.go b/test/extended/builds/labels.go index 7a065ba00fc1..d30ece6a55a9 100644 --- a/test/extended/builds/labels.go +++ b/test/extended/builds/labels.go @@ -46,7 +46,9 @@ var _ = g.Describe("[builds][Slow] result image should have proper labels set", g.By("o.Expecting the S2I build is in Complete phase") err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), buildName, exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) if err != nil { - logs, _ := oc.Run("build-logs").Args(buildName).Output() + logs, _ := oc.Run("logs").Args("-f", "bc/test").Output() + exutil.ExamineDiskUsage() + exutil.ExaminePodDiskUsage(oc) e2e.Failf("build failed: %s", logs) } @@ -82,7 +84,9 @@ var _ = g.Describe("[builds][Slow] result image should have proper labels set", g.By("o.Expecting the Docker build is in Complete phase") err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), buildName, exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) if err != nil { - logs, _ := oc.Run("build-logs").Args(buildName).Output() + logs, _ := oc.Run("logs").Args("-f", "bc/test").Output() + exutil.ExamineDiskUsage() + exutil.ExaminePodDiskUsage(oc) e2e.Failf("build failed: %s", logs) } diff --git a/test/extended/builds/secrets.go b/test/extended/builds/secrets.go index c1f826072099..1b45eb2719d0 100644 --- a/test/extended/builds/secrets.go +++ b/test/extended/builds/secrets.go @@ -6,7 +6,6 @@ import ( g "github.com/onsi/ginkgo" o "github.com/onsi/gomega" - buildapi "github.com/openshift/origin/pkg/build/api" exutil "github.com/openshift/origin/test/extended/util" kapi "k8s.io/kubernetes/pkg/api" ) @@ -49,9 +48,10 @@ var _ = g.Describe("[builds][Slow] can use build secrets", func() { o.Expect(out).To(o.ContainSubstring("relative-secret3=secret3")) g.By("checking the status of the build") - build, err := oc.REST().Builds(oc.Namespace()).Get("test-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "test-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("test", oc) + } g.By("getting the image name") image, err := exutil.GetDockerImageReference(oc.REST().ImageStreams(oc.Namespace()), "test", "latest") @@ -86,9 +86,10 @@ var _ = g.Describe("[builds][Slow] can use build secrets", func() { o.Expect(out).To(o.ContainSubstring("relative-secret2=secret2")) g.By("checking the status of the build") - build, err := oc.REST().Builds(oc.Namespace()).Get("test-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "test-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("test", oc) + } }) }) diff --git a/test/extended/builds/start.go b/test/extended/builds/start.go index 31a6c92dbb27..26b3c01f5df6 100644 --- a/test/extended/builds/start.go +++ b/test/extended/builds/start.go @@ -10,7 +10,6 @@ import ( g "github.com/onsi/ginkgo" o "github.com/onsi/gomega" - buildapi "github.com/openshift/origin/pkg/build/api" exutil "github.com/openshift/origin/test/extended/util" ) @@ -37,9 +36,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { o.Expect(err).NotTo(o.HaveOccurred()) g.By(fmt.Sprintf("verifying the build %q status", out)) - build, err := oc.REST().Builds(oc.Namespace()).Get(out) - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) g.It("should start a build and wait for the build to fail", func() { @@ -64,9 +64,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { o.Expect(out).To(o.ContainSubstring("BAR=test")) o.Expect(out).To(o.ContainSubstring("VAR=test")) g.By(fmt.Sprintf("verifying the build %q status", out)) - build, err := oc.REST().Builds(oc.Namespace()).Get("sample-build-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) g.It("should allow to change build log level", func() { @@ -76,9 +77,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { g.By(fmt.Sprintf("verifying the build output is not verbose")) o.Expect(out).NotTo(o.ContainSubstring("Creating a new S2I builder")) g.By(fmt.Sprintf("verifying the build %q status", out)) - build, err := oc.REST().Builds(oc.Namespace()).Get("sample-build-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) }) @@ -92,9 +94,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { o.Expect(out).To(o.ContainSubstring("as binary input for the build ...")) o.Expect(out).To(o.ContainSubstring("Your bundle is complete")) - build, err := oc.REST().Builds(oc.Namespace()).Get("sample-build-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) g.It("should accept --from-dir as input", func() { @@ -106,9 +109,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { o.Expect(out).To(o.ContainSubstring("as binary input for the build ...")) o.Expect(out).To(o.ContainSubstring("Your bundle is complete")) - build, err := oc.REST().Builds(oc.Namespace()).Get("sample-build-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) g.It("should accept --from-repo as input", func() { @@ -121,9 +125,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { o.Expect(out).To(o.ContainSubstring("as binary input for the build ...")) o.Expect(out).To(o.ContainSubstring("Your bundle is complete")) - build, err := oc.REST().Builds(oc.Namespace()).Get("sample-build-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) g.It("should accept --from-repo with --commit as input", func() { @@ -139,9 +144,10 @@ var _ = g.Describe("[builds][Slow] starting a build using CLI", func() { o.Expect(out).To(o.ContainSubstring("as binary input for the build ...")) o.Expect(out).To(o.ContainSubstring("Your bundle is complete")) - build, err := oc.REST().Builds(oc.Namespace()).Get("sample-build-1") - o.Expect(err).NotTo(o.HaveOccurred()) - o.Expect(build.Status.Phase).Should(o.BeEquivalentTo(buildapi.BuildPhaseComplete)) + err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), "sample-build-1", exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) + if err != nil { + exutil.DumpBuildLogs("sample-build", oc) + } }) }) diff --git a/test/extended/images/sample_repos.go b/test/extended/images/sample_repos.go index 85be29ed2e08..d8140bdb724a 100644 --- a/test/extended/images/sample_repos.go +++ b/test/extended/images/sample_repos.go @@ -50,7 +50,7 @@ func NewSampleRepoTest(c SampleRepoConfig) func() { g.By("expecting the build is in the Complete phase") err = exutil.WaitForABuild(oc.REST().Builds(oc.Namespace()), buildName, exutil.CheckBuildSuccessFn, exutil.CheckBuildFailedFn) if err != nil { - logs, _ := oc.Run("build-logs").Args(buildName).Output() + logs, _ := oc.Run("logs").Args("-f", "bc/"+c.buildConfigName).Output() e2e.Failf("build failed: %s", logs) } diff --git a/test/extended/util/framework.go b/test/extended/util/framework.go index ab1fbc27a5a7..25148adde76a 100644 --- a/test/extended/util/framework.go +++ b/test/extended/util/framework.go @@ -1,6 +1,7 @@ package util import ( + "encoding/json" "fmt" "io/ioutil" "net/http" @@ -49,9 +50,10 @@ func DumpBuildLogs(bc string, oc *CLI) { } ExamineDiskUsage() + ExaminePodDiskUsage(oc) } -// ExamineDiskUsage will dump some df/du output; leveraging this as part of diagnosing +// ExamineDiskUsage will dump df output on the testing system; leveraging this as part of diagnosing // the registry's disk filling up during external tests on jenkins func ExamineDiskUsage() { out, err := exec.Command("/bin/df", "-k").Output() @@ -60,13 +62,50 @@ func ExamineDiskUsage() { } else { fmt.Fprintf(g.GinkgoWriter, "\n\n got error on df %v\n\n", err) } - if _, err := os.Stat("/registry"); err == nil { - out, err = exec.Command("/bin/du", "-a", "/registry").Output() +} + +// ExaminePodDiskUsage will dump df/du output on registry pod; leveraging this as part of diagnosing +// the registry's disk filling up during external tests on jenkins +func ExaminePodDiskUsage(oc *CLI) { + out, err := oc.Run("get").Args("pods", "-o", "json", "-n", "default", "--config", KubeConfigPath()).Output() + var podName string + if err == nil { + b := []byte(out) + var list kapi.PodList + err = json.Unmarshal(b, &list) if err == nil { - fmt.Fprintf(g.GinkgoWriter, "\n\n du -a /registry output: %s\n\n", string(out)) + for _, pod := range list.Items { + fmt.Fprintf(g.GinkgoWriter, "\n\n looking at pod %s \n\n", pod.ObjectMeta.Name) + if strings.Contains(pod.ObjectMeta.Name, "docker-registry-") && !strings.Contains(pod.ObjectMeta.Name, "deploy") { + podName = pod.ObjectMeta.Name + break + } + } } else { - fmt.Fprintf(g.GinkgoWriter, "\n\n got error on df %v\n\n", err) + fmt.Fprintf(g.GinkgoWriter, "\n\n got json unmarshal err: %v\n\n", err) } + } else { + fmt.Fprintf(g.GinkgoWriter, "\n\n got error on get pods: %v\n\n", err) + } + + out, err = oc.Run("get").Args("pods", "-n", "default", "--config", KubeConfigPath()).Output() + if err == nil { + fmt.Fprintf(g.GinkgoWriter, "\n\n pods compact list: \n%s\n\n", out) + } else { + fmt.Fprintf(g.GinkgoWriter, "\n\n got error on get pods : %v\n", err) + } + + out, err = oc.Run("exec").Args("-n", "default", podName, "df", "--config", KubeConfigPath()).Output() + if err == nil { + fmt.Fprintf(g.GinkgoWriter, "\n\n df from registry pod: \n%s\n\n", out) + } else { + fmt.Fprintf(g.GinkgoWriter, "\n\n got error on reg pod df: %v\n", err) + } + out, err = oc.Run("exec").Args("-n", "default", podName, "du", "/registry", "--config", KubeConfigPath()).Output() + if err == nil { + fmt.Fprintf(g.GinkgoWriter, "\n\n du from registry pod: \n%s\n\n", out) + } else { + fmt.Fprintf(g.GinkgoWriter, "\n\n got error on reg pod du: %v\n", err) } }