From 430d8ff6113e41edc4605267081fa424a9bfe19f Mon Sep 17 00:00:00 2001 From: Mike Brown Date: Thu, 29 Oct 2015 12:51:36 -0500 Subject: [PATCH] modifying docker --since and --until to support nanoseconds and time zones Signed-off-by: Mike Brown --- api/client/events.go | 12 ++- api/client/logs.go | 6 +- api/server/router/local/container.go | 5 +- api/server/router/local/info.go | 11 +-- docs/reference/commandline/events.md | 16 +++- docs/reference/commandline/logs.md | 17 ++-- integration-cli/docker_cli_logs_test.go | 5 ++ man/docker-events.1.md | 22 +++-- man/docker-logs.1.md | 18 ++-- pkg/timeutils/utils.go | 108 +++++++++++++++++++++--- pkg/timeutils/utils_test.go | 93 +++++++++++++++----- 11 files changed, 251 insertions(+), 62 deletions(-) diff --git a/api/client/events.go b/api/client/events.go index 435b13e6d9..4009625a1e 100644 --- a/api/client/events.go +++ b/api/client/events.go @@ -40,10 +40,18 @@ func (cli *DockerCli) CmdEvents(args ...string) error { } ref := time.Now() if *since != "" { - v.Set("since", timeutils.GetTimestamp(*since, ref)) + ts, err := timeutils.GetTimestamp(*since, ref) + if err != nil { + return err + } + v.Set("since", ts) } if *until != "" { - v.Set("until", timeutils.GetTimestamp(*until, ref)) + ts, err := timeutils.GetTimestamp(*until, ref) + if err != nil { + return err + } + v.Set("until", ts) } if len(eventFilterArgs) > 0 { filterJSON, err := filters.ToParam(eventFilterArgs) diff --git a/api/client/logs.go b/api/client/logs.go index f6704542b9..2830fa66da 100644 --- a/api/client/logs.go +++ b/api/client/logs.go @@ -41,7 +41,11 @@ func (cli *DockerCli) CmdLogs(args ...string) error { v.Set("stderr", "1") if *since != "" { - v.Set("since", timeutils.GetTimestamp(*since, time.Now())) + ts, err := timeutils.GetTimestamp(*since, time.Now()) + if err != nil { + return err + } + v.Set("since", ts) } if *times { diff --git a/api/server/router/local/container.go b/api/server/router/local/container.go index bedcae01f0..1c6a5fce91 100644 --- a/api/server/router/local/container.go +++ b/api/server/router/local/container.go @@ -17,6 +17,7 @@ import ( derr "github.com/docker/docker/errors" "github.com/docker/docker/pkg/ioutils" "github.com/docker/docker/pkg/signal" + "github.com/docker/docker/pkg/timeutils" "github.com/docker/docker/runconfig" "github.com/docker/docker/utils" "golang.org/x/net/context" @@ -100,11 +101,11 @@ func (s *router) getContainersLogs(ctx context.Context, w http.ResponseWriter, r var since time.Time if r.Form.Get("since") != "" { - s, err := strconv.ParseInt(r.Form.Get("since"), 10, 64) + s, n, err := timeutils.ParseTimestamps(r.Form.Get("since"), 0) if err != nil { return err } - since = time.Unix(s, 0) + since = time.Unix(s, n) } var closeNotifier <-chan bool diff --git a/api/server/router/local/info.go b/api/server/router/local/info.go index e1349c504f..fb5bfda9d8 100644 --- a/api/server/router/local/info.go +++ b/api/server/router/local/info.go @@ -15,6 +15,7 @@ import ( "github.com/docker/docker/pkg/jsonmessage" "github.com/docker/docker/pkg/parsers/filters" "github.com/docker/docker/pkg/parsers/kernel" + "github.com/docker/docker/pkg/timeutils" "github.com/docker/docker/utils" "golang.org/x/net/context" ) @@ -56,19 +57,19 @@ func (s *router) getEvents(ctx context.Context, w http.ResponseWriter, r *http.R if err := httputils.ParseForm(r); err != nil { return err } - since, err := httputils.Int64ValueOrDefault(r, "since", -1) + since, sinceNano, err := timeutils.ParseTimestamps(r.Form.Get("since"), -1) if err != nil { return err } - until, err := httputils.Int64ValueOrDefault(r, "until", -1) + until, untilNano, err := timeutils.ParseTimestamps(r.Form.Get("until"), -1) if err != nil { return err } timer := time.NewTimer(0) timer.Stop() - if until > 0 { - dur := time.Unix(until, 0).Sub(time.Now()) + if until > 0 || untilNano > 0 { + dur := time.Unix(until, untilNano).Sub(time.Now()) timer = time.NewTimer(dur) } @@ -108,7 +109,7 @@ func (s *router) getEvents(ctx context.Context, w http.ResponseWriter, r *http.R current = nil } for _, ev := range current { - if ev.Time < since { + if ev.Time < since || ((ev.Time == since) && (ev.TimeNano < sinceNano)) { continue } if err := handleEvent(ev); err != nil { diff --git a/docs/reference/commandline/events.md b/docs/reference/commandline/events.md index d923573096..df88717385 100644 --- a/docs/reference/commandline/events.md +++ b/docs/reference/commandline/events.md @@ -27,10 +27,18 @@ and Docker images will report: delete, import, pull, push, tag, untag -The `--since` and `--until` parameters can be Unix timestamps, RFC3339 -dates or Go duration strings (e.g. `10m`, `1h30m`) computed relative to -client machine’s time. If you do not provide the --since option, the command -returns only new and/or live events. +The `--since` and `--until` parameters can be Unix timestamps, date formated +timestamps, or Go duration strings (e.g. `10m`, `1h30m`) computed +relative to the client machine’s time. If you do not provide the --since option, +the command returns only new and/or live events. Supported formats for date +formated time stamps include RFC3339Nano, RFC3339, `2006-01-02T15:04:05`, +`2006-01-02T15:04:05.999999999`, `2006-01-02Z07:00`, and `2006-01-02`. The local +timezone on the client will be used if you do not provide either a `Z` or a +`+-00:00` timezone offset at the end of the timestamp. When providing Unix +timestamps enter seconds[.nanoseconds], where seconds is the number of seconds +that have elapsed since January 1, 1970 (midnight UTC/GMT), not counting leap +seconds (aka Unix epoch or Unix time), and the optional .nanoseconds field is a +fraction of a second no more than nine digits long. ## Filtering diff --git a/docs/reference/commandline/logs.md b/docs/reference/commandline/logs.md index 27d68ead87..601c475bd4 100644 --- a/docs/reference/commandline/logs.md +++ b/docs/reference/commandline/logs.md @@ -31,13 +31,20 @@ the container's `STDOUT` and `STDERR`. Passing a negative number or a non-integer to `--tail` is invalid and the value is set to `all` in that case. -The `docker logs --timestamp` commands will add an [RFC3339Nano timestamp](https://golang.org/pkg/time/#pkg-constants) +The `docker logs --timestamps` command will add an [RFC3339Nano timestamp](https://golang.org/pkg/time/#pkg-constants) , for example `2014-09-16T06:17:46.000000000Z`, to each -log entry. To ensure that the timestamps for are aligned the +log entry. To ensure that the timestamps are aligned the nano-second part of the timestamp will be padded with zero when necessary. The `--since` option shows only the container logs generated after a given date. You can specify the date as an RFC 3339 date, a UNIX -timestamp, or a Go duration string (e.g. `1m30s`, `3h`). Docker computes -the date relative to the client machine’s time. You can combine -the `--since` option with either or both of the `--follow` or `--tail` options. +timestamp, or a Go duration string (e.g. `1m30s`, `3h`). Besides RFC3339 date +format you may also use RFC3339Nano, `2006-01-02T15:04:05`, +`2006-01-02T15:04:05.999999999`, `2006-01-02Z07:00`, and `2006-01-02`. The local +timezone on the client will be used if you do not provide either a `Z` or a +`+-00:00` timezone offset at the end of the timestamp. When providing Unix +timestamps enter seconds[.nanoseconds], where seconds is the number of seconds +that have elapsed since January 1, 1970 (midnight UTC/GMT), not counting leap +seconds (aka Unix epoch or Unix time), and the optional .nanoseconds field is a +fraction of a second no more than nine digits long. You can combine the +`--since` option with either or both of the `--follow` or `--tail` options. diff --git a/integration-cli/docker_cli_logs_test.go b/integration-cli/docker_cli_logs_test.go index 8afc6133c7..e93a1aa93f 100644 --- a/integration-cli/docker_cli_logs_test.go +++ b/integration-cli/docker_cli_logs_test.go @@ -182,6 +182,11 @@ func (s *DockerSuite) TestLogsSince(c *check.C) { for _, v := range unexpected { c.Assert(out, checker.Not(checker.Contains), v, check.Commentf("unexpected log message returned, since=%v", since)) } + + // Test to make sure a bad since format is caught by the client + out, _, _ = dockerCmdWithError("logs", "-t", "--since=2006-01-02T15:04:0Z", name) + c.Assert(out, checker.Contains, "cannot parse \"0Z\" as \"05\"", check.Commentf("bad since format passed to server")) + // Test with default value specified and parameter omitted expected := []string{"log1", "log2", "log3"} for _, cmd := range []*exec.Cmd{ diff --git a/man/docker-events.1.md b/man/docker-events.1.md index 87d921cdaa..bf0eda92eb 100644 --- a/man/docker-events.1.md +++ b/man/docker-events.1.md @@ -37,10 +37,19 @@ and Docker images will report: **--until**="" Stream events until this timestamp -You can specify `--since` and `--until` parameters as an RFC 3339 date, -a UNIX timestamp, or a Go duration string (e.g. `1m30s`, `3h`). Docker computes -the date relative to the client machine’s time. - +The `--since` and `--until` parameters can be Unix timestamps, date formated +timestamps, or Go duration strings (e.g. `10m`, `1h30m`) computed +relative to the client machine’s time. If you do not provide the --since option, +the command returns only new and/or live events. Supported formats for date +formated time stamps include RFC3339Nano, RFC3339, `2006-01-02T15:04:05`, +`2006-01-02T15:04:05.999999999`, `2006-01-02Z07:00`, and `2006-01-02`. The local +timezone on the client will be used if you do not provide either a `Z` or a +`+-00:00` timezone offset at the end of the timestamp. When providing Unix +timestamps enter seconds[.nanoseconds], where seconds is the number of seconds +that have elapsed since January 1, 1970 (midnight UTC/GMT), not counting leap +seconds (aka Unix epoch or Unix time), and the optional .nanoseconds field is a +fraction of a second no more than nine digits long. + # EXAMPLES ## Listening for Docker events @@ -71,8 +80,8 @@ The following example outputs all events that were generated in the last 3 minut relative to the current time on the client machine: # docker events --since '3m' - 2015-05-12T11:51:30.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die - 2015-05-12T15:52:12.999999999Z07:00 4 4386fb97867d: (from ubuntu-1:14.04) stop + 2015-05-12T11:51:30.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) die + 2015-05-12T15:52:12.999999999Z07:00 4386fb97867d: (from ubuntu-1:14.04) stop 2015-05-12T15:53:45.999999999Z07:00 7805c1d35632: (from redis:2.8) die 2015-05-12T15:54:03.999999999Z07:00 7805c1d35632: (from redis:2.8) stop @@ -84,3 +93,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 June 2015, updated by Brian Goff +October 2015, updated by Mike Brown diff --git a/man/docker-logs.1.md b/man/docker-logs.1.md index 2925c35009..a49d16de31 100644 --- a/man/docker-logs.1.md +++ b/man/docker-logs.1.md @@ -42,11 +42,18 @@ logging drivers. **--tail**="all" Output the specified number of lines at the end of logs (defaults to all logs) -The `--since` option shows only the container logs generated after -a given date. You can specify the date as an RFC 3339 date, a UNIX -timestamp, or a Go duration string (e.g. `1m30s`, `3h`). Docker computes -the date relative to the client machine’s time. You can combine -the `--since` option with either or both of the `--follow` or `--tail` options. +The `--since` option can be Unix timestamps, date formated timestamps, or Go +duration strings (e.g. `10m`, `1h30m`) computed relative to the client machine’s +time. Supported formats for date formated time stamps include RFC3339Nano, +RFC3339, `2006-01-02T15:04:05`, `2006-01-02T15:04:05.999999999`, +`2006-01-02Z07:00`, and `2006-01-02`. The local timezone on the client will be +used if you do not provide either a `Z` or a `+-00:00` timezone offset at the +end of the timestamp. When providing Unix timestamps enter +seconds[.nanoseconds], where seconds is the number of seconds that have elapsed +since January 1, 1970 (midnight UTC/GMT), not counting leap seconds (aka Unix +epoch or Unix time), and the optional .nanoseconds field is a fraction of a +second no more than nine digits long. You can combine the `--since` option with +either or both of the `--follow` or `--tail` options. # HISTORY April 2014, Originally compiled by William Henry (whenry at redhat dot com) @@ -54,3 +61,4 @@ 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 +October 2015, updated by Mike Brown diff --git a/pkg/timeutils/utils.go b/pkg/timeutils/utils.go index 8437f12472..7502e88553 100644 --- a/pkg/timeutils/utils.go +++ b/pkg/timeutils/utils.go @@ -1,36 +1,124 @@ package timeutils import ( + "fmt" + "math" "strconv" "strings" "time" ) +// These are additional predefined layouts for use in Time.Format and Time.Parse +// with --since and --until parameters for `docker logs` and `docker events` +const ( + rFC3339Local = "2006-01-02T15:04:05" // RFC3339 with local timezone + rFC3339NanoLocal = "2006-01-02T15:04:05.999999999" // RFC3339Nano with local timezone + dateWithZone = "2006-01-02Z07:00" // RFC3339 with time at 00:00:00 + dateLocal = "2006-01-02" // RFC3339 with local timezone and time at 00:00:00 +) + // GetTimestamp tries to parse given string as golang duration, // then RFC3339 time and finally as a Unix timestamp. If // any of these were successful, it returns a Unix timestamp // as string otherwise returns the given value back. // In case of duration input, the returned timestamp is computed // as the given reference time minus the amount of the duration. -func GetTimestamp(value string, reference time.Time) string { +func GetTimestamp(value string, reference time.Time) (string, error) { if d, err := time.ParseDuration(value); value != "0" && err == nil { - return strconv.FormatInt(reference.Add(-d).Unix(), 10) + return strconv.FormatInt(reference.Add(-d).Unix(), 10), nil } var format string + var parseInLocation bool + + // if the string has a Z or a + or three dashes use parse otherwise use parseinlocation + parseInLocation = !(strings.ContainsAny(value, "zZ+") || strings.Count(value, "-") == 3) + if strings.Contains(value, ".") { - format = time.RFC3339Nano + if parseInLocation { + format = rFC3339NanoLocal + } else { + format = time.RFC3339Nano + } + } else if strings.Contains(value, "T") { + // we want the number of colons in the T portion of the timestamp + tcolons := strings.Count(value, ":") + // if parseInLocation is off and we have a +/- zone offset (not Z) then + // there will be an extra colon in the input for the tz offset subract that + // colon from the tcolons count + if !parseInLocation && !strings.ContainsAny(value, "zZ") && tcolons > 0 { + tcolons-- + } + if parseInLocation { + switch tcolons { + case 0: + format = "2006-01-02T15" + case 1: + format = "2006-01-02T15:04" + default: + format = rFC3339Local + } + } else { + switch tcolons { + case 0: + format = "2006-01-02T15Z07:00" + case 1: + format = "2006-01-02T15:04Z07:00" + default: + format = time.RFC3339 + } + } + } else if parseInLocation { + format = dateLocal } else { - format = time.RFC3339 + format = dateWithZone } - loc := time.FixedZone(time.Now().Zone()) - if len(value) < len(format) { - format = format[:len(value)] + var t time.Time + var err error + + if parseInLocation { + t, err = time.ParseInLocation(format, value, time.FixedZone(time.Now().Zone())) + } else { + t, err = time.Parse(format, value) } - t, err := time.ParseInLocation(format, value, loc) + if err != nil { - return value + // if there is a `-` then its an RFC3339 like timestamp otherwise assume unixtimestamp + if strings.Contains(value, "-") { + return "", err // was probably an RFC3339 like timestamp but the parser failed with an error + } + return value, nil // unixtimestamp in and out case (meaning: the value passed at the command line is already in the right format for passing to the server) } - return strconv.FormatInt(t.Unix(), 10) + + return fmt.Sprintf("%d.%09d", t.Unix(), int64(t.Nanosecond())), nil +} + +// ParseTimestamps returns seconds and nanoseconds from a timestamp that has the +// format "%d.%09d", time.Unix(), int64(time.Nanosecond())) +// if the incoming nanosecond portion is longer or shorter than 9 digits it is +// converted to nanoseconds. The expectation is that the seconds and +// seconds will be used to create a time variable. For example: +// seconds, nanoseconds, err := ParseTimestamp("1136073600.000000001",0) +// if err == nil since := time.Unix(seconds, nanoseconds) +// returns seconds as def(aultSeconds) if value == "" +func ParseTimestamps(value string, def int64) (int64, int64, error) { + if value == "" { + return def, 0, nil + } + sa := strings.SplitN(value, ".", 2) + s, err := strconv.ParseInt(sa[0], 10, 64) + if err != nil { + return s, 0, err + } + if len(sa) != 2 { + return s, 0, nil + } + n, err := strconv.ParseInt(sa[1], 10, 64) + if err != nil { + return s, n, err + } + // should already be in nanoseconds but just in case convert n to nanoseonds + n = int64(float64(n) * math.Pow(float64(10), float64(9-len(sa[1])))) + return s, n, nil } diff --git a/pkg/timeutils/utils_test.go b/pkg/timeutils/utils_test.go index f71dcb5310..1c443490ba 100644 --- a/pkg/timeutils/utils_test.go +++ b/pkg/timeutils/utils_test.go @@ -8,37 +8,86 @@ import ( func TestGetTimestamp(t *testing.T) { now := time.Now() - cases := []struct{ in, expected string }{ - {"0", "-62167305600"}, // 0 gets parsed year 0 - + cases := []struct { + in, expected string + expectedErr bool + }{ // Partial RFC3339 strings get parsed with second precision - {"2006-01-02T15:04:05.999999999+07:00", "1136189045"}, - {"2006-01-02T15:04:05.999999999Z", "1136214245"}, - {"2006-01-02T15:04:05.999999999", "1136214245"}, - {"2006-01-02T15:04:05", "1136214245"}, - {"2006-01-02T15:04", "1136214240"}, - {"2006-01-02T15", "1136214000"}, - {"2006-01-02T", "1136160000"}, - {"2006-01-02", "1136160000"}, - {"2006", "1136073600"}, - {"2015-05-13T20:39:09Z", "1431549549"}, + {"2006-01-02T15:04:05.999999999+07:00", "1136189045.999999999", false}, + {"2006-01-02T15:04:05.999999999Z", "1136214245.999999999", false}, + {"2006-01-02T15:04:05.999999999", "1136214245.999999999", false}, + {"2006-01-02T15:04:05Z", "1136214245.000000000", false}, + {"2006-01-02T15:04:05", "1136214245.000000000", false}, + {"2006-01-02T15:04:0Z", "", true}, + {"2006-01-02T15:04:0", "", true}, + {"2006-01-02T15:04Z", "1136214240.000000000", false}, + {"2006-01-02T15:04+00:00", "1136214240.000000000", false}, + {"2006-01-02T15:04-00:00", "1136214240.000000000", false}, + {"2006-01-02T15:04", "1136214240.000000000", false}, + {"2006-01-02T15:0Z", "", true}, + {"2006-01-02T15:0", "", true}, + {"2006-01-02T15Z", "1136214000.000000000", false}, + {"2006-01-02T15+00:00", "1136214000.000000000", false}, + {"2006-01-02T15-00:00", "1136214000.000000000", false}, + {"2006-01-02T15", "1136214000.000000000", false}, + {"2006-01-02T1Z", "1136163600.000000000", false}, + {"2006-01-02T1", "1136163600.000000000", false}, + {"2006-01-02TZ", "", true}, + {"2006-01-02T", "", true}, + {"2006-01-02+00:00", "1136160000.000000000", false}, + {"2006-01-02-00:00", "1136160000.000000000", false}, + {"2006-01-02-00:01", "1136160060.000000000", false}, + {"2006-01-02Z", "1136160000.000000000", false}, + {"2006-01-02", "1136160000.000000000", false}, + {"2015-05-13T20:39:09Z", "1431549549.000000000", false}, // unix timestamps returned as is - {"1136073600", "1136073600"}, - + {"1136073600", "1136073600", false}, + {"1136073600.000000001", "1136073600.000000001", false}, // Durations - {"1m", fmt.Sprintf("%d", now.Add(-1*time.Minute).Unix())}, - {"1.5h", fmt.Sprintf("%d", now.Add(-90*time.Minute).Unix())}, - {"1h30m", fmt.Sprintf("%d", now.Add(-90*time.Minute).Unix())}, + {"1m", fmt.Sprintf("%d", now.Add(-1*time.Minute).Unix()), false}, + {"1.5h", fmt.Sprintf("%d", now.Add(-90*time.Minute).Unix()), false}, + {"1h30m", fmt.Sprintf("%d", now.Add(-90*time.Minute).Unix()), false}, // String fallback - {"invalid", "invalid"}, + {"invalid", "invalid", false}, } for _, c := range cases { - o := GetTimestamp(c.in, now) - if o != c.expected { - t.Fatalf("wrong value for '%s'. expected:'%s' got:'%s'", c.in, c.expected, o) + o, err := GetTimestamp(c.in, now) + if o != c.expected || + (err == nil && c.expectedErr) || + (err != nil && !c.expectedErr) { + t.Errorf("wrong value for '%s'. expected:'%s' got:'%s' with error: `%s`", c.in, c.expected, o, err) + t.Fail() + } + } +} + +func TestParseTimestamps(t *testing.T) { + cases := []struct { + in string + def, expectedS, expectedN int64 + expectedErr bool + }{ + // unix timestamps + {"1136073600", 0, 1136073600, 0, false}, + {"1136073600.000000001", 0, 1136073600, 1, false}, + {"1136073600.0000000010", 0, 1136073600, 1, false}, + {"1136073600.00000001", 0, 1136073600, 10, false}, + {"foo.bar", 0, 0, 0, true}, + {"1136073600.bar", 0, 1136073600, 0, true}, + {"", -1, -1, 0, false}, + } + + for _, c := range cases { + s, n, err := ParseTimestamps(c.in, c.def) + if s != c.expectedS || + n != c.expectedN || + (err == nil && c.expectedErr) || + (err != nil && !c.expectedErr) { + t.Errorf("wrong values for input `%s` with default `%d` expected:'%d'seconds and `%d`nanosecond got:'%d'seconds and `%d`nanoseconds with error: `%s`", c.in, c.def, c.expectedS, c.expectedN, s, n, err) + t.Fail() } } }