From cb9a6b9aed1577bb5590300125d05d9b1c201c16 Mon Sep 17 00:00:00 2001 From: Ahmet Alp Balkan Date: Tue, 14 Apr 2015 04:36:12 +0000 Subject: [PATCH] Add --since argument to docker logs cmd 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 --- api/client/events.go | 18 +---- api/client/logs.go | 6 ++ api/server/server.go | 10 +++ contrib/completion/bash/docker | 2 +- contrib/completion/fish/docker.fish | 1 + contrib/completion/zsh/_docker | 1 + daemon/logs.go | 13 +++- docs/man/docker-logs.1.md | 5 ++ .../reference/api/docker_remote_api.md | 6 ++ .../reference/api/docker_remote_api_v1.19.md | 4 +- docs/sources/reference/commandline/cli.md | 5 ++ integration-cli/docker_cli_logs_test.go | 75 +++++++++++++++++++ pkg/jsonlog/jsonlog.go | 7 +- pkg/jsonlog/jsonlog_test.go | 4 +- pkg/timeutils/utils.go | 22 ++++++ 15 files changed, 154 insertions(+), 25 deletions(-) create mode 100644 pkg/timeutils/utils.go diff --git a/api/client/events.go b/api/client/events.go index 64ec6e139d..75144b09c7 100644 --- a/api/client/events.go +++ b/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) diff --git a/api/client/logs.go b/api/client/logs.go index 171b36da40..14b936b094 100644 --- a/api/client/logs.go +++ b/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") } diff --git a/api/server/server.go b/api/server/server.go index 4238f7aec3..abec1c6334 100644 --- a/api/server/server.go +++ b/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, diff --git a/contrib/completion/bash/docker b/contrib/completion/bash/docker index 325e50c000..64c53f6de6 100755 --- a/contrib/completion/bash/docker +++ b/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') diff --git a/contrib/completion/fish/docker.fish b/contrib/completion/fish/docker.fish index 42f33e3858..79f7ed4bad 100644 --- a/contrib/completion/fish/docker.fish +++ b/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" diff --git a/contrib/completion/zsh/_docker b/contrib/completion/zsh/_docker index 3cff8fbbb6..abd666313e 100644 --- a/contrib/completion/zsh/_docker +++ b/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' diff --git a/daemon/logs.go b/daemon/logs.go index ae3e997311..384dca4e89 100644 --- a/daemon/logs.go +++ b/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() }() } diff --git a/docs/man/docker-logs.1.md b/docs/man/docker-logs.1.md index 01a15f54dc..e2cacea223 100644 --- a/docs/man/docker-logs.1.md +++ b/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 July 2014, updated by Sven Dowideit +April 2015, updated by Ahmet Alp Balkan diff --git a/docs/sources/reference/api/docker_remote_api.md b/docs/sources/reference/api/docker_remote_api.md index 676f210ebc..9ca8edd512 100644 --- a/docs/sources/reference/api/docker_remote_api.md +++ b/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 diff --git a/docs/sources/reference/api/docker_remote_api_v1.19.md b/docs/sources/reference/api/docker_remote_api_v1.19.md index 0512757fd5..0d2ef93449 100644 --- a/docs/sources/reference/api/docker_remote_api_v1.19.md +++ b/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×tamps=1&follow=1&tail=10 HTTP/1.1 + GET /containers/4fa6e0f0c678/logs?stderr=1&stdout=1×tamps=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 ``. Default all diff --git a/docs/sources/reference/commandline/cli.md b/docs/sources/reference/commandline/cli.md index 30e2f80d0b..85d340d9b0 100644 --- a/docs/sources/reference/commandline/cli.md +++ b/docs/sources/reference/commandline/cli.md @@ -1616,6 +1616,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 @@ -1635,6 +1636,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...] diff --git a/integration-cli/docker_cli_logs_test.go b/integration-cli/docker_cli_logs_test.go index 0a3e1af981..49146868fd 100644 --- a/integration-cli/docker_cli_logs_test.go +++ b/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`) diff --git a/pkg/jsonlog/jsonlog.go b/pkg/jsonlog/jsonlog.go index 261c64cdc3..ce2da4a301 100644 --- a/pkg/jsonlog/jsonlog.go +++ b/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() } } diff --git a/pkg/jsonlog/jsonlog_test.go b/pkg/jsonlog/jsonlog_test.go index fa53825b93..d4b26fcb43 100644 --- a/pkg/jsonlog/jsonlog_test.go +++ b/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() diff --git a/pkg/timeutils/utils.go b/pkg/timeutils/utils.go new file mode 100644 index 0000000000..c0c38facb4 --- /dev/null +++ b/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) +}