summaryrefslogtreecommitdiffhomepage
path: root/pkg/log
diff options
context:
space:
mode:
Diffstat (limited to 'pkg/log')
-rw-r--r--pkg/log/BUILD1
-rw-r--r--pkg/log/glog.go164
-rw-r--r--pkg/log/glog_unsafe.go32
-rw-r--r--pkg/log/json_k8s.go2
-rw-r--r--pkg/log/log.go20
-rw-r--r--pkg/log/log_test.go35
6 files changed, 96 insertions, 158 deletions
diff --git a/pkg/log/BUILD b/pkg/log/BUILD
index 935d06963..a7c8f7bef 100644
--- a/pkg/log/BUILD
+++ b/pkg/log/BUILD
@@ -6,7 +6,6 @@ go_library(
name = "log",
srcs = [
"glog.go",
- "glog_unsafe.go",
"json.go",
"json_k8s.go",
"log.go",
diff --git a/pkg/log/glog.go b/pkg/log/glog.go
index 5732785b4..cab5fae55 100644
--- a/pkg/log/glog.go
+++ b/pkg/log/glog.go
@@ -15,149 +15,73 @@
package log
import (
+ "fmt"
"os"
+ "runtime"
+ "strings"
"time"
)
// GoogleEmitter is a wrapper that emits logs in a format compatible with
// package github.com/golang/glog.
type GoogleEmitter struct {
- // Emitter is the underlying emitter.
- Emitter
-}
-
-// buffer is a simple inline buffer to avoid churn. The data slice is generally
-// kept to the local byte array, and we avoid having to allocate it on the heap.
-type buffer struct {
- local [256]byte
- data []byte
-}
-
-func (b *buffer) start() {
- b.data = b.local[:0]
-}
-
-func (b *buffer) String() string {
- return unsafeString(b.data)
-}
-
-func (b *buffer) write(c byte) {
- b.data = append(b.data, c)
-}
-
-func (b *buffer) writeAll(d []byte) {
- b.data = append(b.data, d...)
-}
-
-func (b *buffer) writeOneDigit(d byte) {
- b.write('0' + d)
-}
-
-func (b *buffer) writeTwoDigits(v int) {
- v = v % 100
- b.writeOneDigit(byte(v / 10))
- b.writeOneDigit(byte(v % 10))
-}
-
-func (b *buffer) writeSixDigits(v int) {
- v = v % 1000000
- b.writeOneDigit(byte(v / 100000))
- b.writeOneDigit(byte((v % 100000) / 10000))
- b.writeOneDigit(byte((v % 10000) / 1000))
- b.writeOneDigit(byte((v % 1000) / 100))
- b.writeOneDigit(byte((v % 100) / 10))
- b.writeOneDigit(byte(v % 10))
-}
-
-func calculateBytes(v int, pad int) []byte {
- var d []byte
- r := 1
-
- for n := 10; v >= r; n = n * 10 {
- d = append(d, '0'+byte((v%n)/r))
- r = n
- }
-
- for i := len(d); i < pad; i++ {
- d = append(d, ' ')
- }
-
- for i := 0; i < len(d)/2; i++ {
- d[i], d[len(d)-(i+1)] = d[len(d)-(i+1)], d[i]
- }
- return d
+ Writer
}
// pid is used for the threadid component of the header.
-//
-// The glog package logger uses 7 spaces of padding. See
-// glob.loggingT.formatHeader.
-var pid = calculateBytes(os.Getpid(), 7)
-
-// caller is faked out as the caller. See FIXME below.
-var caller = []byte("x:0")
+var pid = os.Getpid()
// Emit emits the message, google-style.
-func (g GoogleEmitter) Emit(level Level, timestamp time.Time, format string, args ...interface{}) {
- var b buffer
- b.start()
-
- // Log lines have this form:
- // Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
- //
- // where the fields are defined as follows:
- // L A single character, representing the log level (eg 'I' for INFO)
- // mm The month (zero padded; ie May is '05')
- // dd The day (zero padded)
- // hh:mm:ss.uuuuuu Time in hours, minutes and fractional seconds
- // threadid The space-padded thread ID as returned by GetTID()
- // file The file name
- // line The line number
- // msg The user-supplied message
-
+//
+// Log lines have this form:
+// Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
+//
+// where the fields are defined as follows:
+// L A single character, representing the log level (eg 'I' for INFO)
+// mm The month (zero padded; ie May is '05')
+// dd The day (zero padded)
+// hh:mm:ss.uuuuuu Time in hours, minutes and fractional seconds
+// threadid The space-padded thread ID as returned by GetTID()
+// file The file name
+// line The line number
+// msg The user-supplied message
+//
+func (g *GoogleEmitter) Emit(level Level, timestamp time.Time, format string, args ...interface{}) {
// Log level.
+ prefix := byte('?')
switch level {
case Debug:
- b.write('D')
+ prefix = byte('D')
case Info:
- b.write('I')
+ prefix = byte('I')
case Warning:
- b.write('W')
+ prefix = byte('W')
}
// Timestamp.
_, month, day := timestamp.Date()
hour, minute, second := timestamp.Clock()
- b.writeTwoDigits(int(month))
- b.writeTwoDigits(int(day))
- b.write(' ')
- b.writeTwoDigits(int(hour))
- b.write(':')
- b.writeTwoDigits(int(minute))
- b.write(':')
- b.writeTwoDigits(int(second))
- b.write('.')
- b.writeSixDigits(int(timestamp.Nanosecond() / 1000))
- b.write(' ')
-
- // The pid.
- b.writeAll(pid)
- b.write(' ')
-
- // FIXME(b/73383460): The caller, fabricated. This really sucks, but it
- // is unacceptable to put runtime.Callers() in the hot path.
- b.writeAll(caller)
- b.write(']')
- b.write(' ')
-
- // User-provided format string, copied.
- for i := 0; i < len(format); i++ {
- b.write(format[i])
+ microsecond := int(timestamp.Nanosecond() / 1000)
+
+ // 0 = this frame.
+ // 1 = Debugf, etc.
+ // 2 = Caller.
+ _, file, line, ok := runtime.Caller(2)
+ if ok {
+ // Trim any directory path from the file.
+ slash := strings.LastIndexByte(file, byte('/'))
+ if slash >= 0 {
+ file = file[slash+1:]
+ }
+ } else {
+ // We don't have a filename.
+ file = "???"
+ line = 0
}
- // End with a newline.
- b.write('\n')
+ // Generate the message.
+ message := fmt.Sprintf(format, args...)
- // Pass to the underlying routine.
- g.Emitter.Emit(level, timestamp, b.String(), args...)
+ // Emit the formatted result.
+ fmt.Fprintf(&g.Writer, "%c%02d%02d %02d:%02d:%02d.%06d % 7d %s:%d] %s\n", prefix, int(month), day, hour, minute, second, microsecond, pid, file, line, message)
}
diff --git a/pkg/log/glog_unsafe.go b/pkg/log/glog_unsafe.go
deleted file mode 100644
index ea17ae349..000000000
--- a/pkg/log/glog_unsafe.go
+++ /dev/null
@@ -1,32 +0,0 @@
-// Copyright 2018 The gVisor Authors.
-//
-// Licensed under the Apache License, Version 2.0 (the "License");
-// you may not use this file except in compliance with the License.
-// You may obtain a copy of the License at
-//
-// http://www.apache.org/licenses/LICENSE-2.0
-//
-// Unless required by applicable law or agreed to in writing, software
-// distributed under the License is distributed on an "AS IS" BASIS,
-// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
-// See the License for the specific language governing permissions and
-// limitations under the License.
-
-package log
-
-import (
- "reflect"
- "unsafe"
-)
-
-// unsafeString returns a string that points to the given byte array.
-// The byte array must be preserved until the string is disposed.
-func unsafeString(data []byte) (s string) {
- if len(data) == 0 {
- return
- }
-
- (*reflect.StringHeader)(unsafe.Pointer(&s)).Data = uintptr(unsafe.Pointer(&data[0]))
- (*reflect.StringHeader)(unsafe.Pointer(&s)).Len = len(data)
- return
-}
diff --git a/pkg/log/json_k8s.go b/pkg/log/json_k8s.go
index c2c019915..cee6eb514 100644
--- a/pkg/log/json_k8s.go
+++ b/pkg/log/json_k8s.go
@@ -33,7 +33,7 @@ type K8sJSONEmitter struct {
}
// Emit implements Emitter.Emit.
-func (e K8sJSONEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) {
+func (e *K8sJSONEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) {
j := k8sJSONLog{
Log: fmt.Sprintf(format, v...),
Level: level,
diff --git a/pkg/log/log.go b/pkg/log/log.go
index 91a81b288..5056f17e6 100644
--- a/pkg/log/log.go
+++ b/pkg/log/log.go
@@ -17,6 +17,18 @@
// This is separate from the standard logging package because logging may be a
// high-impact activity, and therefore we wanted to provide as much flexibility
// as possible in the underlying implementation.
+//
+// Note that logging should still be considered high-impact, and should not be
+// done in the hot path. If necessary, logging statements should be protected
+// with guards regarding the logging level. For example,
+//
+// if log.IsLogging(log.Debug) {
+// log.Debugf(...)
+// }
+//
+// This is because the log.Debugf(...) statement alone will generate a
+// significant amount of garbage and churn in many cases, even if no log
+// message is ultimately emitted.
package log
import (
@@ -138,8 +150,8 @@ func (l *Writer) Emit(level Level, timestamp time.Time, format string, args ...i
type MultiEmitter []Emitter
// Emit emits to all emitters.
-func (m MultiEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) {
- for _, e := range m {
+func (m *MultiEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) {
+ for _, e := range *m {
e.Emit(level, timestamp, format, v...)
}
}
@@ -155,7 +167,7 @@ type TestEmitter struct {
}
// Emit emits to the TestLogger.
-func (t TestEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) {
+func (t *TestEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) {
t.Logf(format, v...)
}
@@ -332,5 +344,5 @@ func CopyStandardLogTo(l Level) error {
func init() {
// Store the initial value for the log.
- log.Store(&BasicLogger{Level: Info, Emitter: GoogleEmitter{&Writer{Next: os.Stderr}}})
+ log.Store(&BasicLogger{Level: Info, Emitter: &GoogleEmitter{Writer{Next: os.Stderr}}})
}
diff --git a/pkg/log/log_test.go b/pkg/log/log_test.go
index 0634e7c1f..402cc29ae 100644
--- a/pkg/log/log_test.go
+++ b/pkg/log/log_test.go
@@ -16,18 +16,23 @@ package log
import (
"fmt"
+ "strings"
"testing"
)
type testWriter struct {
lines []string
fail bool
+ limit int
}
func (w *testWriter) Write(bytes []byte) (int, error) {
if w.fail {
return 0, fmt.Errorf("simulated failure")
}
+ if w.limit > 0 && len(w.lines) >= w.limit {
+ return len(bytes), nil
+ }
w.lines = append(w.lines, string(bytes))
return len(bytes), nil
}
@@ -68,3 +73,33 @@ func TestDropMessages(t *testing.T) {
}
}
}
+
+func TestCaller(t *testing.T) {
+ tw := &testWriter{}
+ e := &GoogleEmitter{Writer: Writer{Next: tw}}
+ bl := &BasicLogger{
+ Emitter: e,
+ Level: Debug,
+ }
+ bl.Debugf("testing...\n") // Just for file + line.
+ if len(tw.lines) != 1 {
+ t.Errorf("expected 1 line, got %d", len(tw.lines))
+ }
+ if !strings.Contains(tw.lines[0], "log_test.go") {
+ t.Errorf("expected log_test.go, got %q", tw.lines[0])
+ }
+}
+
+func BenchmarkGoogleLogging(b *testing.B) {
+ tw := &testWriter{
+ limit: 1, // Only record one message.
+ }
+ e := &GoogleEmitter{Writer: Writer{Next: tw}}
+ bl := &BasicLogger{
+ Emitter: e,
+ Level: Debug,
+ }
+ for i := 0; i < b.N; i++ {
+ bl.Debugf("hello %d, %d, %d", 1, 2, 3)
+ }
+}
generated by cgit v1.2.3 (git 2.39.1) at 2024-11-29 03:50:52 +0000