Introduced a basic logger to the integration tests framework

.circleci/config.yml

@@ -156,7 +156,7 @@ jobs:
           export CORTEX_IMAGE="${CORTEX_IMAGE_PREFIX}cortex:${CIRCLE_TAG:-$(./tools/image-tag)}"
           export CORTEX_CHECKOUT_DIR="/home/circleci/.go_workspace/src/github.com/cortexproject/cortex"
           echo "Running integration tests with image: $CORTEX_IMAGE"
-          go test -tags=requires_docker -timeout 300s -v -count=1 ./integration/...
+          go test -tags=requires_docker -timeout 600s -v -count=1 ./integration/...
 
   build:
     <<: *defaults

integration/e2e/logger.go

@@ -0,0 +1,44 @@
+package e2e
+
+import (
+	"fmt"
+	"io"
+	"os"
+	"strings"
+	"time"
+
+	"github.com/go-kit/kit/log"
+)
+
+// Global logger to use in integration tests. We use a global logger to simplify
+// writing integration tests and avoiding having to pass the logger instance
+// every time.
+var logger log.Logger
+
+func init() {
+	logger = NewLogger(os.Stdout)
+}
+
+type Logger struct {
+	w io.Writer
+}
+
+func NewLogger(w io.Writer) *Logger {
+	return &Logger{
+		w: w,
+	}
+}
+
+func (l *Logger) Log(keyvals ...interface{}) error {
+	log := strings.Builder{}
+	log.WriteString(time.Now().Format("15:04:05"))
+
+	for _, v := range keyvals {
+		log.WriteString(" " + fmt.Sprint(v))
+	}
+
+	log.WriteString("\n")
+
+	_, err := l.w.Write([]byte(log.String()))
+	return err
+}

integration/e2e/scenario.go

@@ -54,7 +54,7 @@ func NewScenario(networkName string) (*Scenario, error) {
 
 	// Setup the docker network.
 	if out, err := RunCommandAndGetOutput("docker", "network", "create", networkName); err != nil {
-		fmt.Println(string(out))
+		logger.Log(string(out))
 		s.clean()
 		return nil, errors.Wrapf(err, "create docker network '%s'", networkName)
 	}
@@ -90,8 +90,7 @@ func (s *Scenario) StartAndWaitReady(services ...Service) error {
 
 func (s *Scenario) Start(services ...Service) error {
 	for _, service := range services {
-		// TODO(bwplotka): Some basic logger would be nice.
-		fmt.Println("Starting", service.Name())
+		logger.Log("Starting", service.Name())
 
 		// Ensure another service with the same name doesn't exist.
 		if s.isRegistered(service.Name()) {
@@ -153,15 +152,15 @@ func (s *Scenario) Close() {
 // TODO(bwplotka): Add comments.
 func (s *Scenario) clean() {
 	if err := os.RemoveAll(s.sharedDir); err != nil {
-		fmt.Println("error while removing sharedDir", s.sharedDir, "err:", err)
+		logger.Log("error while removing sharedDir", s.sharedDir, "err:", err)
 	}
 }
 
 func (s *Scenario) shutdown() {
 	// Kill the services in the opposite order.
 	for i := len(s.services) - 1; i >= 0; i-- {
 		if err := s.services[i].Kill(); err != nil {
-			fmt.Println("Unable to kill service", s.services[i].Name(), ":", err.Error())
+			logger.Log("Unable to kill service", s.services[i].Name(), ":", err.Error())
 		}
 	}
 
@@ -181,31 +180,31 @@ func (s *Scenario) shutdown() {
 			}
 
 			if out, err = RunCommandAndGetOutput("docker", "rm", "--force", containerID); err != nil {
-				fmt.Println(string(out))
-				fmt.Println("Unable to cleanup leftover container", containerID, ":", err.Error())
+				logger.Log(string(out))
+				logger.Log("Unable to cleanup leftover container", containerID, ":", err.Error())
 			}
 		}
 	} else {
-		fmt.Println(string(out))
-		fmt.Println("Unable to cleanup leftover containers:", err.Error())
+		logger.Log(string(out))
+		logger.Log("Unable to cleanup leftover containers:", err.Error())
 	}
 
 	// Teardown the docker network. In case the network does not exists (ie. this function
 	// is called during the setup of the scenario) we skip the removal in order to not log
 	// an error which may be misleading.
 	if ok, err := existDockerNetwork(s.networkName); ok || err != nil {
 		if out, err := RunCommandAndGetOutput("docker", "network", "rm", s.networkName); err != nil {
-			fmt.Println(string(out))
-			fmt.Println("Unable to remove docker network", s.networkName, ":", err.Error())
+			logger.Log(string(out))
+			logger.Log("Unable to remove docker network", s.networkName, ":", err.Error())
 		}
 	}
 }
 
 func existDockerNetwork(networkName string) (bool, error) {
 	out, err := RunCommandAndGetOutput("docker", "network", "ls", "--quiet", "--filter", fmt.Sprintf("name=%s", networkName))
 	if err != nil {
-		fmt.Println(string(out))
-		fmt.Println("Unable to check if docker network", networkName, "exists:", err.Error())
+		logger.Log(string(out))
+		logger.Log("Unable to check if docker network", networkName, "exists:", err.Error())
 	}
 
 	return strings.TrimSpace(string(out)) != "", nil

integration/e2e/service.go

@@ -4,16 +4,15 @@ import (
 	"bytes"
 	"context"
 	"fmt"
-	"io"
 	"io/ioutil"
 	"math"
-	"os"
 	"os/exec"
 	"regexp"
 	"strconv"
 	"strings"
 	"time"
 
+	"github.com/go-kit/kit/log"
 	"github.com/pkg/errors"
 	io_prometheus_client "github.com/prometheus/client_model/go"
 	"github.com/prometheus/common/expfmt"
@@ -104,8 +103,8 @@ func (s *ConcreteService) Start(networkName, sharedDir string) (err error) {
 	}()
 
 	cmd := exec.Command("docker", s.buildDockerRunArgs(networkName, sharedDir)...)
-	cmd.Stdout = &LinePrefixWriter{prefix: s.name + ": ", wrapped: os.Stdout}
-	cmd.Stderr = &LinePrefixWriter{prefix: s.name + ": ", wrapped: os.Stderr}
+	cmd.Stdout = &LinePrefixLogger{prefix: s.name + ": ", logger: logger}
+	cmd.Stderr = &LinePrefixLogger{prefix: s.name + ": ", logger: logger}
 	if err = cmd.Start(); err != nil {
 		return err
 	}
@@ -142,7 +141,7 @@ func (s *ConcreteService) Start(networkName, sharedDir string) (err error) {
 		}
 		s.networkPortsContainerToLocal[containerPort] = localPort
 	}
-	fmt.Println("Ports for container:", s.containerName(), "Mapping:", s.networkPortsContainerToLocal)
+	logger.Log("Ports for container:", s.containerName(), "Mapping:", s.networkPortsContainerToLocal)
 	return nil
 }
 
@@ -151,10 +150,10 @@ func (s *ConcreteService) Stop() error {
 		return nil
 	}
 
-	fmt.Println("Stopping", s.name)
+	logger.Log("Stopping", s.name)
 
 	if out, err := RunCommandAndGetOutput("docker", "stop", "--time=30", s.containerName()); err != nil {
-		fmt.Println(string(out))
+		logger.Log(string(out))
 		return err
 	}
 	s.usedNetworkName = ""
@@ -167,10 +166,10 @@ func (s *ConcreteService) Kill() error {
 		return nil
 	}
 
-	fmt.Println("Killing", s.name)
+	logger.Log("Killing", s.name)
 
 	if out, err := RunCommandAndGetOutput("docker", "stop", "--time=0", s.containerName()); err != nil {
-		fmt.Println(string(out))
+		logger.Log(string(out))
 		return err
 	}
 	s.usedNetworkName = ""
@@ -405,12 +404,12 @@ func (p *CmdReadinessProbe) Ready(service *ConcreteService) error {
 	return err
 }
 
-type LinePrefixWriter struct {
-	prefix  string
-	wrapped io.Writer
+type LinePrefixLogger struct {
+	prefix string
+	logger log.Logger
 }
 
-func (w *LinePrefixWriter) Write(p []byte) (n int, err error) {
+func (w *LinePrefixLogger) Write(p []byte) (n int, err error) {
 	for _, line := range strings.Split(string(p), "\n") {
 		// Skip empty lines
 		line = strings.TrimSpace(line)
@@ -419,8 +418,7 @@ func (w *LinePrefixWriter) Write(p []byte) (n int, err error) {
 		}
 
 		// Write the prefix + line to the wrapped writer
-		_, err := w.wrapped.Write([]byte(w.prefix + line + "\n"))
-		if err != nil {
+		if err := w.logger.Log(w.prefix + line); err != nil {
 			return 0, err
 		}
 	}