From cc0262ef55cbae4e0403943c7ae6b0068be2cb80 Mon Sep 17 00:00:00 2001 From: Medya Gh Date: Wed, 25 Mar 2020 19:58:38 -0700 Subject: [PATCH] improve logging and fix some not logged errors --- test/integration/aaa_download_only_test.go | 18 +++--- test/integration/addons_test.go | 68 +++++++++++----------- test/integration/functional_test.go | 36 ++++++------ test/integration/version_upgrade_test.go | 4 +- 4 files changed, 63 insertions(+), 63 deletions(-) diff --git a/test/integration/aaa_download_only_test.go b/test/integration/aaa_download_only_test.go index 8be373a5dd..cf6239cd9c 100644 --- a/test/integration/aaa_download_only_test.go +++ b/test/integration/aaa_download_only_test.go @@ -67,7 +67,7 @@ func TestDownloadOnly(t *testing.T) { } if err != nil { - t.Errorf("%s failed: %v", args, err) + t.Errorf("failed to download only. args: %q %v", args, err) } // skip for none, as none driver does not have preload feature. @@ -75,14 +75,14 @@ func TestDownloadOnly(t *testing.T) { if download.PreloadExists(v, r) { // Just make sure the tarball path exists if _, err := os.Stat(download.TarballPath(v)); err != nil { - t.Errorf("preloaded tarball path doesn't exist: %v", err) + t.Errorf("failed to verify preloaded tarball file exists: %v", err) } return } } imgs, err := images.Kubeadm("", v) if err != nil { - t.Errorf("kubeadm images: %v %+v", v, err) + t.Errorf("failed to get kubeadm images for %v: %+v", v, err) } // skip verify for cache images if --driver=none @@ -129,7 +129,7 @@ func TestDownloadOnly(t *testing.T) { } rr, err := Run(t, exec.CommandContext(ctx, Target(), "delete", "--all")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to delete all. args: %q : %v", rr.Args, err) } }) // Delete should always succeed, even if previously partially or fully deleted. @@ -139,7 +139,7 @@ func TestDownloadOnly(t *testing.T) { } rr, err := Run(t, exec.CommandContext(ctx, Target(), "delete", "-p", profile)) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to delete. args: %q: %v", rr.Args, err) } }) }) @@ -158,22 +158,22 @@ func TestDownloadOnlyKic(t *testing.T) { args = append(args, StartArgs()...) rr, err := Run(t, exec.CommandContext(ctx, Target(), args...)) if err != nil { - t.Errorf("%s failed: %v:\n%s", args, err, rr.Output()) + t.Errorf("start with download only failed %q : %v:\n%s", args, err) } // Make sure the downloaded image tarball exists tarball := download.TarballPath(constants.DefaultKubernetesVersion) contents, err := ioutil.ReadFile(tarball) if err != nil { - t.Errorf("reading tarball: %v", err) + t.Errorf("failed to read tarball file %q: %v", tarball, err) } // Make sure it has the correct checksum checksum := md5.Sum(contents) remoteChecksum, err := ioutil.ReadFile(download.PreloadChecksumPath(constants.DefaultKubernetesVersion)) if err != nil { - t.Errorf("reading checksum file: %v", err) + t.Errorf("failed to read checksum file %q : %v", download.PreloadChecksumPath(constants.DefaultKubernetesVersion), err) } if string(remoteChecksum) != string(checksum[:]) { - t.Errorf("checksum of %s does not match remote checksum (%s != %s)", tarball, string(remoteChecksum), string(checksum[:])) + t.Errorf("failed to verify checksum. checksum of %q does not match remote checksum (%q != %q)", tarball, string(remoteChecksum), string(checksum[:])) } } diff --git a/test/integration/addons_test.go b/test/integration/addons_test.go index 3e001cd072..43ad112651 100644 --- a/test/integration/addons_test.go +++ b/test/integration/addons_test.go @@ -69,15 +69,15 @@ func TestAddons(t *testing.T) { // Assert that disable/enable works offline rr, err = Run(t, exec.CommandContext(ctx, Target(), "stop", "-p", profile)) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to stop minikube. args %q : %v", rr.Args, err) } rr, err = Run(t, exec.CommandContext(ctx, Target(), "addons", "enable", "dashboard", "-p", profile)) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to enable dashboard addon: args %q : %v", rr.Args, err) } rr, err = Run(t, exec.CommandContext(ctx, Target(), "addons", "disable", "dashboard", "-p", profile)) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to disable dashboard addon: args %q : %v", rr.Args, err) } } @@ -88,30 +88,30 @@ func validateIngressAddon(ctx context.Context, t *testing.T, profile string) { client, err := kapi.Client(profile) if err != nil { - t.Fatalf("kubernetes client: %v", client) + t.Fatalf("failed to get kubernetes client: %v", client) } if err := kapi.WaitForDeploymentToStabilize(client, "kube-system", "nginx-ingress-controller", Minutes(6)); err != nil { - t.Errorf("waiting for ingress-controller deployment to stabilize: %v", err) + t.Errorf("failed waiting for ingress-controller deployment to stabilize: %v", err) } if _, err := PodWait(ctx, t, profile, "kube-system", "app.kubernetes.io/name=nginx-ingress-controller", Minutes(12)); err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waititing for nginx-ingress-controller : %v", err) } rr, err := Run(t, exec.CommandContext(ctx, "kubectl", "--context", profile, "replace", "--force", "-f", filepath.Join(*testdataDir, "nginx-ing.yaml"))) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to kubectl replace nginx-ing. args %q. %v", rr.Args, err) } rr, err = Run(t, exec.CommandContext(ctx, "kubectl", "--context", profile, "replace", "--force", "-f", filepath.Join(*testdataDir, "nginx-pod-svc.yaml"))) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to kubectl replace nginx-pod-svc. args %q. %v", rr.Args, err) } if _, err := PodWait(ctx, t, profile, "default", "run=nginx", Minutes(4)); err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waiting for ngnix pod: %v", err) } if err := kapi.WaitForService(client, "default", "nginx", true, time.Millisecond*500, Minutes(10)); err != nil { - t.Errorf("Error waiting for nginx service to be up") + t.Errorf("failed waiting for nginx service to be up: %v", err) } want := "Welcome to nginx!" @@ -121,7 +121,7 @@ func validateIngressAddon(ctx context.Context, t *testing.T, profile string) { return err } if rr.Stderr.String() != "" { - t.Logf("%v: unexpected stderr: %s", rr.Args, rr.Stderr) + t.Logf("%v: unexpected stderr: %s (may be temproary)", rr.Args, rr.Stderr) } if !strings.Contains(rr.Stdout.String(), want) { return fmt.Errorf("%v stdout = %q, want %q", rr.Args, rr.Stdout, want) @@ -130,32 +130,32 @@ func validateIngressAddon(ctx context.Context, t *testing.T, profile string) { } if err := retry.Expo(checkIngress, 500*time.Millisecond, Seconds(90)); err != nil { - t.Errorf("ingress never responded as expected on 127.0.0.1:80: %v", err) + t.Errorf("failed to get response from ngninx ingress on 127.0.0.1:80: %v", err) } rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "addons", "disable", "ingress", "--alsologtostderr", "-v=1")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to disable ingress addon. args %q : %v", rr.Args, err) } } func validateRegistryAddon(ctx context.Context, t *testing.T, profile string) { client, err := kapi.Client(profile) if err != nil { - t.Fatalf("kubernetes client: %v", client) + t.Fatalf("failed to get kubernetes client for %s : %v", profile, err) } start := time.Now() if err := kapi.WaitForRCToStabilize(client, "kube-system", "registry", Minutes(6)); err != nil { - t.Errorf("waiting for registry replicacontroller to stabilize: %v", err) + t.Errorf("failed waiting for registry replicacontroller to stabilize: %v", err) } t.Logf("registry stabilized in %s", time.Since(start)) if _, err := PodWait(ctx, t, profile, "kube-system", "actual-registry=true", Minutes(6)); err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waiting for pod actual-registry: %v", err) } if _, err := PodWait(ctx, t, profile, "kube-system", "registry-proxy=true", Minutes(10)); err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waiting for pod registry-proxy: %v", err) } // Test from inside the cluster (no curl available on busybox) @@ -166,20 +166,20 @@ func validateRegistryAddon(ctx context.Context, t *testing.T, profile string) { rr, err = Run(t, exec.CommandContext(ctx, "kubectl", "--context", profile, "run", "--rm", "registry-test", "--restart=Never", "--image=busybox", "-it", "--", "sh", "-c", "wget --spider -S http://registry.kube-system.svc.cluster.local")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to hit registry.kube-system.svc.cluster.local. args %q failed: %v", rr.Args, err) } want := "HTTP/1.1 200" if !strings.Contains(rr.Stdout.String(), want) { - t.Errorf("curl = %q, want *%s*", rr.Stdout.String(), want) + t.Errorf("expected curl response be %q, but got *%s*", want, rr.Stdout.String()) } // Test from outside the cluster rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "ip")) if err != nil { - t.Fatalf("%s failed: %v", rr.Args, err) + t.Fatalf("failed run minikube ip. args %q : %v", rr.Args, err) } if rr.Stderr.String() != "" { - t.Errorf("%s: unexpected stderr: %s", rr.Args, rr.Stderr) + t.Errorf("expected stderr to be -empty- but got: *%q*", rr.Args, rr.Stderr) } endpoint := fmt.Sprintf("http://%s:%d", strings.TrimSpace(rr.Stdout.String()), 5000) @@ -199,30 +199,30 @@ func validateRegistryAddon(ctx context.Context, t *testing.T, profile string) { return nil } - if err := retry.Expo(checkExternalAccess, 500*time.Millisecond, Minutes(2)); err != nil { - t.Errorf(err.Error()) + if err := retry.Expo(checkExternalAccess, 500*time.Millisecond, Seconds(150)); err != nil { + t.Errorf("failed to check external access to %s: %v", u.String(), err.Error()) } rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "addons", "disable", "registry", "--alsologtostderr", "-v=1")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to disable registry addon. args %q: %v", rr.Args, err) } } func validateMetricsServerAddon(ctx context.Context, t *testing.T, profile string) { client, err := kapi.Client(profile) if err != nil { - t.Fatalf("kubernetes client: %v", client) + t.Fatalf("failed to get kubernetes client for %s: %v", profile, err) } start := time.Now() if err := kapi.WaitForDeploymentToStabilize(client, "kube-system", "metrics-server", Minutes(6)); err != nil { - t.Errorf("waiting for metrics-server deployment to stabilize: %v", err) + t.Errorf("failed waiting for metrics-server deployment to stabilize: %v", err) } t.Logf("metrics-server stabilized in %s", time.Since(start)) if _, err := PodWait(ctx, t, profile, "kube-system", "k8s-app=metrics-server", Minutes(6)); err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waiting for k8s-app=metrics-server pod: %v", err) } want := "CPU(cores)" @@ -242,29 +242,29 @@ func validateMetricsServerAddon(ctx context.Context, t *testing.T, profile strin // metrics-server takes some time to be able to collect metrics if err := retry.Expo(checkMetricsServer, time.Second*3, Minutes(6)); err != nil { - t.Errorf(err.Error()) + t.Errorf("failed checking metric server: %v", err.Error()) } rr, err := Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "addons", "disable", "metrics-server", "--alsologtostderr", "-v=1")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to disable metrics-server addon: args %q: %v", rr.Args, err) } } func validateHelmTillerAddon(ctx context.Context, t *testing.T, profile string) { client, err := kapi.Client(profile) if err != nil { - t.Fatalf("kubernetes client: %v", client) + t.Fatalf("failed to get kubernetes client for %s: %v", profile, err) } start := time.Now() if err := kapi.WaitForDeploymentToStabilize(client, "kube-system", "tiller-deploy", Minutes(6)); err != nil { - t.Errorf("waiting for tiller-deploy deployment to stabilize: %v", err) + t.Errorf("failed waiting for tiller-deploy deployment to stabilize: %v", err) } t.Logf("tiller-deploy stabilized in %s", time.Since(start)) if _, err := PodWait(ctx, t, profile, "kube-system", "app=helm", Minutes(6)); err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waiting for helm pod: %v", err) } if NoneDriver() { @@ -292,11 +292,11 @@ func validateHelmTillerAddon(ctx context.Context, t *testing.T, profile string) } if err := retry.Expo(checkHelmTiller, 500*time.Millisecond, Minutes(2)); err != nil { - t.Errorf(err.Error()) + t.Errorf("failed checking helm tiller: %v", err.Error()) } rr, err := Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "addons", "disable", "helm-tiller", "--alsologtostderr", "-v=1")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed disabling helm-tiller addon. arg %q.s %v", rr.Args, err) } } diff --git a/test/integration/functional_test.go b/test/integration/functional_test.go index 63b2a28c9c..127ec9dd99 100644 --- a/test/integration/functional_test.go +++ b/test/integration/functional_test.go @@ -270,40 +270,40 @@ func validateComponentHealth(ctx context.Context, t *testing.T, profile string) func validateStatusCmd(ctx context.Context, t *testing.T, profile string) { rr, err := Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "status")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("%q failed: %v", rr.Args, err) } // Custom format rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "status", "-f", "host:{{.Host}},kublet:{{.Kubelet}},apiserver:{{.APIServer}},kubeconfig:{{.Kubeconfig}}")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("%q failed: %v", rr.Args, err) } match, _ := regexp.MatchString(`host:([A-z]+),kublet:([A-z]+),apiserver:([A-z]+),kubeconfig:([A-z]+)`, rr.Stdout.String()) if !match { - t.Errorf("%s failed: %v. Output for custom format did not match", rr.Args, err) + t.Errorf("%q failed: %v. Output for custom format did not match", rr.Args, err) } // Json output rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "status", "-o", "json")) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("%q failed: %v", rr.Args, err) } var jsonObject map[string]interface{} err = json.Unmarshal(rr.Stdout.Bytes(), &jsonObject) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("%q failed: %v", rr.Args, err) } if _, ok := jsonObject["Host"]; !ok { - t.Errorf("%s failed: %v. Missing key %s in json object", rr.Args, err, "Host") + t.Errorf("%q failed: %v. Missing key %s in json object", rr.Args, err, "Host") } if _, ok := jsonObject["Kubelet"]; !ok { - t.Errorf("%s failed: %v. Missing key %s in json object", rr.Args, err, "Kubelet") + t.Errorf("%q failed: %v. Missing key %s in json object", rr.Args, err, "Kubelet") } if _, ok := jsonObject["APIServer"]; !ok { - t.Errorf("%s failed: %v. Missing key %s in json object", rr.Args, err, "APIServer") + t.Errorf("%q failed: %v. Missing key %s in json object", rr.Args, err, "APIServer") } if _, ok := jsonObject["Kubeconfig"]; !ok { - t.Errorf("%s failed: %v. Missing key %s in json object", rr.Args, err, "Kubeconfig") + t.Errorf("%q failed: %v. Missing key %s in json object", rr.Args, err, "Kubeconfig") } } @@ -312,7 +312,7 @@ func validateDashboardCmd(ctx context.Context, t *testing.T, profile string) { args := []string{"dashboard", "--url", "-p", profile, "--alsologtostderr", "-v=1"} ss, err := Start(t, exec.CommandContext(ctx, Target(), args...)) if err != nil { - t.Errorf("%s failed: %v", args, err) + t.Errorf("%q failed: %v", args, err) } defer func() { ss.Stop(t) @@ -334,7 +334,7 @@ func validateDashboardCmd(ctx context.Context, t *testing.T, profile string) { resp, err := retryablehttp.Get(u.String()) if err != nil { - t.Errorf("failed get: %v", err) + t.Errorf("failed to http get %q : %v", u.String(), err) } if resp.StatusCode != http.StatusOK { body, err := ioutil.ReadAll(resp.Body) @@ -349,12 +349,12 @@ func validateDashboardCmd(ctx context.Context, t *testing.T, profile string) { func validateDNS(ctx context.Context, t *testing.T, profile string) { rr, err := Run(t, exec.CommandContext(ctx, "kubectl", "--context", profile, "replace", "--force", "-f", filepath.Join(*testdataDir, "busybox.yaml"))) if err != nil { - t.Fatalf("%s failed: %v", rr.Args, err) + t.Fatalf("%q failed: %v", rr.Args, err) } names, err := PodWait(ctx, t, profile, "default", "integration-test=busybox", Minutes(4)) if err != nil { - t.Fatalf("wait: %v", err) + t.Fatalf("failed waiting for busybox pod : %v", err) } nslookup := func() error { @@ -364,12 +364,12 @@ func validateDNS(ctx context.Context, t *testing.T, profile string) { // If the coredns process was stable, this retry wouldn't be necessary. if err = retry.Expo(nslookup, 1*time.Second, Minutes(1)); err != nil { - t.Errorf("nslookup failing: %v", err) + t.Errorf("failed to do nslookup on kubernetes.default: %v", err) } want := []byte("10.96.0.1") if !bytes.Contains(rr.Stdout.Bytes(), want) { - t.Errorf("nslookup: got=%q, want=*%q*", rr.Stdout.Bytes(), want) + t.Errorf("failed nslookup: got=%q, want=*%q*", rr.Stdout.Bytes(), want) } } @@ -454,17 +454,17 @@ func validateCacheCmd(ctx context.Context, t *testing.T, profile string) { // make sure the image is deleted. rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "ssh", "sudo", "crictl", "inspecti", img)) if err == nil { - t.Errorf("expected the image be deleted and get error but got nil error ! cmd: %q", rr.Command()) + t.Errorf("expected an error. because image should not exist. but got *nil error* ! cmd: %q", rr.Command()) } // minikube cache reload. rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "cache", "reload")) if err != nil { - t.Errorf("expected %q to run successfully but got error %v", rr.Command(), err) + t.Errorf("expected %q to run successfully but got error: %v", rr.Command(), err) } // make sure 'cache reload' brought back the manually deleted image. rr, err = Run(t, exec.CommandContext(ctx, Target(), "-p", profile, "ssh", "sudo", "crictl", "inspecti", img)) if err != nil { - t.Errorf("expected to get no error for %q but got %v", rr.Command(), err) + t.Errorf("expected %q to run successfully but got error: %v", rr.Command(), err) } }) diff --git a/test/integration/version_upgrade_test.go b/test/integration/version_upgrade_test.go index a03676a335..20d131d5ef 100644 --- a/test/integration/version_upgrade_test.go +++ b/test/integration/version_upgrade_test.go @@ -97,7 +97,7 @@ func TestVersionUpgrade(t *testing.T) { args = append([]string{"start", "-p", profile, fmt.Sprintf("--kubernetes-version=%s", constants.NewestKubernetesVersion), "--alsologtostderr", "-v=1"}, StartArgs()...) rr, err = Run(t, exec.CommandContext(ctx, Target(), args...)) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("failed to start minikube HEAD with newest k8s version. args: %s : %v", rr.Args, err) } s, err := Run(t, exec.CommandContext(ctx, "kubectl", "--context", profile, "version", "--output=json")) @@ -127,6 +127,6 @@ func TestVersionUpgrade(t *testing.T) { args = append([]string{"start", "-p", profile, fmt.Sprintf("--kubernetes-version=%s", constants.NewestKubernetesVersion), "--alsologtostderr", "-v=1"}, StartArgs()...) rr, err = Run(t, exec.CommandContext(ctx, Target(), args...)) if err != nil { - t.Errorf("%s failed: %v", rr.Args, err) + t.Errorf("start and already started minikube failed. args: %q : %v", rr.Args, err) } }