From 2b93fdf357befef44f755655920d5891812f6af2 Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Mon, 7 Feb 2022 11:57:54 -0800 Subject: [PATCH 1/3] Fix a bug in the e2e tests When the test was going to fail, a goroutine would accidentally block on writing to an unbuffered channel, and the spawnTestGoroutine helper would wait for that goroutine to end on cleanup, causing the test to hang forever while it was trying to fail. --- test/integration/cli_test.go | 11 ++++++----- test/integration/e2e_test.go | 8 ++++---- 2 files changed, 10 insertions(+), 9 deletions(-) diff --git a/test/integration/cli_test.go b/test/integration/cli_test.go index dd833414..3c16d11f 100644 --- a/test/integration/cli_test.go +++ b/test/integration/cli_test.go @@ -1,4 +1,4 @@ -// Copyright 2020-2021 the Pinniped contributors. All Rights Reserved. +// Copyright 2020-2022 the Pinniped contributors. All Rights Reserved. // SPDX-License-Identifier: Apache-2.0 package integration @@ -299,7 +299,7 @@ func runPinnipedLoginOIDC( }) // Start a background goroutine to read stderr from the CLI and parse out the login URL. - loginURLChan := make(chan string) + loginURLChan := make(chan string, 1) spawnTestGoroutine(t, func() (err error) { t.Helper() defer func() { @@ -318,7 +318,7 @@ func runPinnipedLoginOIDC( for scanner.Scan() { loginURL, err := url.Parse(strings.TrimSpace(scanner.Text())) if err == nil && loginURL.Scheme == "https" { - loginURLChan <- loginURL.String() + loginURLChan <- loginURL.String() // this channel is buffered so this will not block return nil } } @@ -327,7 +327,7 @@ func runPinnipedLoginOIDC( }) // Start a background goroutine to read stdout from the CLI and parse out an ExecCredential. - credOutputChan := make(chan clientauthenticationv1beta1.ExecCredential) + credOutputChan := make(chan clientauthenticationv1beta1.ExecCredential, 1) spawnTestGoroutine(t, func() (err error) { defer func() { closeErr := stdout.Close() @@ -343,7 +343,7 @@ func runPinnipedLoginOIDC( if err := json.NewDecoder(reader).Decode(&out); err != nil { return fmt.Errorf("could not read ExecCredential from stdout: %w", err) } - credOutputChan <- out + credOutputChan <- out // this channel is buffered so this will not block return readAndExpectEmpty(reader) }) @@ -398,6 +398,7 @@ func readAndExpectEmpty(r io.Reader) (err error) { return nil } +// Note: Callers should ensure that f eventually returns, otherwise this helper will hang forever in t.Cleanup. func spawnTestGoroutine(t *testing.T, f func() error) { t.Helper() var eg errgroup.Group diff --git a/test/integration/e2e_test.go b/test/integration/e2e_test.go index 4f334541..f84a6395 100644 --- a/test/integration/e2e_test.go +++ b/test/integration/e2e_test.go @@ -181,7 +181,7 @@ func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo }) // Start a background goroutine to read stderr from the CLI and parse out the login URL. - loginURLChan := make(chan string) + loginURLChan := make(chan string, 1) spawnTestGoroutine(t, func() (err error) { defer func() { closeErr := stderrPipe.Close() @@ -198,7 +198,7 @@ func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo for scanner.Scan() { loginURL, err := url.Parse(strings.TrimSpace(scanner.Text())) if err == nil && loginURL.Scheme == "https" { - loginURLChan <- loginURL.String() + loginURLChan <- loginURL.String() // this channel is buffered so this will not block return nil } } @@ -206,7 +206,7 @@ func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo }) // Start a background goroutine to read stdout from kubectl and return the result as a string. - kubectlOutputChan := make(chan string) + kubectlOutputChan := make(chan string, 1) spawnTestGoroutine(t, func() (err error) { defer func() { closeErr := stdoutPipe.Close() @@ -222,7 +222,7 @@ func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo return err } t.Logf("kubectl output:\n%s\n", output) - kubectlOutputChan <- string(output) + kubectlOutputChan <- string(output) // this channel is buffered so this will not block return nil }) From aa56f174dba281e9a7af1047e9787070b27c836f Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Mon, 7 Feb 2022 16:17:38 -0800 Subject: [PATCH 2/3] Capture and print the full kubectl output in an e2e test upon failure --- test/integration/e2e_test.go | 57 ++++++++++++++++-------------------- 1 file changed, 25 insertions(+), 32 deletions(-) diff --git a/test/integration/e2e_test.go b/test/integration/e2e_test.go index f84a6395..7aaa11c6 100644 --- a/test/integration/e2e_test.go +++ b/test/integration/e2e_test.go @@ -29,6 +29,7 @@ import ( corev1 "k8s.io/api/core/v1" rbacv1 "k8s.io/api/rbac/v1" metav1 "k8s.io/apimachinery/pkg/apis/meta/v1" + utilerrors "k8s.io/apimachinery/pkg/util/errors" authv1alpha "go.pinniped.dev/generated/latest/apis/concierge/authentication/v1alpha1" configv1alpha1 "go.pinniped.dev/generated/latest/apis/supervisor/config/v1alpha1" @@ -159,40 +160,41 @@ func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo start := time.Now() kubectlCmd := exec.CommandContext(ctx, "kubectl", "get", "namespace", "--kubeconfig", kubeconfigPath) kubectlCmd.Env = append(os.Environ(), env.ProxyEnv()...) - stderrPipe, err := kubectlCmd.StderrPipe() + + // Wrap the stdout and stderr pipes with TeeReaders which will copy each incremental read to an + // in-memory buffer, so we can have the full output available to us at the end. + originalStderrPipe, err := kubectlCmd.StderrPipe() require.NoError(t, err) - stdoutPipe, err := kubectlCmd.StdoutPipe() + originalStdoutPipe, err := kubectlCmd.StdoutPipe() require.NoError(t, err) + var stderrPipeBuf, stdoutPipeBuf bytes.Buffer + stderrPipe := io.TeeReader(originalStderrPipe, &stderrPipeBuf) + stdoutPipe := io.TeeReader(originalStdoutPipe, &stdoutPipeBuf) t.Logf("starting kubectl subprocess") require.NoError(t, kubectlCmd.Start()) t.Cleanup(func() { - err := kubectlCmd.Wait() + // Consume readers so that the tee buffers will contain all the output so far. + _, stdoutReadAllErr := ioutil.ReadAll(stdoutPipe) + _, stderrReadAllErr := ioutil.ReadAll(stderrPipe) + + // Note that Wait closes the stdout/stderr pipes, so we don't need to close them ourselves. + waitErr := kubectlCmd.Wait() t.Logf("kubectl subprocess exited with code %d", kubectlCmd.ProcessState.ExitCode()) - stdout, stdoutErr := ioutil.ReadAll(stdoutPipe) - if stdoutErr != nil { - stdout = []byte("") + + // Upon failure, print the full output so far of the kubectl command. + var testAlreadyFailedErr error + if t.Failed() { + testAlreadyFailedErr = errors.New("test failed prior to clean up function") } - stderr, stderrErr := ioutil.ReadAll(stderrPipe) - if stderrErr != nil { - stderr = []byte("") - } - require.NoErrorf(t, err, "kubectl process did not exit cleanly, stdout/stderr: %q/%q", string(stdout), string(stderr)) + cleanupErrs := utilerrors.NewAggregate([]error{waitErr, stdoutReadAllErr, stderrReadAllErr, testAlreadyFailedErr}) + require.NoErrorf(t, cleanupErrs, "kubectl process did not exit cleanly and/or the test failed\nstdout: %q\nstderr: %q", + stdoutPipeBuf.String(), stderrPipeBuf.String()) }) // Start a background goroutine to read stderr from the CLI and parse out the login URL. loginURLChan := make(chan string, 1) - spawnTestGoroutine(t, func() (err error) { - defer func() { - closeErr := stderrPipe.Close() - if closeErr == nil || errors.Is(closeErr, os.ErrClosed) { - return - } - if err == nil { - err = fmt.Errorf("stderr stream closed with error: %w", closeErr) - } - }() - + spawnTestGoroutine(t, func() error { reader := bufio.NewReader(testlib.NewLoggerReader(t, "stderr", stderrPipe)) scanner := bufio.NewScanner(reader) for scanner.Scan() { @@ -207,16 +209,7 @@ func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo // Start a background goroutine to read stdout from kubectl and return the result as a string. kubectlOutputChan := make(chan string, 1) - spawnTestGoroutine(t, func() (err error) { - defer func() { - closeErr := stdoutPipe.Close() - if closeErr == nil || errors.Is(closeErr, os.ErrClosed) { - return - } - if err == nil { - err = fmt.Errorf("stdout stream closed with error: %w", closeErr) - } - }() + spawnTestGoroutine(t, func() error { output, err := ioutil.ReadAll(stdoutPipe) if err != nil { return err From 0431a072ae255439df40f7d4fa3092755a3914c3 Mon Sep 17 00:00:00 2001 From: Ryan Richard Date: Mon, 7 Feb 2022 16:26:39 -0800 Subject: [PATCH 3/3] Remove an unnecessary nolint comment --- test/integration/e2e_test.go | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/test/integration/e2e_test.go b/test/integration/e2e_test.go index 7aaa11c6..65d687c6 100644 --- a/test/integration/e2e_test.go +++ b/test/integration/e2e_test.go @@ -47,7 +47,7 @@ import ( ) // TestE2EFullIntegration tests a full integration scenario that combines the supervisor, concierge, and CLI. -func TestE2EFullIntegration(t *testing.T) { // nolint:gocyclo +func TestE2EFullIntegration(t *testing.T) { env := testlib.IntegrationEnv(t) ctx, cancelFunc := context.WithTimeout(context.Background(), 15*time.Minute)