diff --git a/integration-cli/docker_cli_logs_test.go b/integration-cli/docker_cli_logs_test.go index c7454fb2fd..85d27e9333 100644 --- a/integration-cli/docker_cli_logs_test.go +++ b/integration-cli/docker_cli_logs_test.go @@ -10,6 +10,7 @@ import ( "strings" "time" + "github.com/docker/docker/pkg/integration/checker" "github.com/docker/docker/pkg/timeutils" "github.com/go-check/check" ) @@ -19,13 +20,13 @@ func (s *DockerSuite) TestLogsContainerSmallerThanPage(c *check.C) { testRequires(c, DaemonIsLinux) testLen := 32767 out, _ := dockerCmd(c, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) - out, _ = dockerCmd(c, "logs", cleanedContainerID) - if len(out) != testLen+1 { - c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out)) - } + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) + + out, _ = dockerCmd(c, "logs", id) + + c.Assert(out, checker.HasLen, testLen+1) } // Regression test: When going over the PageSize, it used to panic (gh#4851) @@ -34,14 +35,12 @@ func (s *DockerSuite) TestLogsContainerBiggerThanPage(c *check.C) { testLen := 32768 out, _ := dockerCmd(c, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - out, _ = dockerCmd(c, "logs", cleanedContainerID) + out, _ = dockerCmd(c, "logs", id) - if len(out) != testLen+1 { - c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out)) - } + c.Assert(out, checker.HasLen, testLen+1) } // Regression test: When going much over the PageSize, it used to block (gh#4851) @@ -50,14 +49,12 @@ func (s *DockerSuite) TestLogsContainerMuchBiggerThanPage(c *check.C) { testLen := 33000 out, _ := dockerCmd(c, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - out, _ = dockerCmd(c, "logs", cleanedContainerID) + out, _ = dockerCmd(c, "logs", id) - if len(out) != testLen+1 { - c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out)) - } + c.Assert(out, checker.HasLen, testLen+1) } func (s *DockerSuite) TestLogsTimestamps(c *check.C) { @@ -65,28 +62,23 @@ func (s *DockerSuite) TestLogsTimestamps(c *check.C) { testLen := 100 out, _ := dockerCmd(c, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo =; done;", testLen)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - out, _ = dockerCmd(c, "logs", "-t", cleanedContainerID) + out, _ = dockerCmd(c, "logs", "-t", id) lines := strings.Split(out, "\n") - if len(lines) != testLen+1 { - c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines)) - } + c.Assert(lines, checker.HasLen, testLen+1) ts := regexp.MustCompile(`^.* `) for _, l := range lines { if l != "" { _, err := time.Parse(timeutils.RFC3339NanoFixed+" ", ts.FindString(l)) - if err != nil { - c.Fatalf("Failed to parse timestamp from %v: %v", l, err) - } - if l[29] != 'Z' { // ensure we have padded 0's - c.Fatalf("Timestamp isn't padded properly: %s", l) - } + c.Assert(err, checker.IsNil, check.Commentf("Failed to parse timestamp from %v", l)) + // ensure we have padded 0's + c.Assert(l[29], checker.Equals, uint8('Z')) } } } @@ -96,19 +88,16 @@ func (s *DockerSuite) TestLogsSeparateStderr(c *check.C) { msg := "stderr_log" out, _ := dockerCmd(c, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("echo %s 1>&2", msg)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - stdout, stderr, _ := dockerCmdWithStdoutStderr(c, "logs", cleanedContainerID) + stdout, stderr, _ := dockerCmdWithStdoutStderr(c, "logs", id) - if stdout != "" { - c.Fatalf("Expected empty stdout stream, got %v", stdout) - } + c.Assert(stdout, checker.Equals, "") stderr = strings.TrimSpace(stderr) - if stderr != msg { - c.Fatalf("Expected %v in stderr stream, got %v", msg, stderr) - } + + c.Assert(stderr, checker.Equals, msg) } func (s *DockerSuite) TestLogsStderrInStdout(c *check.C) { @@ -116,18 +105,14 @@ func (s *DockerSuite) TestLogsStderrInStdout(c *check.C) { msg := "stderr_log" out, _ := dockerCmd(c, "run", "-d", "-t", "busybox", "sh", "-c", fmt.Sprintf("echo %s 1>&2", msg)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - stdout, stderr, _ := dockerCmdWithStdoutStderr(c, "logs", cleanedContainerID) - if stderr != "" { - c.Fatalf("Expected empty stderr stream, got %v", stderr) - } + stdout, stderr, _ := dockerCmdWithStdoutStderr(c, "logs", id) + c.Assert(stderr, checker.Equals, "") stdout = strings.TrimSpace(stdout) - if stdout != msg { - c.Fatalf("Expected %v in stdout stream, got %v", msg, stdout) - } + c.Assert(stdout, checker.Equals, msg) } func (s *DockerSuite) TestLogsTail(c *check.C) { @@ -135,43 +120,37 @@ func (s *DockerSuite) TestLogsTail(c *check.C) { testLen := 100 out, _ := dockerCmd(c, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo =; done;", testLen)) - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - out, _ = dockerCmd(c, "logs", "--tail", "5", cleanedContainerID) + out, _ = dockerCmd(c, "logs", "--tail", "5", id) lines := strings.Split(out, "\n") - if len(lines) != 6 { - c.Fatalf("Expected log %d lines, received %d\n", 6, len(lines)) - } - out, _ = dockerCmd(c, "logs", "--tail", "all", cleanedContainerID) + c.Assert(lines, checker.HasLen, 6) + + out, _ = dockerCmd(c, "logs", "--tail", "all", id) lines = strings.Split(out, "\n") - if len(lines) != testLen+1 { - c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines)) - } - out, _, _ = dockerCmdWithStdoutStderr(c, "logs", "--tail", "random", cleanedContainerID) + c.Assert(lines, checker.HasLen, testLen+1) + + out, _, _ = dockerCmdWithStdoutStderr(c, "logs", "--tail", "random", id) lines = strings.Split(out, "\n") - if len(lines) != testLen+1 { - c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines)) - } + c.Assert(lines, checker.HasLen, testLen+1) } func (s *DockerSuite) TestLogsFollowStopped(c *check.C) { testRequires(c, DaemonIsLinux) out, _ := dockerCmd(c, "run", "-d", "busybox", "echo", "hello") - cleanedContainerID := strings.TrimSpace(out) - dockerCmd(c, "wait", cleanedContainerID) + id := strings.TrimSpace(out) + dockerCmd(c, "wait", id) - logsCmd := exec.Command(dockerBinary, "logs", "-f", cleanedContainerID) - if err := logsCmd.Start(); err != nil { - c.Fatal(err) - } + logsCmd := exec.Command(dockerBinary, "logs", "-f", id) + c.Assert(logsCmd.Start(), checker.IsNil) errChan := make(chan error) go func() { @@ -181,7 +160,7 @@ func (s *DockerSuite) TestLogsFollowStopped(c *check.C) { select { case err := <-errChan: - c.Assert(err, check.IsNil) + c.Assert(err, checker.IsNil) case <-time.After(1 * time.Second): c.Fatal("Following logs is hanged") } @@ -194,16 +173,14 @@ func (s *DockerSuite) TestLogsSince(c *check.C) { log2Line := strings.Split(strings.Split(out, "\n")[1], " ") t, err := strconv.ParseInt(log2Line[0], 10, 64) // the timestamp log2 is written - c.Assert(err, check.IsNil) + c.Assert(err, checker.IsNil) since := t + 1 // add 1s so log1 & log2 doesn't show up out, _ = dockerCmd(c, "logs", "-t", fmt.Sprintf("--since=%v", since), name) // Skip 2 seconds unexpected := []string{"log1", "log2"} for _, v := range unexpected { - if strings.Contains(out, v) { - c.Fatalf("unexpected log message returned=%v, since=%v\nout=%v", v, since, out) - } + c.Assert(out, checker.Not(checker.Contains), v, check.Commentf("unexpected log message returned, since=%v", since)) } // Test with default value specified and parameter omitted expected := []string{"log1", "log2", "log3"} @@ -212,13 +189,9 @@ func (s *DockerSuite) TestLogsSince(c *check.C) { exec.Command(dockerBinary, "logs", "-t", "--since=0", name), } { out, _, err = runCommandWithOutput(cmd) - if err != nil { - c.Fatalf("failed to log container: %s, %v", out, err) - } + c.Assert(err, checker.IsNil, check.Commentf("failed to log container: %s", out)) for _, v := range expected { - if !strings.Contains(out, v) { - c.Fatalf("'%v' does not contain=%v\nout=%s", cmd.Args, v, out) - } + c.Assert(out, checker.Contains, v) } } } @@ -226,23 +199,17 @@ func (s *DockerSuite) TestLogsSince(c *check.C) { func (s *DockerSuite) TestLogsSinceFutureFollow(c *check.C) { testRequires(c, DaemonIsLinux) out, _ := dockerCmd(c, "run", "-d", "busybox", "/bin/sh", "-c", `for i in $(seq 1 5); do date +%s; sleep 1; done`) - cleanedContainerID := strings.TrimSpace(out) + id := strings.TrimSpace(out) now := daemonTime(c).Unix() since := now + 2 - out, _ = dockerCmd(c, "logs", "-f", fmt.Sprintf("--since=%v", since), cleanedContainerID) + out, _ = dockerCmd(c, "logs", "-f", fmt.Sprintf("--since=%v", since), id) lines := strings.Split(strings.TrimSpace(out), "\n") - if len(lines) == 0 { - c.Fatal("got no log lines") - } + c.Assert(lines, checker.Not(checker.HasLen), 0) for _, v := range lines { ts, err := strconv.ParseInt(v, 10, 64) - if err != nil { - c.Fatalf("cannot parse timestamp output from log: '%v'\nout=%s", v, out) - } - if ts < since { - c.Fatalf("earlier log found. since=%v logdate=%v", since, ts) - } + c.Assert(err, checker.IsNil, check.Commentf("cannot parse timestamp output from log: '%v'\nout=%s", v, out)) + c.Assert(ts >= since, checker.Equals, true, check.Commentf("earlier log found. since=%v logdate=%v", since, ts)) } } @@ -251,33 +218,31 @@ func (s *DockerSuite) TestLogsFollowSlowStdoutConsumer(c *check.C) { testRequires(c, DaemonIsLinux) out, _ := dockerCmd(c, "run", "-d", "busybox", "/bin/sh", "-c", `usleep 200000;yes X | head -c 200000`) - cleanedContainerID := strings.TrimSpace(out) + id := strings.TrimSpace(out) stopSlowRead := make(chan bool) go func() { - exec.Command(dockerBinary, "wait", cleanedContainerID).Run() + exec.Command(dockerBinary, "wait", id).Run() stopSlowRead <- true }() - logCmd := exec.Command(dockerBinary, "logs", "-f", cleanedContainerID) + logCmd := exec.Command(dockerBinary, "logs", "-f", id) stdout, err := logCmd.StdoutPipe() - c.Assert(err, check.IsNil) - c.Assert(logCmd.Start(), check.IsNil) + c.Assert(err, checker.IsNil) + c.Assert(logCmd.Start(), checker.IsNil) // First read slowly bytes1, err := consumeWithSpeed(stdout, 10, 50*time.Millisecond, stopSlowRead) - c.Assert(err, check.IsNil) + c.Assert(err, checker.IsNil) // After the container has finished we can continue reading fast bytes2, err := consumeWithSpeed(stdout, 32*1024, 0, nil) - c.Assert(err, check.IsNil) + c.Assert(err, checker.IsNil) actual := bytes1 + bytes2 expected := 200000 - if actual != expected { - c.Fatalf("Invalid bytes read: %d, expected %d", actual, expected) - } + c.Assert(actual, checker.Equals, expected) } @@ -285,7 +250,7 @@ func (s *DockerSuite) TestLogsFollowGoroutinesWithStdout(c *check.C) { testRequires(c, DaemonIsLinux) out, _ := dockerCmd(c, "run", "-d", "busybox", "/bin/sh", "-c", "while true; do echo hello; sleep 2; done") id := strings.TrimSpace(out) - c.Assert(waitRun(id), check.IsNil) + c.Assert(waitRun(id), checker.IsNil) type info struct { NGoroutines int @@ -293,9 +258,9 @@ func (s *DockerSuite) TestLogsFollowGoroutinesWithStdout(c *check.C) { getNGoroutines := func() int { var i info status, b, err := sockRequest("GET", "/info", nil) - c.Assert(err, check.IsNil) - c.Assert(status, check.Equals, 200) - c.Assert(json.Unmarshal(b, &i), check.IsNil) + c.Assert(err, checker.IsNil) + c.Assert(status, checker.Equals, 200) + c.Assert(json.Unmarshal(b, &i), checker.IsNil) return i.NGoroutines } @@ -304,7 +269,7 @@ func (s *DockerSuite) TestLogsFollowGoroutinesWithStdout(c *check.C) { cmd := exec.Command(dockerBinary, "logs", "-f", id) r, w := io.Pipe() cmd.Stdout = w - c.Assert(cmd.Start(), check.IsNil) + c.Assert(cmd.Start(), checker.IsNil) // Make sure pipe is written to chErr := make(chan error) @@ -313,17 +278,17 @@ func (s *DockerSuite) TestLogsFollowGoroutinesWithStdout(c *check.C) { _, err := r.Read(b) chErr <- err }() - c.Assert(<-chErr, check.IsNil) - c.Assert(cmd.Process.Kill(), check.IsNil) + c.Assert(<-chErr, checker.IsNil) + c.Assert(cmd.Process.Kill(), checker.IsNil) // NGoroutines is not updated right away, so we need to wait before failing t := time.After(30 * time.Second) for { select { case <-t: - if n := getNGoroutines(); n > nroutines { - c.Fatalf("leaked goroutines: expected less than or equal to %d, got: %d", nroutines, n) - } + n := getNGoroutines() + c.Assert(n <= nroutines, checker.Equals, true, check.Commentf("leaked goroutines: expected less than or equal to %d, got: %d", nroutines, n)) + default: if n := getNGoroutines(); n <= nroutines { return @@ -337,7 +302,7 @@ func (s *DockerSuite) TestLogsFollowGoroutinesNoOutput(c *check.C) { testRequires(c, DaemonIsLinux) out, _ := dockerCmd(c, "run", "-d", "busybox", "/bin/sh", "-c", "while true; do sleep 2; done") id := strings.TrimSpace(out) - c.Assert(waitRun(id), check.IsNil) + c.Assert(waitRun(id), checker.IsNil) type info struct { NGoroutines int @@ -345,27 +310,27 @@ func (s *DockerSuite) TestLogsFollowGoroutinesNoOutput(c *check.C) { getNGoroutines := func() int { var i info status, b, err := sockRequest("GET", "/info", nil) - c.Assert(err, check.IsNil) - c.Assert(status, check.Equals, 200) - c.Assert(json.Unmarshal(b, &i), check.IsNil) + c.Assert(err, checker.IsNil) + c.Assert(status, checker.Equals, 200) + c.Assert(json.Unmarshal(b, &i), checker.IsNil) return i.NGoroutines } nroutines := getNGoroutines() cmd := exec.Command(dockerBinary, "logs", "-f", id) - c.Assert(cmd.Start(), check.IsNil) + c.Assert(cmd.Start(), checker.IsNil) time.Sleep(200 * time.Millisecond) - c.Assert(cmd.Process.Kill(), check.IsNil) + c.Assert(cmd.Process.Kill(), checker.IsNil) // NGoroutines is not updated right away, so we need to wait before failing t := time.After(30 * time.Second) for { select { case <-t: - if n := getNGoroutines(); n > nroutines { - c.Fatalf("leaked goroutines: expected less than or equal to %d, got: %d", nroutines, n) - } + n := getNGoroutines() + c.Assert(n <= nroutines, checker.Equals, true, check.Commentf("leaked goroutines: expected less than or equal to %d, got: %d", nroutines, n)) + default: if n := getNGoroutines(); n <= nroutines { return @@ -379,5 +344,5 @@ func (s *DockerSuite) TestLogsCLIContainerNotFound(c *check.C) { name := "testlogsnocontainer" out, _, _ := dockerCmdWithError("logs", name) message := fmt.Sprintf(".*no such id: %s.*\n", name) - c.Assert(out, check.Matches, message) + c.Assert(out, checker.Matches, message) }