Reduce test log verbosity (#150)

* Reduce test verbosity
* Divert gin's log to the test buffer
* Divert stdlib's log to the test buffer
* Add bolt tests into log buffer

* Add a linebreak to improve log output layout

api/runner/async_runner_test.go

@@ -1,10 +1,12 @@
 package runner
 
 import (
+	"bytes"
 	"context"
 	"encoding/json"
 	"fmt"
 	"io/ioutil"
+	"log"
 	"math/rand"
 	"net/http"
 	"net/http/httptest"
@@ -19,6 +21,16 @@ import (
 	"github.com/iron-io/runner/drivers"
 )
 
+func setLogBuffer() *bytes.Buffer {
+	var buf bytes.Buffer
+	buf.WriteByte('\n')
+	logrus.SetOutput(&buf)
+	gin.DefaultErrorWriter = &buf
+	gin.DefaultWriter = &buf
+	log.SetOutput(&buf)
+	return &buf
+}
+
 func getMockTask() models.Task {
 	priority := int32(0)
 	image := fmt.Sprintf("Image-%d", rand.Int31()%1000)
@@ -97,6 +109,7 @@ func TestRunTask(t *testing.T) {
 }
 
 func TestGetTask(t *testing.T) {
+	buf := setLogBuffer()
 	mockTask := getMockTask()
 
 	ts := getTestServer([]*models.Task{&mockTask})
@@ -105,14 +118,18 @@ func TestGetTask(t *testing.T) {
 	url := ts.URL + "/tasks"
 	task, err := getTask(url)
 	if err != nil {
+		t.Log(buf.String())
 		t.Error("expected no error, got", err)
 	}
 	if task.ID != mockTask.ID {
+		t.Log(buf.String())
 		t.Errorf("expected task ID '%s', got '%s'", task.ID, mockTask.ID)
 	}
 }
 
 func TestGetTaskError(t *testing.T) {
+	buf := setLogBuffer()
+
 	tests := []map[string]interface{}{
 		{
 			"url":   "/invalid",
@@ -134,15 +151,18 @@ func TestGetTaskError(t *testing.T) {
 		url := ts.URL + test["url"].(string)
 		_, err := getTask(url)
 		if err == nil {
+			t.Log(buf.String())
 			t.Errorf("expected error '%s'", test["error"].(string))
 		}
 		if err.Error() != test["error"].(string) {
+			t.Log(buf.String())
 			t.Errorf("test %d: expected error '%s', got '%s'", i, test["error"].(string), err)
 		}
 	}
 }
 
 func TestDeleteTask(t *testing.T) {
+	buf := setLogBuffer()
 	mockTask := getMockTask()
 
 	ts := getTestServer([]*models.Task{&mockTask})
@@ -151,16 +171,19 @@ func TestDeleteTask(t *testing.T) {
 	url := ts.URL + "/tasks"
 	err := deleteTask(url, &mockTask)
 	if err == nil {
+		t.Log(buf.String())
 		t.Error("expected error 'Not reserver', got", err)
 	}
 
 	_, err = getTask(url)
 	if err != nil {
+		t.Log(buf.String())
 		t.Error("expected no error, got", err)
 	}
 
 	err = deleteTask(url, &mockTask)
 	if err != nil {
+		t.Log(buf.String())
 		t.Error("expected no error, got", err)
 	}
 }
@@ -188,6 +211,7 @@ func TestTasksrvURL(t *testing.T) {
 }
 
 func TestAsyncRunnersGracefulShutdown(t *testing.T) {
+	buf := setLogBuffer()
 	mockTask := getMockTask()
 	ts := getTestServer([]*models.Task{&mockTask})
 	defer ts.Close()
@@ -201,6 +225,7 @@ func TestAsyncRunnersGracefulShutdown(t *testing.T) {
 	wg.Wait()
 
 	if err := ctx.Err(); err != context.DeadlineExceeded {
+		t.Log(buf.String())
 		t.Errorf("async runners stopped unexpectedly. context error: %v", err)
 	}
 }

api/runner/runner_test.go

@@ -12,6 +12,7 @@ import (
 )
 
 func TestRunnerHello(t *testing.T) {
+	buf := setLogBuffer()
 	runner, err := New(NewMetricLogger())
 	if err != nil {
 		t.Fatalf("Test error during New() - %s", err)
@@ -41,24 +42,29 @@ func TestRunnerHello(t *testing.T) {
 
 		result, err := runner.Run(ctx, cfg)
 		if err != nil {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: error during Run() - %s", i, err)
 		}
 
 		if test.expectedStatus != result.Status() {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: expected result status to be `%s` but it was `%s`", i, test.expectedStatus, result.Status())
 		}
 
 		if !bytes.Contains(stdout.Bytes(), []byte(test.expectedOut)) {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: expected output log to contain `%s` in `%s`", i, test.expectedOut, stdout.String())
 		}
 
 		if !bytes.Contains(stderr.Bytes(), []byte(test.expectedErr)) {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: expected error log to contain `%s` in `%s`", i, test.expectedErr, stderr.String())
 		}
 	}
 }
 
 func TestRunnerError(t *testing.T) {
+	buf := setLogBuffer()
 	runner, err := New(NewMetricLogger())
 	if err != nil {
 		t.Fatalf("Test error during New() - %s", err)
@@ -88,18 +94,22 @@ func TestRunnerError(t *testing.T) {
 
 		result, err := runner.Run(ctx, cfg)
 		if err != nil {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: error during Run() - %s", i, err)
 		}
 
 		if test.expectedStatus != result.Status() {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: expected result status to be `%s` but it was `%s`", i, test.expectedStatus, result.Status())
 		}
 
 		if !bytes.Contains(stdout.Bytes(), []byte(test.expectedOut)) {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: expected output log to contain `%s` in `%s`", i, test.expectedOut, stdout.String())
 		}
 
 		if !bytes.Contains(stderr.Bytes(), []byte(test.expectedErr)) {
+			t.Log(buf.String())
 			t.Fatalf("Test %d: expected error log to contain `%s` in `%s`", i, test.expectedErr, stderr.String())
 		}
 	}