1
0
Fork 0
mirror of https://github.com/moby/moby.git synced 2022-11-09 12:21:53 -05:00

Use c.Assert in integration-cli/docker_cli_logs_test.go

Signed-off-by: Jian Zhang <zhangjian.fnst@cn.fujitsu.com>
This commit is contained in:
Jian Zhang 2015-10-13 09:50:17 +08:00
parent 7a19164c17
commit 946e8cde53

View file

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