From 712109f1f1c871498147d1ce44b6cff0b64e03e0 Mon Sep 17 00:00:00 2001 From: Rob Pike Date: Tue, 12 Oct 2010 17:27:14 -0700 Subject: [PATCH] log: reduce allocations Use a bytes.Buffer in log writing instead of string concatenation. Should reduce the number of allocations significantly. R=rsc, r2 CC=golang-dev https://golang.org/cl/2417042 --- src/pkg/log/log.go | 59 +++++++++++++++++++++++++++-------------- src/pkg/log/log_test.go | 4 ++- 2 files changed, 42 insertions(+), 21 deletions(-) diff --git a/src/pkg/log/log.go b/src/pkg/log/log.go index 1978358c28..74602d93c6 100644 --- a/src/pkg/log/log.go +++ b/src/pkg/log/log.go @@ -14,6 +14,7 @@ package log import ( + "bytes" "fmt" "io" "runtime" @@ -32,7 +33,6 @@ const ( Lmicroseconds // microsecond resolution: 01:23:23.123123. assumes Ltime. Llongfile // full file name and line number: /a/b/c/d.go:23 Lshortfile // final file name element and line number: d.go:23. overrides Llongfile - lallBits = Ldate | Ltime | Lmicroseconds | Llongfile | Lshortfile ) // Logger represents an active logging object. @@ -55,11 +55,13 @@ var ( stdout = New(os.Stdout, "", Ldate|Ltime) // Deprecated. ) -// Cheap integer to fixed-width decimal ASCII. Use a negative width to avoid zero-padding -func itoa(i int, wid int) string { +// Cheap integer to fixed-width decimal ASCII. Give a negative width to avoid zero-padding. +// Knows the buffer has capacity. +func itoa(buf *bytes.Buffer, i int, wid int) { var u uint = uint(i) if u == 0 && wid <= 1 { - return "0" + buf.WriteByte('0') + return } // Assemble decimal in reverse order. @@ -71,22 +73,36 @@ func itoa(i int, wid int) string { b[bp] = byte(u%10) + '0' } - return string(b[bp:]) + // avoid slicing b to avoid an allocation. + for bp < len(b) { + buf.WriteByte(b[bp]) + bp++ + } } -func (l *Logger) formatHeader(ns int64, calldepth int) string { - h := l.prefix +func (l *Logger) formatHeader(buf *bytes.Buffer, ns int64, calldepth int) { + buf.WriteString(l.prefix) if l.flag&(Ldate|Ltime|Lmicroseconds) != 0 { t := time.SecondsToLocalTime(ns / 1e9) - if l.flag&(Ldate) != 0 { - h += itoa(int(t.Year), 4) + "/" + itoa(t.Month, 2) + "/" + itoa(t.Day, 2) + " " + if l.flag&Ldate != 0 { + itoa(buf, int(t.Year), 4) + buf.WriteByte('/') + itoa(buf, int(t.Month), 2) + buf.WriteByte('/') + itoa(buf, int(t.Day), 2) + buf.WriteByte(' ') } if l.flag&(Ltime|Lmicroseconds) != 0 { - h += itoa(t.Hour, 2) + ":" + itoa(t.Minute, 2) + ":" + itoa(t.Second, 2) + itoa(buf, int(t.Hour), 2) + buf.WriteByte(':') + itoa(buf, int(t.Minute), 2) + buf.WriteByte(':') + itoa(buf, int(t.Second), 2) if l.flag&Lmicroseconds != 0 { - h += "." + itoa(int(ns%1e9)/1e3, 6) + buf.WriteByte('.') + itoa(buf, int(ns%1e9)/1e3, 6) } - h += " " + buf.WriteByte(' ') } } if l.flag&(Lshortfile|Llongfile) != 0 { @@ -106,9 +122,11 @@ func (l *Logger) formatHeader(ns int64, calldepth int) string { file = "???" line = 0 } - h += file + ":" + itoa(line, -1) + ": " + buf.WriteString(file) + buf.WriteByte(':') + itoa(buf, line, -1) + buf.WriteString(": ") } - return h } // Output writes the output for a logging event. The string s contains the text to print after @@ -116,12 +134,13 @@ func (l *Logger) formatHeader(ns int64, calldepth int) string { // at the moment on all pre-defined paths it will be 2. func (l *Logger) Output(calldepth int, s string) os.Error { now := time.Nanoseconds() // get this early. - newline := "\n" - if len(s) > 0 && s[len(s)-1] == '\n' { - newline = "" + buf := new(bytes.Buffer) + l.formatHeader(buf, now, calldepth+1) + buf.WriteString(s) + if len(s) > 0 && s[len(s)-1] != '\n' { + buf.WriteByte('\n') } - s = l.formatHeader(now, calldepth+1) + s + newline - _, err := io.WriteString(l.out, s) + _, err := std.out.Write(buf.Bytes()) return err } @@ -143,7 +162,7 @@ func SetOutput(w io.Writer) { // SetFlags sets the output flags for the standard logger. func SetFlags(flag int) { - std.flag = flag & lallBits + std.flag = flag } // SetPrefix sets the output prefix for the standard logger. diff --git a/src/pkg/log/log_test.go b/src/pkg/log/log_test.go index a5b1f281de..0a5753f3a9 100644 --- a/src/pkg/log/log_test.go +++ b/src/pkg/log/log_test.go @@ -8,6 +8,7 @@ package log import ( "bytes" + "os" "regexp" "testing" ) @@ -16,7 +17,7 @@ const ( Rdate = `[0-9][0-9][0-9][0-9]/[0-9][0-9]/[0-9][0-9]` Rtime = `[0-9][0-9]:[0-9][0-9]:[0-9][0-9]` Rmicroseconds = `\.[0-9][0-9][0-9][0-9][0-9][0-9]` - Rline = `(53|55):` // must update if the calls to l.Printf / l.Print below move + Rline = `(54|56):` // must update if the calls to l.Printf / l.Print below move Rlongfile = `.*/[A-Za-z0-9_\-]+\.go:` + Rline Rshortfile = `[A-Za-z0-9_\-]+\.go:` + Rline ) @@ -64,6 +65,7 @@ func testPrint(t *testing.T, flag int, prefix string, pattern string, useFormat if !matched { t.Errorf("log output should match %q is %q", pattern, line) } + SetOutput(os.Stderr) } func TestAll(t *testing.T) {