From a06ad2792ab92d4f246e4b4cc4c3529eb060651e Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Mon, 25 Sep 2017 15:52:42 -0400 Subject: [PATCH] Fix benchmarks and remove more unnecessary code. Signed-off-by: Daniel Nephin --- daemon/logger/jsonfilelog/jsonfilelog.go | 8 +- daemon/logger/jsonfilelog/jsonfilelog_test.go | 104 ++++++------------ daemon/logger/jsonfilelog/read_test.go | 65 +++++++++++ pkg/jsonlog/jsonlog.go | 3 +- pkg/jsonlog/jsonlogbytes.go | 72 +----------- 5 files changed, 103 insertions(+), 149 deletions(-) create mode 100644 daemon/logger/jsonfilelog/read_test.go diff --git a/daemon/logger/jsonfilelog/jsonfilelog.go b/daemon/logger/jsonfilelog/jsonfilelog.go index 351d6eeed5..f9aac82fe5 100644 --- a/daemon/logger/jsonfilelog/jsonfilelog.go +++ b/daemon/logger/jsonfilelog/jsonfilelog.go @@ -14,7 +14,7 @@ import ( "github.com/docker/docker/daemon/logger" "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,10 +106,8 @@ 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 { diff --git a/daemon/logger/jsonfilelog/jsonfilelog_test.go b/daemon/logger/jsonfilelog/jsonfilelog_test.go index d2d36e943b..e3ebc64d0e 100644 --- a/daemon/logger/jsonfilelog/jsonfilelog_test.go +++ b/daemon/logger/jsonfilelog/jsonfilelog_test.go @@ -1,6 +1,7 @@ package jsonfilelog import ( + "bytes" "encoding/json" "io/ioutil" "os" @@ -12,6 +13,8 @@ import ( "github.com/docker/docker/daemon/logger" "github.com/docker/docker/pkg/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, - }) - if err != nil { - b.Fatal(err) - } - defer l.Close() +func BenchmarkJSONFileLoggerLog(b *testing.B) { + tmp := fs.NewDir(b, "bench-jsonfilelog") + defer tmp.Remove() - 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) + 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(), } - 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 - } - } -} diff --git a/daemon/logger/jsonfilelog/read_test.go b/daemon/logger/jsonfilelog/read_test.go new file mode 100644 index 0000000000..ffae3b0ab5 --- /dev/null +++ b/daemon/logger/jsonfilelog/read_test.go @@ -0,0 +1,65 @@ +package jsonfilelog + +import ( + "testing" + + "bytes" + "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) + } + } + } +} diff --git a/pkg/jsonlog/jsonlog.go b/pkg/jsonlog/jsonlog.go index 7b9871ae87..549e355855 100644 --- a/pkg/jsonlog/jsonlog.go +++ b/pkg/jsonlog/jsonlog.go @@ -4,8 +4,7 @@ import ( "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. +// 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"` diff --git a/pkg/jsonlog/jsonlogbytes.go b/pkg/jsonlog/jsonlogbytes.go index 79941d4119..37604ae549 100644 --- a/pkg/jsonlog/jsonlogbytes.go +++ b/pkg/jsonlog/jsonlogbytes.go @@ -17,8 +17,8 @@ type JSONLogs struct { 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 @@ -35,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 { @@ -61,72 +61,6 @@ func (mj *JSONLogs) MarshalJSONBuf(buf *bytes.Buffer) error { 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('"') -} - -// This is based on ffjsonWriteJSONString. It has been changed -// to accept a string passed as a slice of bytes. -// TODO: remove duplication with ffjsonWriteJSONString func ffjsonWriteJSONBytesAsString(buf *bytes.Buffer, s []byte) { const hex = "0123456789abcdef"