Merge pull request #12362 from ahmetalpbalkan/logs/since

Add --since argument to docker logs cmd

api/client/events.go

@@ -2,8 +2,6 @@ package client
 
 import (
 	"net/url"
-	"strconv"
-	"time"
 
 	"github.com/docker/docker/opts"
 	flag "github.com/docker/docker/pkg/mflag"
@@ -26,7 +24,6 @@ func (cli *DockerCli) CmdEvents(args ...string) error {
 
 	var (
 		v               = url.Values{}
-		loc             = time.FixedZone(time.Now().Zone())
 		eventFilterArgs = filters.Args{}
 	)
 
@@ -39,22 +36,11 @@ func (cli *DockerCli) CmdEvents(args ...string) error {
 			return err
 		}
 	}
-	var setTime = func(key, value string) {
-		format := timeutils.RFC3339NanoFixed
-		if len(value) < len(format) {
-			format = format[:len(value)]
-		}
-		if t, err := time.ParseInLocation(format, value, loc); err == nil {
-			v.Set(key, strconv.FormatInt(t.Unix(), 10))
-		} else {
-			v.Set(key, value)
-		}
-	}
 	if *since != "" {
-		setTime("since", *since)
+		v.Set("since", timeutils.GetTimestamp(*since))
 	}
 	if *until != "" {
-		setTime("until", *until)
+		v.Set("until", timeutils.GetTimestamp(*until))
 	}
 	if len(eventFilterArgs) > 0 {
 		filterJSON, err := filters.ToParam(eventFilterArgs)

api/client/logs.go

@@ -7,6 +7,7 @@ import (
 
 	"github.com/docker/docker/api/types"
 	flag "github.com/docker/docker/pkg/mflag"
+	"github.com/docker/docker/pkg/timeutils"
 )
 
 // CmdLogs fetches the logs of a given container.
@@ -16,6 +17,7 @@ func (cli *DockerCli) CmdLogs(args ...string) error {
 	var (
 		cmd    = cli.Subcmd("logs", "CONTAINER", "Fetch the logs of a container", true)
 		follow = cmd.Bool([]string{"f", "-follow"}, false, "Follow log output")
+		since  = cmd.String([]string{"-since"}, "", "Show logs since timestamp")
 		times  = cmd.Bool([]string{"t", "-timestamps"}, false, "Show timestamps")
 		tail   = cmd.String([]string{"-tail"}, "all", "Number of lines to show from the end of the logs")
 	)
@@ -43,6 +45,10 @@ func (cli *DockerCli) CmdLogs(args ...string) error {
 	v.Set("stdout", "1")
 	v.Set("stderr", "1")
 
+	if *since != "" {
+		v.Set("since", timeutils.GetTimestamp(*since))
+	}
+
 	if *times {
 		v.Set("timestamps", "1")
 	}

api/server/server.go

@@ -594,9 +594,19 @@ func (s *Server) getContainersLogs(version version.Version, w http.ResponseWrite
 		return fmt.Errorf("Bad parameters: you must choose at least one stream")
 	}
 
+	var since time.Time
+	if r.Form.Get("since") != "" {
+		s, err := strconv.ParseInt(r.Form.Get("since"), 10, 64)
+		if err != nil {
+			return err
+		}
+		since = time.Unix(s, 0)
+	}
+
 	logsConfig := &daemon.ContainerLogsConfig{
 		Follow:     boolValue(r, "follow"),
 		Timestamps: boolValue(r, "timestamps"),
+		Since:      since,
 		Tail:       r.Form.Get("tail"),
 		UseStdout:  stdout,
 		UseStderr:  stderr,

contrib/completion/bash/docker

@@ -593,7 +593,7 @@ _docker_logs() {
 
 	case "$cur" in
 		-*)
-			COMPREPLY=( $( compgen -W "--follow -f --help --tail --timestamps -t" -- "$cur" ) )
+			COMPREPLY=( $( compgen -W "--follow -f --help --since --tail --timestamps -t" -- "$cur" ) )
 			;;
 		*)
 			local counter=$(__docker_pos_first_nonflag '--tail')

contrib/completion/fish/docker.fish

@@ -233,6 +233,7 @@ complete -c docker -f -n '__fish_docker_no_subcommand' -a logs -d 'Fetch the log
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -s f -l follow -d 'Follow log output'
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -l help -d 'Print usage'
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -s t -l timestamps -d 'Show timestamps'
+complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -l since -d 'Show logs since timestamp'
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -l tail -d 'Output the specified number of lines at the end of logs (defaults to all logs)'
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -a '(__fish_print_docker_containers running)' -d "Container"
 

contrib/completion/zsh/_docker

@@ -305,6 +305,7 @@ __docker_subcommand () {
         (logs)
             _arguments \
                 {-f,--follow}'[Follow log output]' \
+                '-s,--since[Show logs since timestamp]' \
                 {-t,--timestamps}'[Show timestamps]' \
                 '--tail=-[Output the last K lines]:lines:(1 10 20 50 all)' \
                 '*:containers:__docker_containers'

daemon/logs.go

@@ -8,6 +8,7 @@ import (
 	"os"
 	"strconv"
 	"sync"
+	"time"
 
 	"github.com/Sirupsen/logrus"
 	"github.com/docker/docker/pkg/jsonlog"
@@ -19,6 +20,7 @@ import (
 type ContainerLogsConfig struct {
 	Follow, Timestamps   bool
 	Tail                 string
+	Since                time.Time
 	UseStdout, UseStderr bool
 	OutStream            io.Writer
 }
@@ -88,6 +90,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
 				lines = -1
 			}
 		}
+
 		if lines != 0 {
 			if lines > 0 {
 				f := cLog.(*os.File)
@@ -101,9 +104,11 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
 				}
 				cLog = tmp
 			}
+
 			dec := json.NewDecoder(cLog)
 			l := &jsonlog.JSONLog{}
 			for {
+				l.Reset()
 				if err := dec.Decode(l); err == io.EOF {
 					break
 				} else if err != nil {
@@ -111,6 +116,9 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
 					break
 				}
 				logLine := l.Log
+				if !config.Since.IsZero() && l.Created.Before(config.Since) {
+					continue
+				}
 				if config.Timestamps {
 					// format can be "" or time format, so here can't be error
 					logLine, _ = l.Format(format)
@@ -121,7 +129,6 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
 				if l.Stream == "stderr" && config.UseStderr {
 					io.WriteString(errStream, logLine)
 				}
-				l.Reset()
 			}
 		}
 	}
@@ -139,7 +146,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
 			stdoutPipe := container.StdoutLogPipe()
 			defer stdoutPipe.Close()
 			go func() {
-				errors <- jsonlog.WriteLog(stdoutPipe, outStream, format)
+				errors <- jsonlog.WriteLog(stdoutPipe, outStream, format, config.Since)
 				wg.Done()
 			}()
 		}
@@ -148,7 +155,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
 			stderrPipe := container.StderrLogPipe()
 			defer stderrPipe.Close()
 			go func() {
-				errors <- jsonlog.WriteLog(stderrPipe, errStream, format)
+				errors <- jsonlog.WriteLog(stderrPipe, errStream, format, config.Since)
 				wg.Done()
 			}()
 		}

docs/man/docker-logs.1.md

@@ -8,6 +8,7 @@ docker-logs - Fetch the logs of a container
 **docker logs**
 [**-f**|**--follow**[=*false*]]
 [**--help**]
+[**--since**[=*SINCE*]]
 [**-t**|**--timestamps**[=*false*]]
 [**--tail**[=*"all"*]]
 CONTAINER
@@ -31,6 +32,9 @@ then continue streaming new output from the container’s stdout and stderr.
 **-f**, **--follow**=*true*|*false*
    Follow log output. The default is *false*.
 
+**--since**=""
+   Show logs since timestamp
+
 **-t**, **--timestamps**=*true*|*false*
    Show timestamps. The default is *false*.
 
@@ -42,3 +46,4 @@ April 2014, Originally compiled by William Henry (whenry at redhat dot com)
 based on docker.com source material and internal work.
 June 2014, updated by Sven Dowideit <SvenDowideit@home.org.au>
 July 2014, updated by Sven Dowideit <SvenDowideit@home.org.au>
+April 2015, updated by Ahmet Alp Balkan <ahmetalpbalkan@gmail.com>

docs/sources/reference/api/docker_remote_api.md

@@ -52,6 +52,12 @@ You can still call an old version of the API using
 You can now supply a `stream` bool to get only one set of stats and
 disconnect
 
+`GET /containers(id)/logs`
+
+**New!**
+
+This endpoint now accepts a `since` timestamp parameter.
+
 ## v1.18
 
 ### Full documentation

docs/sources/reference/api/docker_remote_api_v1.19.md

@@ -477,7 +477,7 @@ Get stdout and stderr logs from the container ``id``
 
 **Example request**:
 
-       GET /containers/4fa6e0f0c678/logs?stderr=1&stdout=1&timestamps=1&follow=1&tail=10 HTTP/1.1
+       GET /containers/4fa6e0f0c678/logs?stderr=1&stdout=1&timestamps=1&follow=1&tail=10&since=1428990821 HTTP/1.1
 
 **Example response**:
 
@@ -493,6 +493,8 @@ Query Parameters:
 -   **follow** – 1/True/true or 0/False/false, return stream. Default false
 -   **stdout** – 1/True/true or 0/False/false, show stdout log. Default false
 -   **stderr** – 1/True/true or 0/False/false, show stderr log. Default false
+-   **since** – UNIX timestamp (integer) to filter logs. Specifying a timestamp
+    will only output log-entries since that timestamp. Default: 0 (unfiltered)
 -   **timestamps** – 1/True/true or 0/False/false, print timestamps for
         every log line. Default false
 -   **tail** – Output specified number of lines at the end of logs: `all` or `<number>`. Default all

docs/sources/reference/commandline/cli.md

@@ -1632,6 +1632,7 @@ For example:
     Fetch the logs of a container
 
       -f, --follow=false        Follow log output
+      --since=""                Show logs since timestamp
       -t, --timestamps=false    Show timestamps
       --tail="all"              Number of lines to show from the end of the logs
 
@@ -1651,6 +1652,10 @@ timestamp, for example `2014-09-16T06:17:46.000000000Z`, to each
 log entry. To ensure that the timestamps for are aligned the
 nano-second part of the timestamp will be padded with zero when necessary.
 
+The `--since` option shows logs of a container generated only after
+the given date, specified as RFC 3339 or UNIX timestamp. The `--since` option
+can be combined with the `--follow` and `--tail` options.
+
 ## pause
 
     Usage: docker pause CONTAINER [CONTAINER...]

integration-cli/docker_cli_logs_test.go

@@ -4,6 +4,7 @@ import (
 	"fmt"
 	"os/exec"
 	"regexp"
+	"strconv"
 	"strings"
 	"time"
 
@@ -276,6 +277,80 @@ func (s *DockerSuite) TestLogsFollowStopped(c *check.C) {
 	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`)

pkg/jsonlog/jsonlog.go

@@ -32,16 +32,20 @@ func (jl *JSONLog) Reset() {
 	jl.Created = time.Time{}
 }
 
-func WriteLog(src io.Reader, dst io.Writer, format string) error {
+func WriteLog(src io.Reader, dst io.Writer, format string, since time.Time) error {
 	dec := json.NewDecoder(src)
 	l := &JSONLog{}
 	for {
+		l.Reset()
 		if err := dec.Decode(l); err == io.EOF {
 			return nil
 		} else if err != nil {
 			logrus.Printf("Error streaming logs: %s", err)
 			return err
 		}
+		if !since.IsZero() && l.Created.Before(since) {
+			continue
+		}
 		line, err := l.Format(format)
 		if err != nil {
 			return err
@@ -49,6 +53,5 @@ func WriteLog(src io.Reader, dst io.Writer, format string) error {
 		if _, err := io.WriteString(dst, line); err != nil {
 			return err
 		}
-		l.Reset()
 	}
 }

pkg/jsonlog/jsonlog_test.go

@@ -21,7 +21,7 @@ func TestWriteLog(t *testing.T) {
 	}
 	w := bytes.NewBuffer(nil)
 	format := timeutils.RFC3339NanoFixed
-	if err := WriteLog(&buf, w, format); err != nil {
+	if err := WriteLog(&buf, w, format, time.Time{}); err != nil {
 		t.Fatal(err)
 	}
 	res := w.String()
@@ -52,7 +52,7 @@ func BenchmarkWriteLog(b *testing.B) {
 	b.SetBytes(int64(r.Len()))
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
-		if err := WriteLog(r, w, format); err != nil {
+		if err := WriteLog(r, w, format, time.Time{}); err != nil {
 			b.Fatal(err)
 		}
 		b.StopTimer()

pkg/timeutils/utils.go

@@ -0,0 +1,22 @@
+package timeutils
+
+import (
+	"strconv"
+	"time"
+)
+
+// GetTimestamp tries to parse given string as RFC3339 time
+// or Unix timestamp, if successful returns a Unix timestamp
+// as string otherwise returns value back.
+func GetTimestamp(value string) string {
+	format := RFC3339NanoFixed
+	loc := time.FixedZone(time.Now().Zone())
+	if len(value) < len(format) {
+		format = format[:len(value)]
+	}
+	t, err := time.ParseInLocation(format, value, loc)
+	if err != nil {
+		return value
+	}
+	return strconv.FormatInt(t.Unix(), 10)
+}