Fix for issue 7902.

Use utils.RFC3339NanoFixed ("2006-01-02T15:04:05.000000000Z07:00")
instead of time.RFC3339Nano to format our log timestamps - this way
things are aligned, in particular the nano seconds are padded with zeros

Signed-off-by: Doug Davis <dug@us.ibm.com>

api/client/commands.go

@@ -1687,7 +1687,7 @@ func (cli *DockerCli) CmdEvents(args ...string) error {
 		loc = time.FixedZone(time.Now().Zone())
 	)
 	var setTime = func(key, value string) {
-		format := time.RFC3339Nano
+		format := utils.RFC3339NanoFixed
 		if len(value) < len(format) {
 			format = format[:len(value)]
 		}

daemon/logs.go

@@ -7,13 +7,13 @@ import (
 	"io"
 	"os"
 	"strconv"
-	"time"
 
 	"github.com/docker/docker/pkg/log"
 	"github.com/docker/docker/pkg/tailfile"
 
 	"github.com/docker/docker/engine"
 	"github.com/docker/docker/pkg/jsonlog"
+	"github.com/docker/docker/utils"
 )
 
 func (daemon *Daemon) ContainerLogs(job *engine.Job) engine.Status {
@@ -35,7 +35,7 @@ func (daemon *Daemon) ContainerLogs(job *engine.Job) engine.Status {
 		return job.Errorf("You must choose at least one stream")
 	}
 	if times {
-		format = time.RFC3339Nano
+		format = utils.RFC3339NanoFixed
 	}
 	if tail == "" {
 		tail = "all"

docs/sources/reference/commandline/cli.md

@@ -759,8 +759,9 @@ Passing a negative number or a non-integer to `--tail` is invalid and the
 value is set to `all` in that case. This behavior may change in the future.
 
 The `docker logs --timestamp` commands will add an RFC3339Nano
-timestamp, for example `2014-05-10T17:42:14.999999999Z07:00`, to each
-log entry.
+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.
 
 ## port
 

integration-cli/docker_cli_logs_test.go

@@ -7,6 +7,8 @@ import (
 	"strings"
 	"testing"
 	"time"
+
+	"github.com/docker/docker/utils"
 )
 
 // This used to work, it test a log of PageSize-1 (gh#4851)
@@ -102,10 +104,13 @@ func TestLogsTimestamps(t *testing.T) {
 
 	for _, l := range lines {
 		if l != "" {
-			_, err := time.Parse(time.RFC3339Nano+" ", ts.FindString(l))
+			_, err := time.Parse(utils.RFC3339NanoFixed+" ", ts.FindString(l))
 			if err != nil {
 				t.Fatalf("Failed to parse timestamp from %v: %v", l, err)
 			}
+			if l[29] != 'Z' { // ensure we have padded 0's
+				t.Fatalf("Timestamp isn't padded properly: %s", l)
+			}
 		}
 	}
 

utils/jsonmessage.go

@@ -100,7 +100,7 @@ func (jm *JSONMessage) Display(out io.Writer, isTerminal bool) error {
 		return nil
 	}
 	if jm.Time != 0 {
-		fmt.Fprintf(out, "%s ", time.Unix(jm.Time, 0).Format(time.RFC3339Nano))
+		fmt.Fprintf(out, "%s ", time.Unix(jm.Time, 0).Format(RFC3339NanoFixed))
 	}
 	if jm.ID != "" {
 		fmt.Fprintf(out, "%s: ", jm.ID)

utils/utils.go

@@ -24,6 +24,13 @@ import (
 	"github.com/docker/docker/pkg/log"
 )
 
+const (
+	// Define our own version of RFC339Nano because we want one
+	// that pads the nano seconds part with zeros to ensure
+	// the timestamps are aligned in the logs.
+	RFC3339NanoFixed = "2006-01-02T15:04:05.000000000Z07:00"
+)
+
 type KeyValuePair struct {
 	Key   string
 	Value string