Browse code

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 <ahmetalpbalkan@gmail.com>

Ahmet Alp Balkan authored on 2015/04/14 13:36:12
Showing 15 changed files
... ...
@@ -2,8 +2,6 @@ package client
2 2
 
3 3
 import (
4 4
 	"net/url"
5
-	"strconv"
6
-	"time"
7 5
 
8 6
 	"github.com/docker/docker/opts"
9 7
 	flag "github.com/docker/docker/pkg/mflag"
... ...
@@ -26,7 +24,6 @@ func (cli *DockerCli) CmdEvents(args ...string) error {
26 26
 
27 27
 	var (
28 28
 		v               = url.Values{}
29
-		loc             = time.FixedZone(time.Now().Zone())
30 29
 		eventFilterArgs = filters.Args{}
31 30
 	)
32 31
 
... ...
@@ -39,22 +36,11 @@ func (cli *DockerCli) CmdEvents(args ...string) error {
39 39
 			return err
40 40
 		}
41 41
 	}
42
-	var setTime = func(key, value string) {
43
-		format := timeutils.RFC3339NanoFixed
44
-		if len(value) < len(format) {
45
-			format = format[:len(value)]
46
-		}
47
-		if t, err := time.ParseInLocation(format, value, loc); err == nil {
48
-			v.Set(key, strconv.FormatInt(t.Unix(), 10))
49
-		} else {
50
-			v.Set(key, value)
51
-		}
52
-	}
53 42
 	if *since != "" {
54
-		setTime("since", *since)
43
+		v.Set("since", timeutils.GetTimestamp(*since))
55 44
 	}
56 45
 	if *until != "" {
57
-		setTime("until", *until)
46
+		v.Set("until", timeutils.GetTimestamp(*until))
58 47
 	}
59 48
 	if len(eventFilterArgs) > 0 {
60 49
 		filterJSON, err := filters.ToParam(eventFilterArgs)
... ...
@@ -7,6 +7,7 @@ import (
7 7
 
8 8
 	"github.com/docker/docker/api/types"
9 9
 	flag "github.com/docker/docker/pkg/mflag"
10
+	"github.com/docker/docker/pkg/timeutils"
10 11
 )
11 12
 
12 13
 // CmdLogs fetches the logs of a given container.
... ...
@@ -16,6 +17,7 @@ func (cli *DockerCli) CmdLogs(args ...string) error {
16 16
 	var (
17 17
 		cmd    = cli.Subcmd("logs", "CONTAINER", "Fetch the logs of a container", true)
18 18
 		follow = cmd.Bool([]string{"f", "-follow"}, false, "Follow log output")
19
+		since  = cmd.String([]string{"-since"}, "", "Show logs since timestamp")
19 20
 		times  = cmd.Bool([]string{"t", "-timestamps"}, false, "Show timestamps")
20 21
 		tail   = cmd.String([]string{"-tail"}, "all", "Number of lines to show from the end of the logs")
21 22
 	)
... ...
@@ -43,6 +45,10 @@ func (cli *DockerCli) CmdLogs(args ...string) error {
43 43
 	v.Set("stdout", "1")
44 44
 	v.Set("stderr", "1")
45 45
 
46
+	if *since != "" {
47
+		v.Set("since", timeutils.GetTimestamp(*since))
48
+	}
49
+
46 50
 	if *times {
47 51
 		v.Set("timestamps", "1")
48 52
 	}
... ...
@@ -594,9 +594,19 @@ func (s *Server) getContainersLogs(version version.Version, w http.ResponseWrite
594 594
 		return fmt.Errorf("Bad parameters: you must choose at least one stream")
595 595
 	}
596 596
 
597
+	var since time.Time
598
+	if r.Form.Get("since") != "" {
599
+		s, err := strconv.ParseInt(r.Form.Get("since"), 10, 64)
600
+		if err != nil {
601
+			return err
602
+		}
603
+		since = time.Unix(s, 0)
604
+	}
605
+
597 606
 	logsConfig := &daemon.ContainerLogsConfig{
598 607
 		Follow:     boolValue(r, "follow"),
599 608
 		Timestamps: boolValue(r, "timestamps"),
609
+		Since:      since,
600 610
 		Tail:       r.Form.Get("tail"),
601 611
 		UseStdout:  stdout,
602 612
 		UseStderr:  stderr,
... ...
@@ -593,7 +593,7 @@ _docker_logs() {
593 593
 
594 594
 	case "$cur" in
595 595
 		-*)
596
-			COMPREPLY=( $( compgen -W "--follow -f --help --tail --timestamps -t" -- "$cur" ) )
596
+			COMPREPLY=( $( compgen -W "--follow -f --help --since --tail --timestamps -t" -- "$cur" ) )
597 597
 			;;
598 598
 		*)
599 599
 			local counter=$(__docker_pos_first_nonflag '--tail')
... ...
@@ -233,6 +233,7 @@ complete -c docker -f -n '__fish_docker_no_subcommand' -a logs -d 'Fetch the log
233 233
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -s f -l follow -d 'Follow log output'
234 234
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -l help -d 'Print usage'
235 235
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -s t -l timestamps -d 'Show timestamps'
236
+complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -l since -d 'Show logs since timestamp'
236 237
 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)'
237 238
 complete -c docker -A -f -n '__fish_seen_subcommand_from logs' -a '(__fish_print_docker_containers running)' -d "Container"
238 239
 
... ...
@@ -305,6 +305,7 @@ __docker_subcommand () {
305 305
         (logs)
306 306
             _arguments \
307 307
                 {-f,--follow}'[Follow log output]' \
308
+                '-s,--since[Show logs since timestamp]' \
308 309
                 {-t,--timestamps}'[Show timestamps]' \
309 310
                 '--tail=-[Output the last K lines]:lines:(1 10 20 50 all)' \
310 311
                 '*:containers:__docker_containers'
... ...
@@ -8,6 +8,7 @@ import (
8 8
 	"os"
9 9
 	"strconv"
10 10
 	"sync"
11
+	"time"
11 12
 
12 13
 	"github.com/Sirupsen/logrus"
13 14
 	"github.com/docker/docker/pkg/jsonlog"
... ...
@@ -19,6 +20,7 @@ import (
19 19
 type ContainerLogsConfig struct {
20 20
 	Follow, Timestamps   bool
21 21
 	Tail                 string
22
+	Since                time.Time
22 23
 	UseStdout, UseStderr bool
23 24
 	OutStream            io.Writer
24 25
 }
... ...
@@ -88,6 +90,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
88 88
 				lines = -1
89 89
 			}
90 90
 		}
91
+
91 92
 		if lines != 0 {
92 93
 			if lines > 0 {
93 94
 				f := cLog.(*os.File)
... ...
@@ -101,9 +104,11 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
101 101
 				}
102 102
 				cLog = tmp
103 103
 			}
104
+
104 105
 			dec := json.NewDecoder(cLog)
105 106
 			l := &jsonlog.JSONLog{}
106 107
 			for {
108
+				l.Reset()
107 109
 				if err := dec.Decode(l); err == io.EOF {
108 110
 					break
109 111
 				} else if err != nil {
... ...
@@ -111,6 +116,9 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
111 111
 					break
112 112
 				}
113 113
 				logLine := l.Log
114
+				if !config.Since.IsZero() && l.Created.Before(config.Since) {
115
+					continue
116
+				}
114 117
 				if config.Timestamps {
115 118
 					// format can be "" or time format, so here can't be error
116 119
 					logLine, _ = l.Format(format)
... ...
@@ -121,7 +129,6 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
121 121
 				if l.Stream == "stderr" && config.UseStderr {
122 122
 					io.WriteString(errStream, logLine)
123 123
 				}
124
-				l.Reset()
125 124
 			}
126 125
 		}
127 126
 	}
... ...
@@ -139,7 +146,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
139 139
 			stdoutPipe := container.StdoutLogPipe()
140 140
 			defer stdoutPipe.Close()
141 141
 			go func() {
142
-				errors <- jsonlog.WriteLog(stdoutPipe, outStream, format)
142
+				errors <- jsonlog.WriteLog(stdoutPipe, outStream, format, config.Since)
143 143
 				wg.Done()
144 144
 			}()
145 145
 		}
... ...
@@ -148,7 +155,7 @@ func (daemon *Daemon) ContainerLogs(name string, config *ContainerLogsConfig) er
148 148
 			stderrPipe := container.StderrLogPipe()
149 149
 			defer stderrPipe.Close()
150 150
 			go func() {
151
-				errors <- jsonlog.WriteLog(stderrPipe, errStream, format)
151
+				errors <- jsonlog.WriteLog(stderrPipe, errStream, format, config.Since)
152 152
 				wg.Done()
153 153
 			}()
154 154
 		}
... ...
@@ -8,6 +8,7 @@ docker-logs - Fetch the logs of a container
8 8
 **docker logs**
9 9
 [**-f**|**--follow**[=*false*]]
10 10
 [**--help**]
11
+[**--since**[=*SINCE*]]
11 12
 [**-t**|**--timestamps**[=*false*]]
12 13
 [**--tail**[=*"all"*]]
13 14
 CONTAINER
... ...
@@ -31,6 +32,9 @@ then continue streaming new output from the container’s stdout and stderr.
31 31
 **-f**, **--follow**=*true*|*false*
32 32
    Follow log output. The default is *false*.
33 33
 
34
+**--since**=""
35
+   Show logs since timestamp
36
+
34 37
 **-t**, **--timestamps**=*true*|*false*
35 38
    Show timestamps. The default is *false*.
36 39
 
... ...
@@ -42,3 +46,4 @@ April 2014, Originally compiled by William Henry (whenry at redhat dot com)
42 42
 based on docker.com source material and internal work.
43 43
 June 2014, updated by Sven Dowideit <SvenDowideit@home.org.au>
44 44
 July 2014, updated by Sven Dowideit <SvenDowideit@home.org.au>
45
+April 2015, updated by Ahmet Alp Balkan <ahmetalpbalkan@gmail.com>
... ...
@@ -52,6 +52,12 @@ You can still call an old version of the API using
52 52
 You can now supply a `stream` bool to get only one set of stats and
53 53
 disconnect
54 54
 
55
+`GET /containers(id)/logs`
56
+
57
+**New!**
58
+
59
+This endpoint now accepts a `since` timestamp parameter.
60
+
55 61
 ## v1.18
56 62
 
57 63
 ### Full documentation
... ...
@@ -477,7 +477,7 @@ Get stdout and stderr logs from the container ``id``
477 477
 
478 478
 **Example request**:
479 479
 
480
-       GET /containers/4fa6e0f0c678/logs?stderr=1&stdout=1&timestamps=1&follow=1&tail=10 HTTP/1.1
480
+       GET /containers/4fa6e0f0c678/logs?stderr=1&stdout=1&timestamps=1&follow=1&tail=10&since=1428990821 HTTP/1.1
481 481
 
482 482
 **Example response**:
483 483
 
... ...
@@ -493,6 +493,8 @@ Query Parameters:
493 493
 -   **follow** – 1/True/true or 0/False/false, return stream. Default false
494 494
 -   **stdout** – 1/True/true or 0/False/false, show stdout log. Default false
495 495
 -   **stderr** – 1/True/true or 0/False/false, show stderr log. Default false
496
+-   **since** – UNIX timestamp (integer) to filter logs. Specifying a timestamp
497
+    will only output log-entries since that timestamp. Default: 0 (unfiltered)
496 498
 -   **timestamps** – 1/True/true or 0/False/false, print timestamps for
497 499
         every log line. Default false
498 500
 -   **tail** – Output specified number of lines at the end of logs: `all` or `<number>`. Default all
... ...
@@ -1616,6 +1616,7 @@ For example:
1616 1616
     Fetch the logs of a container
1617 1617
 
1618 1618
       -f, --follow=false        Follow log output
1619
+      --since=""                Show logs since timestamp
1619 1620
       -t, --timestamps=false    Show timestamps
1620 1621
       --tail="all"              Number of lines to show from the end of the logs
1621 1622
 
... ...
@@ -1635,6 +1636,10 @@ timestamp, for example `2014-09-16T06:17:46.000000000Z`, to each
1635 1635
 log entry. To ensure that the timestamps for are aligned the
1636 1636
 nano-second part of the timestamp will be padded with zero when necessary.
1637 1637
 
1638
+The `--since` option shows logs of a container generated only after
1639
+the given date, specified as RFC 3339 or UNIX timestamp. The `--since` option
1640
+can be combined with the `--follow` and `--tail` options.
1641
+
1638 1642
 ## pause
1639 1643
 
1640 1644
     Usage: docker pause CONTAINER [CONTAINER...]
... ...
@@ -4,6 +4,7 @@ import (
4 4
 	"fmt"
5 5
 	"os/exec"
6 6
 	"regexp"
7
+	"strconv"
7 8
 	"strings"
8 9
 	"time"
9 10
 
... ...
@@ -276,6 +277,80 @@ func (s *DockerSuite) TestLogsFollowStopped(c *check.C) {
276 276
 	deleteContainer(cleanedContainerID)
277 277
 }
278 278
 
279
+func (s *DockerSuite) TestLogsSince(c *check.C) {
280
+	name := "testlogssince"
281
+	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`)
282
+	out, _, err := runCommandWithOutput(runCmd)
283
+	if err != nil {
284
+		c.Fatalf("run failed with errors: %s, %v", out, err)
285
+	}
286
+
287
+	outLines := strings.Split(out, "\n")
288
+	startUnix, _ := strconv.ParseInt(outLines[0], 10, 64)
289
+	since := startUnix + 3
290
+	logsCmd := exec.Command(dockerBinary, "logs", "-t", fmt.Sprintf("--since=%v", since), name)
291
+
292
+	out, _, err = runCommandWithOutput(logsCmd)
293
+	if err != nil {
294
+		c.Fatalf("failed to log container: %s, %v", out, err)
295
+	}
296
+
297
+	// Skip 2 seconds
298
+	unexpected := []string{"log1", "log2"}
299
+	for _, v := range unexpected {
300
+		if strings.Contains(out, v) {
301
+			c.Fatalf("unexpected log message returned=%v, since=%v\nout=%v", v, since, out)
302
+		}
303
+	}
304
+
305
+	// Test with default value specified and parameter omitted
306
+	expected := []string{"log1", "log2", "log3", "log4", "log5"}
307
+	for _, cmd := range []*exec.Cmd{
308
+		exec.Command(dockerBinary, "logs", "-t", name),
309
+		exec.Command(dockerBinary, "logs", "-t", "--since=0", name),
310
+	} {
311
+		out, _, err = runCommandWithOutput(cmd)
312
+		if err != nil {
313
+			c.Fatalf("failed to log container: %s, %v", out, err)
314
+		}
315
+		for _, v := range expected {
316
+			if !strings.Contains(out, v) {
317
+				c.Fatalf("'%v' does not contain=%v\nout=%s", cmd.Args, v, out)
318
+			}
319
+		}
320
+	}
321
+}
322
+
323
+func (s *DockerSuite) TestLogsSinceFutureFollow(c *check.C) {
324
+	runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "/bin/sh", "-c", `for i in $(seq 1 5); do date +%s; sleep 1; done`)
325
+	out, _, err := runCommandWithOutput(runCmd)
326
+	if err != nil {
327
+		c.Fatalf("run failed with errors: %s, %v", out, err)
328
+	}
329
+	cleanedContainerID := strings.TrimSpace(out)
330
+
331
+	now := daemonTime(c).Unix()
332
+	since := now + 2
333
+	logCmd := exec.Command(dockerBinary, "logs", "-f", fmt.Sprintf("--since=%v", since), cleanedContainerID)
334
+	out, _, err = runCommandWithOutput(logCmd)
335
+	if err != nil {
336
+		c.Fatalf("failed to log container: %s, %v", out, err)
337
+	}
338
+	lines := strings.Split(strings.TrimSpace(out), "\n")
339
+	if len(lines) == 0 {
340
+		c.Fatal("got no log lines")
341
+	}
342
+	for _, v := range lines {
343
+		ts, err := strconv.ParseInt(v, 10, 64)
344
+		if err != nil {
345
+			c.Fatalf("cannot parse timestamp output from log: '%v'\nout=%s", v, out)
346
+		}
347
+		if ts < since {
348
+			c.Fatalf("earlier log found. since=%v logdate=%v", since, ts)
349
+		}
350
+	}
351
+}
352
+
279 353
 // Regression test for #8832
280 354
 func (s *DockerSuite) TestLogsFollowSlowStdoutConsumer(c *check.C) {
281 355
 	runCmd := exec.Command(dockerBinary, "run", "-d", "busybox", "/bin/sh", "-c", `usleep 200000;yes X | head -c 200000`)
... ...
@@ -32,16 +32,20 @@ func (jl *JSONLog) Reset() {
32 32
 	jl.Created = time.Time{}
33 33
 }
34 34
 
35
-func WriteLog(src io.Reader, dst io.Writer, format string) error {
35
+func WriteLog(src io.Reader, dst io.Writer, format string, since time.Time) error {
36 36
 	dec := json.NewDecoder(src)
37 37
 	l := &JSONLog{}
38 38
 	for {
39
+		l.Reset()
39 40
 		if err := dec.Decode(l); err == io.EOF {
40 41
 			return nil
41 42
 		} else if err != nil {
42 43
 			logrus.Printf("Error streaming logs: %s", err)
43 44
 			return err
44 45
 		}
46
+		if !since.IsZero() && l.Created.Before(since) {
47
+			continue
48
+		}
45 49
 		line, err := l.Format(format)
46 50
 		if err != nil {
47 51
 			return err
... ...
@@ -49,6 +53,5 @@ func WriteLog(src io.Reader, dst io.Writer, format string) error {
49 49
 		if _, err := io.WriteString(dst, line); err != nil {
50 50
 			return err
51 51
 		}
52
-		l.Reset()
53 52
 	}
54 53
 }
... ...
@@ -21,7 +21,7 @@ func TestWriteLog(t *testing.T) {
21 21
 	}
22 22
 	w := bytes.NewBuffer(nil)
23 23
 	format := timeutils.RFC3339NanoFixed
24
-	if err := WriteLog(&buf, w, format); err != nil {
24
+	if err := WriteLog(&buf, w, format, time.Time{}); err != nil {
25 25
 		t.Fatal(err)
26 26
 	}
27 27
 	res := w.String()
... ...
@@ -52,7 +52,7 @@ func BenchmarkWriteLog(b *testing.B) {
52 52
 	b.SetBytes(int64(r.Len()))
53 53
 	b.ResetTimer()
54 54
 	for i := 0; i < b.N; i++ {
55
-		if err := WriteLog(r, w, format); err != nil {
55
+		if err := WriteLog(r, w, format, time.Time{}); err != nil {
56 56
 			b.Fatal(err)
57 57
 		}
58 58
 		b.StopTimer()
59 59
new file mode 100644
... ...
@@ -0,0 +1,22 @@
0
+package timeutils
1
+
2
+import (
3
+	"strconv"
4
+	"time"
5
+)
6
+
7
+// GetTimestamp tries to parse given string as RFC3339 time
8
+// or Unix timestamp, if successful returns a Unix timestamp
9
+// as string otherwise returns value back.
10
+func GetTimestamp(value string) string {
11
+	format := RFC3339NanoFixed
12
+	loc := time.FixedZone(time.Now().Zone())
13
+	if len(value) < len(format) {
14
+		format = format[:len(value)]
15
+	}
16
+	t, err := time.ParseInLocation(format, value, loc)
17
+	if err != nil {
18
+		return value
19
+	}
20
+	return strconv.FormatInt(t.Unix(), 10)
21
+}