[WKP-468] test for debug log level (#173)

* test for debug log level

* make verbose setting configurable in test

* test for debug log level

* make verbose setting configurable in test

* updates to verbose logging testcase

* test for debug log level

* make verbose setting configurable in test

* test for debug log level

* make verbose setting configurable in test

* updates to verbose logging testcase

* check verbose from json output

* add logging debug statement

* fixes for TestApply

* print run object in test for debugging

* Old version of kubectl doesn't support -A

* test fixes to work with outdated kubectl

* Wait for all output to complete in test executor

* select specific output from kubectl command looking for "--verbose"

* switch to standard exec.Cmd

* small fix

* fix missing imports that "make lint" did not catch

* debug logging for pods

* debug

* debug

* switch to default namespace in test because that's how the cluster is created

Co-authored-by: Mark Emeis <mark.emeis@weave.works>
Co-authored-by: Jerry Jackson <jerry@weave.works>

.circleci/config.yml

@@ -198,6 +198,7 @@ jobs:
           CREATE_IMAGE: 1
           USE_IMAGE: 1
           IMAGE_NAME: centos-cloud/centos-7
+          WKP_DEBUG: true
     working_directory: /src/github.com/weaveworks/wksctl
     steps:
       - checkout
@@ -269,6 +270,7 @@ jobs:
           CREATE_IMAGE: 1
           USE_IMAGE: 1
           IMAGE_NAME: rhel-cloud/rhel-7
+          WKP_DEBUG: false
     working_directory: /src/github.com/weaveworks/wksctl
     steps:
       - checkout

test/integration/spawn/executor.go

@@ -144,8 +144,16 @@ func (e *Executor) RunCmd(cmd *exec.Cmd) (*Entry, error) {
 		return nil, err
 	}
 
-	go e.handStream(entry, stdout, stdoutPipe)
-	go e.handStream(entry, stderr, stderrPipe)
+	syncChan := make(chan bool)
+	go func() {
+		e.handStream(entry, stdout, stdoutPipe)
+		syncChan <- true
+	}()
+
+	go func() {
+		e.handStream(entry, stderr, stderrPipe)
+		syncChan <- true
+	}()
 
 	if e.showBreadcrumbs {
 		fmt.Printf("=== EXE   %s\n", strings.Join(cmd.Args, " "))
@@ -155,6 +163,10 @@ func (e *Executor) RunCmd(cmd *exec.Cmd) (*Entry, error) {
 		return nil, err
 	}
 
+	// Make sure copying is finished
+	<-syncChan
+	<-syncChan
+
 	err = cmd.Wait()
 	exitCode, err := exitCode(err)
 	entry.exitCode = exitCode

test/integration/test/apply_test.go

@@ -271,6 +271,29 @@ func testKubectl(t *testing.T, kubeconfig string) {
 	assert.True(t, run.Contains("Ready"))
 }
 
+func testDebugLogging(t *testing.T, kubeconfig string) {
+	exe := run.NewExecutor()
+
+	run, err := exe.RunV(kubectl,
+		fmt.Sprintf("--kubeconfig=%s", kubeconfig), "get", "pods", "-l", "name=wks-controller", "--namespace=default", "-o", "jsonpath={.items[].spec.containers[].command}")
+	assert.NoError(t, err)
+	assert.Equal(t, 0, run.ExitCode())
+	verbose := false
+	if run.Contains("--verbose") {
+		verbose = true
+	}
+
+	run, err = exe.RunV(kubectl,
+		fmt.Sprintf("--kubeconfig=%s", kubeconfig), "logs", "-l", "name=wks-controller", "--namespace=default")
+	assert.NoError(t, err)
+	assert.Equal(t, 0, run.ExitCode())
+	if verbose {
+		assert.True(t, run.Contains("level=debug"))
+	} else {
+		assert.False(t, run.Contains("level=debug"))
+	}
+}
+
 func nodeIsMaster(n *v1.Node) bool {
 	const masterLabel = "node-role.kubernetes.io/master"
 	if _, ok := n.Labels[masterLabel]; ok {
@@ -450,4 +473,9 @@ func TestApply(t *testing.T) {
 	t.Run("kubectl", func(t *testing.T) {
 		testKubectl(t, kubeconfig)
 	})
+
+	// Test the we are getting debug logging messages.
+	t.Run("loglevel", func(t *testing.T) {
+		testDebugLogging(t, kubeconfig)
+	})
 }