mirror of
https://github.com/moby/moby.git
synced 2022-11-09 12:21:53 -05:00
cb9a6b9aed
Added --since argument to `docker logs` command. Accept unix timestamps and shows logs only created after the specified date. Default value is 0 and passing default value or not specifying the value in the request causes parameter to be ignored (behavior prior to this change). Signed-off-by: Ahmet Alp Balkan <ahmetalpbalkan@gmail.com>
395 lines
11 KiB
Go
395 lines
11 KiB
Go
package main
|
|
|
|
import (
|
|
"fmt"
|
|
"os/exec"
|
|
"regexp"
|
|
"strconv"
|
|
"strings"
|
|
"time"
|
|
|
|
"github.com/docker/docker/pkg/timeutils"
|
|
"github.com/go-check/check"
|
|
)
|
|
|
|
// This used to work, it test a log of PageSize-1 (gh#4851)
|
|
func (s *DockerSuite) TestLogsContainerSmallerThanPage(c *check.C) {
|
|
testLen := 32767
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen))
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
if len(out) != testLen+1 {
|
|
c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out))
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
|
|
}
|
|
|
|
// Regression test: When going over the PageSize, it used to panic (gh#4851)
|
|
func (s *DockerSuite) TestLogsContainerBiggerThanPage(c *check.C) {
|
|
testLen := 32768
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen))
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
if len(out) != testLen+1 {
|
|
c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out))
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
|
|
}
|
|
|
|
// Regression test: When going much over the PageSize, it used to block (gh#4851)
|
|
func (s *DockerSuite) TestLogsContainerMuchBiggerThanPage(c *check.C) {
|
|
testLen := 33000
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo -n =; done; echo", testLen))
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
if len(out) != testLen+1 {
|
|
c.Fatalf("Expected log length of %d, received %d\n", testLen+1, len(out))
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsTimestamps(c *check.C) {
|
|
testLen := 100
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo =; done;", testLen))
|
|
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", "-t", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
lines := strings.Split(out, "\n")
|
|
|
|
if len(lines) != testLen+1 {
|
|
c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines))
|
|
}
|
|
|
|
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)
|
|
}
|
|
}
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsSeparateStderr(c *check.C) {
|
|
msg := "stderr_log"
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("echo %s 1>&2", msg))
|
|
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID)
|
|
stdout, stderr, _, err := runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
if stdout != "" {
|
|
c.Fatalf("Expected empty stdout stream, got %v", stdout)
|
|
}
|
|
|
|
stderr = strings.TrimSpace(stderr)
|
|
if stderr != msg {
|
|
c.Fatalf("Expected %v in stderr stream, got %v", msg, stderr)
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsStderrInStdout(c *check.C) {
|
|
msg := "stderr_log"
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "-t", "busybox", "sh", "-c", fmt.Sprintf("echo %s 1>&2", msg))
|
|
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", cleanedContainerID)
|
|
stdout, stderr, _, err := runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
if stderr != "" {
|
|
c.Fatalf("Expected empty stderr stream, got %v", stdout)
|
|
}
|
|
|
|
stdout = strings.TrimSpace(stdout)
|
|
if stdout != msg {
|
|
c.Fatalf("Expected %v in stdout stream, got %v", msg, stdout)
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsTail(c *check.C) {
|
|
testLen := 100
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "sh", "-c", fmt.Sprintf("for i in $(seq 1 %d); do echo =; done;", testLen))
|
|
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", "--tail", "5", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
lines := strings.Split(out, "\n")
|
|
|
|
if len(lines) != 6 {
|
|
c.Fatalf("Expected log %d lines, received %d\n", 6, len(lines))
|
|
}
|
|
|
|
logsCmd = exec.Command(dockerBinary, "logs", "--tail", "all", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
lines = strings.Split(out, "\n")
|
|
|
|
if len(lines) != testLen+1 {
|
|
c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines))
|
|
}
|
|
|
|
logsCmd = exec.Command(dockerBinary, "logs", "--tail", "random", cleanedContainerID)
|
|
out, _, _, err = runCommandWithStdoutStderr(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
lines = strings.Split(out, "\n")
|
|
|
|
if len(lines) != testLen+1 {
|
|
c.Fatalf("Expected log %d lines, received %d\n", testLen+1, len(lines))
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsFollowStopped(c *check.C) {
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "echo", "hello")
|
|
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
|
|
logsCmd := exec.Command(dockerBinary, "logs", "-f", cleanedContainerID)
|
|
if err := logsCmd.Start(); err != nil {
|
|
c.Fatal(err)
|
|
}
|
|
|
|
errChan := make(chan error)
|
|
go func() {
|
|
errChan <- logsCmd.Wait()
|
|
close(errChan)
|
|
}()
|
|
|
|
select {
|
|
case err := <-errChan:
|
|
c.Assert(err, check.IsNil)
|
|
case <-time.After(1 * time.Second):
|
|
c.Fatal("Following logs is hanged")
|
|
}
|
|
|
|
deleteContainer(cleanedContainerID)
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsSince(c *check.C) {
|
|
name := "testlogssince"
|
|
runCmd := exec.Command(dockerBinary, "run", "--name="+name, "busybox", "/bin/sh", "-c", `date +%s; for i in $(seq 1 5); do sleep 1; echo log$i; done`)
|
|
out, _, err := runCommandWithOutput(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
outLines := strings.Split(out, "\n")
|
|
startUnix, _ := strconv.ParseInt(outLines[0], 10, 64)
|
|
since := startUnix + 3
|
|
logsCmd := exec.Command(dockerBinary, "logs", "-t", fmt.Sprintf("--since=%v", since), name)
|
|
|
|
out, _, err = runCommandWithOutput(logsCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
|
|
// 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)
|
|
}
|
|
}
|
|
|
|
// Test with default value specified and parameter omitted
|
|
expected := []string{"log1", "log2", "log3", "log4", "log5"}
|
|
for _, cmd := range []*exec.Cmd{
|
|
exec.Command(dockerBinary, "logs", "-t", name),
|
|
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)
|
|
}
|
|
for _, v := range expected {
|
|
if !strings.Contains(out, v) {
|
|
c.Fatalf("'%v' does not contain=%v\nout=%s", cmd.Args, v, out)
|
|
}
|
|
}
|
|
}
|
|
}
|
|
|
|
func (s *DockerSuite) TestLogsSinceFutureFollow(c *check.C) {
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "/bin/sh", "-c", `for i in $(seq 1 5); do date +%s; sleep 1; done`)
|
|
out, _, err := runCommandWithOutput(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
|
|
now := daemonTime(c).Unix()
|
|
since := now + 2
|
|
logCmd := exec.Command(dockerBinary, "logs", "-f", fmt.Sprintf("--since=%v", since), cleanedContainerID)
|
|
out, _, err = runCommandWithOutput(logCmd)
|
|
if err != nil {
|
|
c.Fatalf("failed to log container: %s, %v", out, err)
|
|
}
|
|
lines := strings.Split(strings.TrimSpace(out), "\n")
|
|
if len(lines) == 0 {
|
|
c.Fatal("got no log lines")
|
|
}
|
|
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)
|
|
}
|
|
}
|
|
}
|
|
|
|
// Regression test for #8832
|
|
func (s *DockerSuite) TestLogsFollowSlowStdoutConsumer(c *check.C) {
|
|
runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "/bin/sh", "-c", `usleep 200000;yes X | head -c 200000`)
|
|
|
|
out, _, _, err := runCommandWithStdoutStderr(runCmd)
|
|
if err != nil {
|
|
c.Fatalf("run failed with errors: %s, %v", out, err)
|
|
}
|
|
|
|
cleanedContainerID := strings.TrimSpace(out)
|
|
|
|
stopSlowRead := make(chan bool)
|
|
|
|
go func() {
|
|
exec.Command(dockerBinary, "wait", cleanedContainerID).Run()
|
|
stopSlowRead <- true
|
|
}()
|
|
|
|
logCmd := exec.Command(dockerBinary, "logs", "-f", cleanedContainerID)
|
|
|
|
stdout, err := logCmd.StdoutPipe()
|
|
c.Assert(err, check.IsNil)
|
|
|
|
if err := logCmd.Start(); err != nil {
|
|
c.Fatal(err)
|
|
}
|
|
|
|
// First read slowly
|
|
bytes1, err := consumeWithSpeed(stdout, 10, 50*time.Millisecond, stopSlowRead)
|
|
c.Assert(err, check.IsNil)
|
|
|
|
// After the container has finished we can continue reading fast
|
|
bytes2, err := consumeWithSpeed(stdout, 32*1024, 0, nil)
|
|
c.Assert(err, check.IsNil)
|
|
|
|
actual := bytes1 + bytes2
|
|
expected := 200000
|
|
if actual != expected {
|
|
c.Fatalf("Invalid bytes read: %d, expected %d", actual, expected)
|
|
}
|
|
|
|
}
|