From 4026512a2c535fe377a4cf834b7a78fccfd82dab Mon Sep 17 00:00:00 2001 From: Vincent Batts Date: Tue, 15 Sep 2015 15:33:11 -0400 Subject: [PATCH] events/jsonmessage: add and prefer TimeNano for events This way provide both Time and TimeNano in the event. For the display of the JSONMessage, use either, but prefer TimeNano Proving only TimeNano would break Subscribers that are using the `Time` field, so both are set for backwards compatibility. The events logging uses nano formatting, but only provides a Unix() time, therefor ordering may get lost in the output. Example: ``` 2015-09-15T14:18:51.000000000-04:00 ee46febd64ac629f7de9cd8bf58582e6f263d97ff46896adc5b508db804682da: (from busybox) resize 2015-09-15T14:18:51.000000000-04:00 a78c9149b1c0474502a117efaa814541926c2ae6ec3c76607e1c931b84c3a44b: (from busybox) resize ``` By having a field just for Nano time, when set, the marshalling back to `time.Unix(sec int64, nsec int64)` has zeros exactly where it needs to. This does not break any existing use of jsonmessage.JSONMessage, but now allows for use of `UnixNano()` and get event formatting that has distinguishable order. Example: ``` 2015-09-15T15:37:23.810295632-04:00 6adcf8ed9f5f5ec059a915466cd1cde86a18b4a085fc3af405e9cc9fecbbbbaf: (from busybox) resize 2015-09-15T15:37:23.810412202-04:00 6b7c5bfdc3f902096f5a91e628f21bd4b56e32590c5b4b97044aafc005ddcb0d: (from busybox) resize ``` Including tests for TimeNano and updated event API reference doc. Signed-off-by: Vincent Batts --- daemon/events/events.go | 3 +- docs/reference/api/docker_remote_api.md | 1 + docs/reference/api/docker_remote_api_v1.21.md | 8 ++--- pkg/jsonmessage/jsonmessage.go | 5 +++- pkg/jsonmessage/jsonmessage_test.go | 29 ++++++++++++++++--- 5 files changed, 36 insertions(+), 10 deletions(-) diff --git a/daemon/events/events.go b/daemon/events/events.go index 6687e2f155..0334dece47 100644 --- a/daemon/events/events.go +++ b/daemon/events/events.go @@ -45,7 +45,8 @@ func (e *Events) Evict(l chan interface{}) { // Log broadcasts event to listeners. Each listener has 100 millisecond for // receiving event or it will be skipped. func (e *Events) Log(action, id, from string) { - jm := &jsonmessage.JSONMessage{Status: action, ID: id, From: from, Time: time.Now().UTC().Unix()} + now := time.Now().UTC() + jm := &jsonmessage.JSONMessage{Status: action, ID: id, From: from, Time: now.Unix(), TimeNano: now.UnixNano()} e.mu.Lock() if len(e.events) == cap(e.events) { // discard oldest event diff --git a/docs/reference/api/docker_remote_api.md b/docs/reference/api/docker_remote_api.md index 2b6b4c9503..8cf91ee145 100644 --- a/docs/reference/api/docker_remote_api.md +++ b/docs/reference/api/docker_remote_api.md @@ -87,6 +87,7 @@ This section lists each version from latest to oldest. Each listing includes a * The `hostConfig` option now accepts the field `DnsOptions`, which specifies a list of DNS options to be used in the container. * `POST /build` now optionally takes a serialized map of build-time variables. +* `GET /events` now includes a `timenano` field, in addition to the existing `time` field. ### v1.20 API changes diff --git a/docs/reference/api/docker_remote_api_v1.21.md b/docs/reference/api/docker_remote_api_v1.21.md index 0ac6040555..a5a3f220ce 100644 --- a/docs/reference/api/docker_remote_api_v1.21.md +++ b/docs/reference/api/docker_remote_api_v1.21.md @@ -2014,10 +2014,10 @@ and Docker images report: HTTP/1.1 200 OK Content-Type: application/json - {"status": "create", "id": "dfdf82bd3881","from": "ubuntu:latest", "time":1374067924} - {"status": "start", "id": "dfdf82bd3881","from": "ubuntu:latest", "time":1374067924} - {"status": "stop", "id": "dfdf82bd3881","from": "ubuntu:latest", "time":1374067966} - {"status": "destroy", "id": "dfdf82bd3881","from": "ubuntu:latest", "time":1374067970} + {"status":"pull","id":"busybox:latest","time":1442421700,"timeNano":1442421700598988358} + {"status":"create","id":"5745704abe9caa5","from":"busybox","time":1442421716,"timeNano":1442421716853979870} + {"status":"attach","id":"5745704abe9caa5","from":"busybox","time":1442421716,"timeNano":1442421716894759198} + {"status":"start","id":"5745704abe9caa5","from":"busybox","time":1442421716,"timeNano":1442421716983607193} Query Parameters: diff --git a/pkg/jsonmessage/jsonmessage.go b/pkg/jsonmessage/jsonmessage.go index f12547c664..451c6a9fd2 100644 --- a/pkg/jsonmessage/jsonmessage.go +++ b/pkg/jsonmessage/jsonmessage.go @@ -99,6 +99,7 @@ type JSONMessage struct { ID string `json:"id,omitempty"` From string `json:"from,omitempty"` Time int64 `json:"time,omitempty"` + TimeNano int64 `json:"timeNano,omitempty"` Error *JSONError `json:"errorDetail,omitempty"` ErrorMessage string `json:"error,omitempty"` //deprecated } @@ -121,7 +122,9 @@ func (jm *JSONMessage) Display(out io.Writer, isTerminal bool) error { } else if jm.Progress != nil && jm.Progress.String() != "" { //disable progressbar in non-terminal return nil } - if jm.Time != 0 { + if jm.TimeNano != 0 { + fmt.Fprintf(out, "%s ", time.Unix(0, jm.TimeNano).Format(timeutils.RFC3339NanoFixed)) + } else if jm.Time != 0 { fmt.Fprintf(out, "%s ", time.Unix(jm.Time, 0).Format(timeutils.RFC3339NanoFixed)) } if jm.ID != "" { diff --git a/pkg/jsonmessage/jsonmessage_test.go b/pkg/jsonmessage/jsonmessage_test.go index 889b0ba5e2..7f46a8f63e 100644 --- a/pkg/jsonmessage/jsonmessage_test.go +++ b/pkg/jsonmessage/jsonmessage_test.go @@ -53,7 +53,7 @@ func TestProgress(t *testing.T) { } func TestJSONMessageDisplay(t *testing.T) { - now := time.Now().Unix() + now := time.Now() messages := map[JSONMessage][]string{ // Empty JSONMessage{}: {"\n", "\n"}, @@ -66,13 +66,34 @@ func TestJSONMessageDisplay(t *testing.T) { }, // General JSONMessage{ - Time: now, + Time: now.Unix(), ID: "ID", From: "From", Status: "status", }: { - fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now, 0).Format(timeutils.RFC3339NanoFixed)), - fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now, 0).Format(timeutils.RFC3339NanoFixed)), + fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now.Unix(), 0).Format(timeutils.RFC3339NanoFixed)), + fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now.Unix(), 0).Format(timeutils.RFC3339NanoFixed)), + }, + // General, with nano precision time + JSONMessage{ + TimeNano: now.UnixNano(), + ID: "ID", + From: "From", + Status: "status", + }: { + fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(timeutils.RFC3339NanoFixed)), + fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(timeutils.RFC3339NanoFixed)), + }, + // General, with both times Nano is preferred + JSONMessage{ + Time: now.Unix(), + TimeNano: now.UnixNano(), + ID: "ID", + From: "From", + Status: "status", + }: { + fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(timeutils.RFC3339NanoFixed)), + fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(timeutils.RFC3339NanoFixed)), }, // Stream over status JSONMessage{