Merge pull request #34946 from dnephin/fix-jsonlog

Move pkg/jsonlog to be a subpackage of the single consumer

api/server/httputils/write_log_stream.go

@@ -11,7 +11,7 @@ import (
 	"github.com/docker/docker/api/types"
 	"github.com/docker/docker/api/types/backend"
 	"github.com/docker/docker/pkg/ioutils"
-	"github.com/docker/docker/pkg/jsonlog"
+	"github.com/docker/docker/pkg/jsonmessage"
 	"github.com/docker/docker/pkg/stdcopy"
 )
 
@@ -49,11 +49,7 @@ func WriteLogStream(_ context.Context, w io.Writer, msgs <-chan *backend.LogMess
 			logLine = append(logLine, msg.Line...)
 		}
 		if config.Timestamps {
-			// TODO(dperny) the format is defined in
-			// daemon/logger/logger.go as logger.TimeFormat. importing
-			// logger is verboten (not part of backend) so idk if just
-			// importing the same thing from jsonlog is good enough
-			logLine = append([]byte(msg.Timestamp.Format(jsonlog.RFC3339NanoFixed)+" "), logLine...)
+			logLine = append([]byte(msg.Timestamp.Format(jsonmessage.RFC3339NanoFixed)+" "), logLine...)
 		}
 		if msg.Source == "stdout" && config.ShowStdout {
 			outStream.Write(logLine)

cmd/dockerd/daemon.go

@@ -38,7 +38,7 @@ import (
 	"github.com/docker/docker/libcontainerd"
 	dopts "github.com/docker/docker/opts"
 	"github.com/docker/docker/pkg/authorization"
-	"github.com/docker/docker/pkg/jsonlog"
+	"github.com/docker/docker/pkg/jsonmessage"
 	"github.com/docker/docker/pkg/pidfile"
 	"github.com/docker/docker/pkg/plugingetter"
 	"github.com/docker/docker/pkg/signal"
@@ -94,7 +94,7 @@ func (cli *DaemonCli) start(opts *daemonOptions) (err error) {
 	}
 
 	logrus.SetFormatter(&logrus.TextFormatter{
-		TimestampFormat: jsonlog.RFC3339NanoFixed,
+		TimestampFormat: jsonmessage.RFC3339NanoFixed,
 		DisableColors:   cli.Config.RawLogs,
 		FullTimestamp:   true,
 	})

daemon/logger/jsonfilelog/jsonfilelog.go

@@ -12,9 +12,9 @@ import (
 	"sync"
 
 	"github.com/docker/docker/daemon/logger"
+	"github.com/docker/docker/daemon/logger/jsonfilelog/jsonlog"
 	"github.com/docker/docker/daemon/logger/loggerutils"
-	"github.com/docker/docker/pkg/jsonlog"
-	"github.com/docker/go-units"
+	units "github.com/docker/go-units"
 	"github.com/pkg/errors"
 	"github.com/sirupsen/logrus"
 )
@@ -106,25 +106,19 @@ func writeMessageBuf(w io.Writer, m *logger.Message, extra json.RawMessage, buf
 		return err
 	}
 	logger.PutMessage(m)
-	if _, err := w.Write(buf.Bytes()); err != nil {
-		return errors.Wrap(err, "error writing log entry")
-	}
-	return nil
+	_, err := w.Write(buf.Bytes())
+	return errors.Wrap(err, "error writing log entry")
 }
 
 func marshalMessage(msg *logger.Message, extra json.RawMessage, buf *bytes.Buffer) error {
-	timestamp, err := jsonlog.FastTimeMarshalJSON(msg.Timestamp)
-	if err != nil {
-		return err
-	}
 	logLine := msg.Line
 	if !msg.Partial {
 		logLine = append(msg.Line, '\n')
 	}
-	err = (&jsonlog.JSONLogs{
+	err := (&jsonlog.JSONLogs{
 		Log:      logLine,
 		Stream:   msg.Source,
-		Created:  timestamp,
+		Created:  msg.Timestamp,
 		RawAttrs: extra,
 	}).MarshalJSONBuf(buf)
 	if err != nil {

daemon/logger/jsonfilelog/jsonfilelog_test.go

@@ -1,6 +1,7 @@
 package jsonfilelog
 
 import (
+	"bytes"
 	"encoding/json"
 	"io/ioutil"
 	"os"
@@ -11,7 +12,9 @@ import (
 	"time"
 
 	"github.com/docker/docker/daemon/logger"
-	"github.com/docker/docker/pkg/jsonlog"
+	"github.com/docker/docker/daemon/logger/jsonfilelog/jsonlog"
+	"github.com/gotestyourself/gotestyourself/fs"
+	"github.com/stretchr/testify/require"
 )
 
 func TestJSONFileLogger(t *testing.T) {
@@ -54,36 +57,38 @@ func TestJSONFileLogger(t *testing.T) {
 	}
 }
 
-func BenchmarkJSONFileLogger(b *testing.B) {
-	cid := "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657"
-	tmp, err := ioutil.TempDir("", "docker-logger-")
-	if err != nil {
-		b.Fatal(err)
-	}
-	defer os.RemoveAll(tmp)
-	filename := filepath.Join(tmp, "container.log")
-	l, err := New(logger.Info{
-		ContainerID: cid,
-		LogPath:     filename,
+func BenchmarkJSONFileLoggerLog(b *testing.B) {
+	tmp := fs.NewDir(b, "bench-jsonfilelog")
+	defer tmp.Remove()
+
+	jsonlogger, err := New(logger.Info{
+		ContainerID: "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657",
+		LogPath:     tmp.Join("container.log"),
+		Config: map[string]string{
+			"labels": "first,second",
+		},
+		ContainerLabels: map[string]string{
+			"first":  "label_value",
+			"second": "label_foo",
+		},
 	})
-	if err != nil {
-		b.Fatal(err)
-	}
-	defer l.Close()
+	require.NoError(b, err)
+	defer jsonlogger.Close()
 
-	testLine := "Line that thinks that it is log line from docker\n"
-	msg := &logger.Message{Line: []byte(testLine), Source: "stderr", Timestamp: time.Now().UTC()}
-	jsonlog, err := (&jsonlog.JSONLog{Log: string(msg.Line) + "\n", Stream: msg.Source, Created: msg.Timestamp}).MarshalJSON()
-	if err != nil {
-		b.Fatal(err)
+	msg := &logger.Message{
+		Line:      []byte("Line that thinks that it is log line from docker\n"),
+		Source:    "stderr",
+		Timestamp: time.Now().UTC(),
 	}
-	b.SetBytes(int64(len(jsonlog)+1) * 30)
+
+	buf := bytes.NewBuffer(nil)
+	require.NoError(b, marshalMessage(msg, jsonlogger.(*JSONFileLogger).extra, buf))
+	b.SetBytes(int64(buf.Len()))
+
 	b.ResetTimer()
 	for i := 0; i < b.N; i++ {
-		for j := 0; j < 30; j++ {
-			if err := l.Log(msg); err != nil {
-				b.Fatal(err)
-			}
+		if err := jsonlogger.Log(msg); err != nil {
+			b.Fatal(err)
 		}
 	}
 }
@@ -200,50 +205,3 @@ func TestJSONFileLoggerWithLabelsEnv(t *testing.T) {
 		t.Fatalf("Wrong log attrs: %q, expected %q", extra, expected)
 	}
 }
-
-func BenchmarkJSONFileLoggerWithReader(b *testing.B) {
-	b.StopTimer()
-	b.ResetTimer()
-	cid := "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657"
-	dir, err := ioutil.TempDir("", "json-logger-bench")
-	if err != nil {
-		b.Fatal(err)
-	}
-	defer os.RemoveAll(dir)
-
-	l, err := New(logger.Info{
-		ContainerID: cid,
-		LogPath:     filepath.Join(dir, "container.log"),
-	})
-	if err != nil {
-		b.Fatal(err)
-	}
-	defer l.Close()
-	msg := &logger.Message{Line: []byte("line"), Source: "src1"}
-	jsonlog, err := (&jsonlog.JSONLog{Log: string(msg.Line) + "\n", Stream: msg.Source, Created: msg.Timestamp}).MarshalJSON()
-	if err != nil {
-		b.Fatal(err)
-	}
-	b.SetBytes(int64(len(jsonlog)+1) * 30)
-
-	b.StartTimer()
-
-	go func() {
-		for i := 0; i < b.N; i++ {
-			for j := 0; j < 30; j++ {
-				l.Log(msg)
-			}
-		}
-		l.Close()
-	}()
-
-	lw := l.(logger.LogReader).ReadLogs(logger.ReadConfig{Follow: true})
-	watchClose := lw.WatchClose()
-	for {
-		select {
-		case <-lw.Msg:
-		case <-watchClose:
-			return
-		}
-	}
-}

daemon/logger/jsonfilelog/jsonlog/jsonlog.go

@@ -0,0 +1,25 @@
+package jsonlog
+
+import (
+	"time"
+)
+
+// JSONLog is a log message, typically a single entry from a given log stream.
+type JSONLog struct {
+	// Log is the log message
+	Log string `json:"log,omitempty"`
+	// Stream is the log source
+	Stream string `json:"stream,omitempty"`
+	// Created is the created timestamp of log
+	Created time.Time `json:"time"`
+	// Attrs is the list of extra attributes provided by the user
+	Attrs map[string]string `json:"attrs,omitempty"`
+}
+
+// Reset all fields to their zero value.
+func (jl *JSONLog) Reset() {
+	jl.Log = ""
+	jl.Stream = ""
+	jl.Created = time.Time{}
+	jl.Attrs = make(map[string]string)
+}

pkg/jsonlog/jsonlogbytes.go → daemon/logger/jsonfilelog/jsonlog/jsonlogbytes.go

@@ -3,23 +3,22 @@ package jsonlog
 import (
 	"bytes"
 	"encoding/json"
+	"time"
 	"unicode/utf8"
 )
 
-// JSONLogs is based on JSONLog.
-// It allows marshalling JSONLog from Log as []byte
-// and an already marshalled Created timestamp.
+// JSONLogs marshals encoded JSONLog objects
 type JSONLogs struct {
-	Log     []byte `json:"log,omitempty"`
-	Stream  string `json:"stream,omitempty"`
-	Created string `json:"time"`
+	Log     []byte    `json:"log,omitempty"`
+	Stream  string    `json:"stream,omitempty"`
+	Created time.Time `json:"time"`
 
 	// json-encoded bytes
 	RawAttrs json.RawMessage `json:"attrs,omitempty"`
 }
 
-// MarshalJSONBuf is based on the same method from JSONLog
-// It has been modified to take into account the necessary changes.
+// MarshalJSONBuf is an optimized JSON marshaller that avoids reflection
+// and unnecessary allocation.
 func (mj *JSONLogs) MarshalJSONBuf(buf *bytes.Buffer) error {
 	var first = true
 
@@ -36,7 +35,7 @@ func (mj *JSONLogs) MarshalJSONBuf(buf *bytes.Buffer) error {
 			buf.WriteString(`,`)
 		}
 		buf.WriteString(`"stream":`)
-		ffjsonWriteJSONString(buf, mj.Stream)
+		ffjsonWriteJSONBytesAsString(buf, []byte(mj.Stream))
 	}
 	if len(mj.RawAttrs) > 0 {
 		if first {
@@ -50,14 +49,18 @@ func (mj *JSONLogs) MarshalJSONBuf(buf *bytes.Buffer) error {
 	if !first {
 		buf.WriteString(`,`)
 	}
+
+	created, err := fastTimeMarshalJSON(mj.Created)
+	if err != nil {
+		return err
+	}
+
 	buf.WriteString(`"time":`)
-	buf.WriteString(mj.Created)
+	buf.WriteString(created)
 	buf.WriteString(`}`)
 	return nil
 }
 
-// This is based on ffjsonWriteJSONBytesAsString. It has been changed
-// to accept a string passed as a slice of bytes.
 func ffjsonWriteJSONBytesAsString(buf *bytes.Buffer, s []byte) {
 	const hex = "0123456789abcdef"
 

daemon/logger/jsonfilelog/jsonlog/jsonlogbytes_test.go

@@ -0,0 +1,40 @@
+package jsonlog
+
+import (
+	"bytes"
+	"encoding/json"
+	"regexp"
+	"testing"
+	"time"
+
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestJSONLogsMarshalJSONBuf(t *testing.T) {
+	logs := map[*JSONLogs]string{
+		{Log: []byte(`"A log line with \\"`)}:                  `^{\"log\":\"\\\"A log line with \\\\\\\\\\\"\",\"time\":`,
+		{Log: []byte("A log line")}:                            `^{\"log\":\"A log line\",\"time\":`,
+		{Log: []byte("A log line with \r")}:                    `^{\"log\":\"A log line with \\r\",\"time\":`,
+		{Log: []byte("A log line with & < >")}:                 `^{\"log\":\"A log line with \\u0026 \\u003c \\u003e\",\"time\":`,
+		{Log: []byte("A log line with utf8 : 🚀 ψ ω β")}:        `^{\"log\":\"A log line with utf8 : 🚀 ψ ω β\",\"time\":`,
+		{Stream: "stdout"}:                                     `^{\"stream\":\"stdout\",\"time\":`,
+		{Stream: "stdout", Log: []byte("A log line")}:          `^{\"log\":\"A log line\",\"stream\":\"stdout\",\"time\":`,
+		{Created: time.Date(2017, 9, 1, 1, 1, 1, 1, time.UTC)}: `^{\"time\":"2017-09-01T01:01:01.000000001Z"}$`,
+
+		{}: `^{\"time\":"0001-01-01T00:00:00Z"}$`,
+		// These ones are a little weird
+		{Log: []byte("\u2028 \u2029")}: `^{\"log\":\"\\u2028 \\u2029\",\"time\":`,
+		{Log: []byte{0xaF}}:            `^{\"log\":\"\\ufffd\",\"time\":`,
+		{Log: []byte{0x7F}}:            `^{\"log\":\"\x7f\",\"time\":`,
+		// with raw attributes
+		{Log: []byte("A log line"), RawAttrs: []byte(`{"hello":"world","value":1234}`)}: `^{\"log\":\"A log line\",\"attrs\":{\"hello\":\"world\",\"value\":1234},\"time\":`,
+	}
+	for jsonLog, expression := range logs {
+		var buf bytes.Buffer
+		err := jsonLog.MarshalJSONBuf(&buf)
+		require.NoError(t, err)
+		assert.Regexp(t, regexp.MustCompile(expression), buf.String())
+		assert.NoError(t, json.Unmarshal(buf.Bytes(), &map[string]interface{}{}))
+	}
+}

daemon/logger/jsonfilelog/jsonlog/time_marshalling.go

@@ -0,0 +1,20 @@
+package jsonlog
+
+import (
+	"time"
+
+	"github.com/pkg/errors"
+)
+
+const jsonFormat = `"` + time.RFC3339Nano + `"`
+
+// fastTimeMarshalJSON avoids one of the extra allocations that
+// time.MarshalJSON is making.
+func fastTimeMarshalJSON(t time.Time) (string, error) {
+	if y := t.Year(); y < 0 || y >= 10000 {
+		// RFC 3339 is clear that years are 4 digits exactly.
+		// See golang.org/issue/4556#c15 for more discussion.
+		return "", errors.New("time.MarshalJSON: year outside of range [0,9999]")
+	}
+	return t.Format(jsonFormat), nil
+}

daemon/logger/jsonfilelog/jsonlog/time_marshalling_test.go

@@ -0,0 +1,35 @@
+package jsonlog
+
+import (
+	"testing"
+	"time"
+
+	"github.com/docker/docker/internal/testutil"
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
+)
+
+func TestFastTimeMarshalJSONWithInvalidYear(t *testing.T) {
+	aTime := time.Date(-1, 1, 1, 0, 0, 0, 0, time.Local)
+	_, err := fastTimeMarshalJSON(aTime)
+	testutil.ErrorContains(t, err, "year outside of range")
+
+	anotherTime := time.Date(10000, 1, 1, 0, 0, 0, 0, time.Local)
+	_, err = fastTimeMarshalJSON(anotherTime)
+	testutil.ErrorContains(t, err, "year outside of range")
+}
+
+func TestFastTimeMarshalJSON(t *testing.T) {
+	aTime := time.Date(2015, 5, 29, 11, 1, 2, 3, time.UTC)
+	json, err := fastTimeMarshalJSON(aTime)
+	require.NoError(t, err)
+	assert.Equal(t, "\"2015-05-29T11:01:02.000000003Z\"", json)
+
+	location, err := time.LoadLocation("Europe/Paris")
+	require.NoError(t, err)
+
+	aTime = time.Date(2015, 5, 29, 11, 1, 2, 3, location)
+	json, err = fastTimeMarshalJSON(aTime)
+	require.NoError(t, err)
+	assert.Equal(t, "\"2015-05-29T11:01:02.000000003+02:00\"", json)
+}

daemon/logger/jsonfilelog/read.go

@@ -13,9 +13,9 @@ import (
 
 	"github.com/docker/docker/api/types/backend"
 	"github.com/docker/docker/daemon/logger"
+	"github.com/docker/docker/daemon/logger/jsonfilelog/jsonlog"
 	"github.com/docker/docker/daemon/logger/jsonfilelog/multireader"
 	"github.com/docker/docker/pkg/filenotify"
-	"github.com/docker/docker/pkg/jsonlog"
 	"github.com/docker/docker/pkg/tailfile"
 	"github.com/pkg/errors"
 	"github.com/sirupsen/logrus"
@@ -147,9 +147,8 @@ func tailFile(f io.ReadSeeker, logWatcher *logger.LogWatcher, tail int, since ti
 		rdr = bytes.NewBuffer(bytes.Join(ls, []byte("\n")))
 	}
 	dec := json.NewDecoder(rdr)
-	l := &jsonlog.JSONLog{}
 	for {
-		msg, err := decodeLogLine(dec, l)
+		msg, err := decodeLogLine(dec, &jsonlog.JSONLog{})
 		if err != nil {
 			if err != io.EOF {
 				logWatcher.Err <- err

daemon/logger/jsonfilelog/read_test.go

@@ -0,0 +1,64 @@
+package jsonfilelog
+
+import (
+	"bytes"
+	"testing"
+	"time"
+
+	"github.com/docker/docker/daemon/logger"
+	"github.com/gotestyourself/gotestyourself/fs"
+	"github.com/stretchr/testify/require"
+)
+
+func BenchmarkJSONFileLoggerReadLogs(b *testing.B) {
+	tmp := fs.NewDir(b, "bench-jsonfilelog")
+	defer tmp.Remove()
+
+	jsonlogger, err := New(logger.Info{
+		ContainerID: "a7317399f3f857173c6179d44823594f8294678dea9999662e5c625b5a1c7657",
+		LogPath:     tmp.Join("container.log"),
+		Config: map[string]string{
+			"labels": "first,second",
+		},
+		ContainerLabels: map[string]string{
+			"first":  "label_value",
+			"second": "label_foo",
+		},
+	})
+	require.NoError(b, err)
+	defer jsonlogger.Close()
+
+	msg := &logger.Message{
+		Line:      []byte("Line that thinks that it is log line from docker\n"),
+		Source:    "stderr",
+		Timestamp: time.Now().UTC(),
+	}
+
+	buf := bytes.NewBuffer(nil)
+	require.NoError(b, marshalMessage(msg, jsonlogger.(*JSONFileLogger).extra, buf))
+	b.SetBytes(int64(buf.Len()))
+
+	b.ResetTimer()
+
+	chError := make(chan error, b.N+1)
+	go func() {
+		for i := 0; i < b.N; i++ {
+			chError <- jsonlogger.Log(msg)
+		}
+		chError <- jsonlogger.Close()
+	}()
+
+	lw := jsonlogger.(*JSONFileLogger).ReadLogs(logger.ReadConfig{Follow: true})
+	watchClose := lw.WatchClose()
+	for {
+		select {
+		case <-lw.Msg:
+		case <-watchClose:
+			return
+		case err := <-chError:
+			if err != nil {
+				b.Fatal(err)
+			}
+		}
+	}
+}

daemon/logger/logger.go

@@ -12,7 +12,6 @@ import (
 	"time"
 
 	"github.com/docker/docker/api/types/backend"
-	"github.com/docker/docker/pkg/jsonlog"
 )
 
 // ErrReadLogsNotSupported is returned when the underlying log driver does not support reading
@@ -26,8 +25,6 @@ func (ErrReadLogsNotSupported) Error() string {
 func (ErrReadLogsNotSupported) NotImplemented() {}
 
 const (
-	// TimeFormat is the time format used for timestamps sent to log readers.
-	TimeFormat           = jsonlog.RFC3339NanoFixed
 	logWatcherBufferSize = 4096
 )
 

integration-cli/docker_cli_logs_test.go

@@ -10,7 +10,7 @@ import (
 
 	"github.com/docker/docker/integration-cli/checker"
 	"github.com/docker/docker/integration-cli/cli"
-	"github.com/docker/docker/pkg/jsonlog"
+	"github.com/docker/docker/pkg/jsonmessage"
 	"github.com/go-check/check"
 	"github.com/gotestyourself/gotestyourself/icmd"
 )
@@ -55,7 +55,7 @@ func (s *DockerSuite) TestLogsTimestamps(c *check.C) {
 
 	for _, l := range lines {
 		if l != "" {
-			_, err := time.Parse(jsonlog.RFC3339NanoFixed+" ", ts.FindString(l))
+			_, err := time.Parse(jsonmessage.RFC3339NanoFixed+" ", ts.FindString(l))
 			c.Assert(err, checker.IsNil, check.Commentf("Failed to parse timestamp from %v", l))
 			// ensure we have padded 0's
 			c.Assert(l[29], checker.Equals, uint8('Z'))

pkg/jsonlog/jsonlog.go

@@ -1,42 +0,0 @@
-package jsonlog
-
-import (
-	"encoding/json"
-	"fmt"
-	"time"
-)
-
-// JSONLog represents a log message, typically a single entry from a given log stream.
-// JSONLogs can be easily serialized to and from JSON and support custom formatting.
-type JSONLog struct {
-	// Log is the log message
-	Log string `json:"log,omitempty"`
-	// Stream is the log source
-	Stream string `json:"stream,omitempty"`
-	// Created is the created timestamp of log
-	Created time.Time `json:"time"`
-	// Attrs is the list of extra attributes provided by the user
-	Attrs map[string]string `json:"attrs,omitempty"`
-}
-
-// Format returns the log formatted according to format
-// If format is nil, returns the log message
-// If format is json, returns the log marshaled in json format
-// By default, returns the log with the log time formatted according to format.
-func (jl *JSONLog) Format(format string) (string, error) {
-	if format == "" {
-		return jl.Log, nil
-	}
-	if format == "json" {
-		m, err := json.Marshal(jl)
-		return string(m), err
-	}
-	return fmt.Sprintf("%s %s", jl.Created.Format(format), jl.Log), nil
-}
-
-// Reset resets the log to nil.
-func (jl *JSONLog) Reset() {
-	jl.Log = ""
-	jl.Stream = ""
-	jl.Created = time.Time{}
-}

pkg/jsonlog/jsonlog_marshalling.go

@@ -1,178 +0,0 @@
-// This code was initially generated by ffjson <https://github.com/pquerna/ffjson>
-// This code was generated via the following steps:
-// $ go get -u github.com/pquerna/ffjson
-// $ make BIND_DIR=. shell
-// $ ffjson pkg/jsonlog/jsonlog.go
-// $ mv pkg/jsonglog/jsonlog_ffjson.go pkg/jsonlog/jsonlog_marshalling.go
-//
-// It has been modified to improve the performance of time marshalling to JSON
-// and to clean it up.
-// Should this code need to be regenerated when the JSONLog struct is changed,
-// the relevant changes which have been made are:
-// import (
-//        "bytes"
-//-
-//        "unicode/utf8"
-// )
-//
-// func (mj *JSONLog) MarshalJSON() ([]byte, error) {
-//@@ -20,13 +16,13 @@ func (mj *JSONLog) MarshalJSON() ([]byte, error) {
-//        }
-//        return buf.Bytes(), nil
-// }
-//+
-// func (mj *JSONLog) MarshalJSONBuf(buf *bytes.Buffer) error {
-//-       var err error
-//-       var obj []byte
-//-       var first bool = true
-//-       _ = obj
-//-       _ = err
-//-       _ = first
-//+       var (
-//+               err       error
-//+               timestamp string
-//+               first     bool = true
-//+       )
-//        buf.WriteString(`{`)
-//        if len(mj.Log) != 0 {
-//                if first == true {
-//@@ -52,11 +48,11 @@ func (mj *JSONLog) MarshalJSONBuf(buf *bytes.Buffer) error {
-//                buf.WriteString(`,`)
-//        }
-//        buf.WriteString(`"time":`)
-//-       obj, err = mj.Created.MarshalJSON()
-//+       timestamp, err = FastTimeMarshalJSON(mj.Created)
-//        if err != nil {
-//                return err
-//        }
-//-       buf.Write(obj)
-//+       buf.WriteString(timestamp)
-//        buf.WriteString(`}`)
-//        return nil
-// }
-// @@ -81,9 +81,10 @@ func (mj *JSONLog) MarshalJSONBuf(buf *bytes.Buffer) error {
-//         if len(mj.Log) != 0 {
-// -                if first == true {
-// -                       first = false
-// -               } else {
-// -                       buf.WriteString(`,`)
-// -               }
-// +               first = false
-//                 buf.WriteString(`"log":`)
-//                 ffjsonWriteJSONString(buf, mj.Log)
-//         }
-
-package jsonlog
-
-import (
-	"bytes"
-	"unicode/utf8"
-)
-
-// MarshalJSON marshals the JSONLog.
-func (mj *JSONLog) MarshalJSON() ([]byte, error) {
-	var buf bytes.Buffer
-	buf.Grow(1024)
-	if err := mj.MarshalJSONBuf(&buf); err != nil {
-		return nil, err
-	}
-	return buf.Bytes(), nil
-}
-
-// MarshalJSONBuf marshals the JSONLog and stores the result to a bytes.Buffer.
-func (mj *JSONLog) MarshalJSONBuf(buf *bytes.Buffer) error {
-	var (
-		err       error
-		timestamp string
-		first     = true
-	)
-	buf.WriteString(`{`)
-	if len(mj.Log) != 0 {
-		first = false
-		buf.WriteString(`"log":`)
-		ffjsonWriteJSONString(buf, mj.Log)
-	}
-	if len(mj.Stream) != 0 {
-		if first {
-			first = false
-		} else {
-			buf.WriteString(`,`)
-		}
-		buf.WriteString(`"stream":`)
-		ffjsonWriteJSONString(buf, mj.Stream)
-	}
-	if !first {
-		buf.WriteString(`,`)
-	}
-	buf.WriteString(`"time":`)
-	timestamp, err = FastTimeMarshalJSON(mj.Created)
-	if err != nil {
-		return err
-	}
-	buf.WriteString(timestamp)
-	buf.WriteString(`}`)
-	return nil
-}
-
-func ffjsonWriteJSONString(buf *bytes.Buffer, s string) {
-	const hex = "0123456789abcdef"
-
-	buf.WriteByte('"')
-	start := 0
-	for i := 0; i < len(s); {
-		if b := s[i]; b < utf8.RuneSelf {
-			if 0x20 <= b && b != '\\' && b != '"' && b != '<' && b != '>' && b != '&' {
-				i++
-				continue
-			}
-			if start < i {
-				buf.WriteString(s[start:i])
-			}
-			switch b {
-			case '\\', '"':
-				buf.WriteByte('\\')
-				buf.WriteByte(b)
-			case '\n':
-				buf.WriteByte('\\')
-				buf.WriteByte('n')
-			case '\r':
-				buf.WriteByte('\\')
-				buf.WriteByte('r')
-			default:
-
-				buf.WriteString(`\u00`)
-				buf.WriteByte(hex[b>>4])
-				buf.WriteByte(hex[b&0xF])
-			}
-			i++
-			start = i
-			continue
-		}
-		c, size := utf8.DecodeRuneInString(s[i:])
-		if c == utf8.RuneError && size == 1 {
-			if start < i {
-				buf.WriteString(s[start:i])
-			}
-			buf.WriteString(`\ufffd`)
-			i += size
-			start = i
-			continue
-		}
-
-		if c == '\u2028' || c == '\u2029' {
-			if start < i {
-				buf.WriteString(s[start:i])
-			}
-			buf.WriteString(`\u202`)
-			buf.WriteByte(hex[c&0xF])
-			i += size
-			start = i
-			continue
-		}
-		i += size
-	}
-	if start < len(s) {
-		buf.WriteString(s[start:])
-	}
-	buf.WriteByte('"')
-}

pkg/jsonlog/jsonlog_marshalling_test.go

@@ -1,34 +0,0 @@
-package jsonlog
-
-import (
-	"regexp"
-	"testing"
-)
-
-func TestJSONLogMarshalJSON(t *testing.T) {
-	logs := map[*JSONLog]string{
-		{Log: `"A log line with \\"`}:           `^{\"log\":\"\\\"A log line with \\\\\\\\\\\"\",\"time\":\".{20,}\"}$`,
-		{Log: "A log line"}:                     `^{\"log\":\"A log line\",\"time\":\".{20,}\"}$`,
-		{Log: "A log line with \r"}:             `^{\"log\":\"A log line with \\r\",\"time\":\".{20,}\"}$`,
-		{Log: "A log line with & < >"}:          `^{\"log\":\"A log line with \\u0026 \\u003c \\u003e\",\"time\":\".{20,}\"}$`,
-		{Log: "A log line with utf8 : 🚀 ψ ω β"}: `^{\"log\":\"A log line with utf8 : 🚀 ψ ω β\",\"time\":\".{20,}\"}$`,
-		{Stream: "stdout"}:                      `^{\"stream\":\"stdout\",\"time\":\".{20,}\"}$`,
-		{}:                                      `^{\"time\":\".{20,}\"}$`,
-		// These ones are a little weird
-		{Log: "\u2028 \u2029"}:      `^{\"log\":\"\\u2028 \\u2029\",\"time\":\".{20,}\"}$`,
-		{Log: string([]byte{0xaF})}: `^{\"log\":\"\\ufffd\",\"time\":\".{20,}\"}$`,
-		{Log: string([]byte{0x7F})}: `^{\"log\":\"\x7f\",\"time\":\".{20,}\"}$`,
-	}
-	for jsonLog, expression := range logs {
-		data, err := jsonLog.MarshalJSON()
-		if err != nil {
-			t.Fatal(err)
-		}
-		res := string(data)
-		t.Logf("Result of WriteLog: %q", res)
-		logRe := regexp.MustCompile(expression)
-		if !logRe.MatchString(res) {
-			t.Fatalf("Log line not in expected format [%v]: %q", expression, res)
-		}
-	}
-}

pkg/jsonlog/jsonlogbytes_test.go

@@ -1,39 +0,0 @@
-package jsonlog
-
-import (
-	"bytes"
-	"regexp"
-	"testing"
-)
-
-func TestJSONLogsMarshalJSONBuf(t *testing.T) {
-	logs := map[*JSONLogs]string{
-		{Log: []byte(`"A log line with \\"`)}:           `^{\"log\":\"\\\"A log line with \\\\\\\\\\\"\",\"time\":}$`,
-		{Log: []byte("A log line")}:                     `^{\"log\":\"A log line\",\"time\":}$`,
-		{Log: []byte("A log line with \r")}:             `^{\"log\":\"A log line with \\r\",\"time\":}$`,
-		{Log: []byte("A log line with & < >")}:          `^{\"log\":\"A log line with \\u0026 \\u003c \\u003e\",\"time\":}$`,
-		{Log: []byte("A log line with utf8 : 🚀 ψ ω β")}: `^{\"log\":\"A log line with utf8 : 🚀 ψ ω β\",\"time\":}$`,
-		{Stream: "stdout"}:                              `^{\"stream\":\"stdout\",\"time\":}$`,
-		{Stream: "stdout", Log: []byte("A log line")}:   `^{\"log\":\"A log line\",\"stream\":\"stdout\",\"time\":}$`,
-		{Created: "time"}:                               `^{\"time\":time}$`,
-		{}:                                              `^{\"time\":}$`,
-		// These ones are a little weird
-		{Log: []byte("\u2028 \u2029")}: `^{\"log\":\"\\u2028 \\u2029\",\"time\":}$`,
-		{Log: []byte{0xaF}}:            `^{\"log\":\"\\ufffd\",\"time\":}$`,
-		{Log: []byte{0x7F}}:            `^{\"log\":\"\x7f\",\"time\":}$`,
-		// with raw attributes
-		{Log: []byte("A log line"), RawAttrs: []byte(`{"hello":"world","value":1234}`)}: `^{\"log\":\"A log line\",\"attrs\":{\"hello\":\"world\",\"value\":1234},\"time\":}$`,
-	}
-	for jsonLog, expression := range logs {
-		var buf bytes.Buffer
-		if err := jsonLog.MarshalJSONBuf(&buf); err != nil {
-			t.Fatal(err)
-		}
-		res := buf.String()
-		t.Logf("Result of WriteLog: %q", res)
-		logRe := regexp.MustCompile(expression)
-		if !logRe.MatchString(res) {
-			t.Fatalf("Log line not in expected format [%v]: %q", expression, res)
-		}
-	}
-}

pkg/jsonlog/time_marshalling.go

@@ -1,27 +0,0 @@
-// Package jsonlog provides helper functions to parse and print time (time.Time) as JSON.
-package jsonlog
-
-import (
-	"errors"
-	"time"
-)
-
-const (
-	// RFC3339NanoFixed is 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"
-	// JSONFormat is the format used by FastMarshalJSON
-	JSONFormat = `"` + time.RFC3339Nano + `"`
-)
-
-// FastTimeMarshalJSON avoids one of the extra allocations that
-// time.MarshalJSON is making.
-func FastTimeMarshalJSON(t time.Time) (string, error) {
-	if y := t.Year(); y < 0 || y >= 10000 {
-		// RFC 3339 is clear that years are 4 digits exactly.
-		// See golang.org/issue/4556#c15 for more discussion.
-		return "", errors.New("time.MarshalJSON: year outside of range [0,9999]")
-	}
-	return t.Format(JSONFormat), nil
-}

pkg/jsonlog/time_marshalling_test.go

@@ -1,47 +0,0 @@
-package jsonlog
-
-import (
-	"testing"
-	"time"
-)
-
-// Testing to ensure 'year' fields is between 0 and 9999
-func TestFastTimeMarshalJSONWithInvalidDate(t *testing.T) {
-	aTime := time.Date(-1, 1, 1, 0, 0, 0, 0, time.Local)
-	json, err := FastTimeMarshalJSON(aTime)
-	if err == nil {
-		t.Fatalf("FastTimeMarshalJSON should throw an error, but was '%v'", json)
-	}
-	anotherTime := time.Date(10000, 1, 1, 0, 0, 0, 0, time.Local)
-	json, err = FastTimeMarshalJSON(anotherTime)
-	if err == nil {
-		t.Fatalf("FastTimeMarshalJSON should throw an error, but was '%v'", json)
-	}
-
-}
-
-func TestFastTimeMarshalJSON(t *testing.T) {
-	aTime := time.Date(2015, 5, 29, 11, 1, 2, 3, time.UTC)
-	json, err := FastTimeMarshalJSON(aTime)
-	if err != nil {
-		t.Fatal(err)
-	}
-	expected := "\"2015-05-29T11:01:02.000000003Z\""
-	if json != expected {
-		t.Fatalf("Expected %v, got %v", expected, json)
-	}
-
-	location, err := time.LoadLocation("Europe/Paris")
-	if err != nil {
-		t.Fatal(err)
-	}
-	aTime = time.Date(2015, 5, 29, 11, 1, 2, 3, location)
-	json, err = FastTimeMarshalJSON(aTime)
-	if err != nil {
-		t.Fatal(err)
-	}
-	expected = "\"2015-05-29T11:01:02.000000003+02:00\""
-	if json != expected {
-		t.Fatalf("Expected %v, got %v", expected, json)
-	}
-}

pkg/jsonmessage/jsonmessage.go

@@ -9,11 +9,14 @@ import (
 	"time"
 
 	gotty "github.com/Nvveen/Gotty"
-	"github.com/docker/docker/pkg/jsonlog"
 	"github.com/docker/docker/pkg/term"
 	units "github.com/docker/go-units"
 )
 
+// RFC3339NanoFixed is time.RFC3339Nano with nanoseconds padded using zeros to
+// ensure the formatted time isalways the same number of characters.
+const RFC3339NanoFixed = "2006-01-02T15:04:05.000000000Z07:00"
+
 // JSONError wraps a concrete Code and Message, `Code` is
 // is an integer error code, `Message` is the error message.
 type JSONError struct {
@@ -199,9 +202,9 @@ func (jm *JSONMessage) Display(out io.Writer, termInfo termInfo) error {
 		return nil
 	}
 	if jm.TimeNano != 0 {
-		fmt.Fprintf(out, "%s ", time.Unix(0, jm.TimeNano).Format(jsonlog.RFC3339NanoFixed))
+		fmt.Fprintf(out, "%s ", time.Unix(0, jm.TimeNano).Format(RFC3339NanoFixed))
 	} else if jm.Time != 0 {
-		fmt.Fprintf(out, "%s ", time.Unix(jm.Time, 0).Format(jsonlog.RFC3339NanoFixed))
+		fmt.Fprintf(out, "%s ", time.Unix(jm.Time, 0).Format(RFC3339NanoFixed))
 	}
 	if jm.ID != "" {
 		fmt.Fprintf(out, "%s: ", jm.ID)

pkg/jsonmessage/jsonmessage_test.go

@@ -8,7 +8,6 @@ import (
 	"testing"
 	"time"
 
-	"github.com/docker/docker/pkg/jsonlog"
 	"github.com/docker/docker/pkg/term"
 	"github.com/stretchr/testify/assert"
 )
@@ -115,8 +114,8 @@ func TestJSONMessageDisplay(t *testing.T) {
 			From:   "From",
 			Status: "status",
 		}: {
-			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now.Unix(), 0).Format(jsonlog.RFC3339NanoFixed)),
-			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now.Unix(), 0).Format(jsonlog.RFC3339NanoFixed)),
+			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now.Unix(), 0).Format(RFC3339NanoFixed)),
+			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(now.Unix(), 0).Format(RFC3339NanoFixed)),
 		},
 		// General, with nano precision time
 		{
@@ -125,8 +124,8 @@ func TestJSONMessageDisplay(t *testing.T) {
 			From:     "From",
 			Status:   "status",
 		}: {
-			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(jsonlog.RFC3339NanoFixed)),
-			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(jsonlog.RFC3339NanoFixed)),
+			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(RFC3339NanoFixed)),
+			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(RFC3339NanoFixed)),
 		},
 		// General, with both times Nano is preferred
 		{
@@ -136,8 +135,8 @@ func TestJSONMessageDisplay(t *testing.T) {
 			From:     "From",
 			Status:   "status",
 		}: {
-			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(jsonlog.RFC3339NanoFixed)),
-			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(jsonlog.RFC3339NanoFixed)),
+			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(RFC3339NanoFixed)),
+			fmt.Sprintf("%v ID: (from From) status\n", time.Unix(0, now.UnixNano()).Format(RFC3339NanoFixed)),
 		},
 		// Stream over status
 		{