diff options
Diffstat (limited to 'pkg/log')
-rw-r--r-- | pkg/log/glog.go | 163 | ||||
-rw-r--r-- | pkg/log/glog_unsafe.go | 32 | ||||
-rw-r--r-- | pkg/log/json.go | 76 | ||||
-rw-r--r-- | pkg/log/json_k8s.go | 47 | ||||
-rw-r--r-- | pkg/log/log.go | 323 | ||||
-rwxr-xr-x | pkg/log/log_state_autogen.go | 4 |
6 files changed, 645 insertions, 0 deletions
diff --git a/pkg/log/glog.go b/pkg/log/glog.go new file mode 100644 index 000000000..5732785b4 --- /dev/null +++ b/pkg/log/glog.go @@ -0,0 +1,163 @@ +// 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 ( + "os" + "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 +} + +// 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") + +// 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 level. + switch level { + case Debug: + b.write('D') + case Info: + b.write('I') + case Warning: + b.write('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]) + } + + // End with a newline. + b.write('\n') + + // Pass to the underlying routine. + g.Emitter.Emit(level, timestamp, b.String(), args...) +} diff --git a/pkg/log/glog_unsafe.go b/pkg/log/glog_unsafe.go new file mode 100644 index 000000000..ea17ae349 --- /dev/null +++ b/pkg/log/glog_unsafe.go @@ -0,0 +1,32 @@ +// 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.go b/pkg/log/json.go new file mode 100644 index 000000000..a278c8fc8 --- /dev/null +++ b/pkg/log/json.go @@ -0,0 +1,76 @@ +// 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 ( + "encoding/json" + "fmt" + "time" +) + +type jsonLog struct { + Msg string `json:"msg"` + Level Level `json:"level"` + Time time.Time `json:"time"` +} + +// MarshalJSON implements json.Marshaler.MarashalJSON. +func (lv Level) MarshalJSON() ([]byte, error) { + switch lv { + case Warning: + return []byte(`"warning"`), nil + case Info: + return []byte(`"info"`), nil + case Debug: + return []byte(`"debug"`), nil + default: + return nil, fmt.Errorf("unknown level %v", lv) + } +} + +// UnmarshalJSON implements json.Unmarshaler.UnmarshalJSON. It can unmarshal +// from both string names and integers. +func (lv *Level) UnmarshalJSON(b []byte) error { + switch s := string(b); s { + case "0", `"warning"`: + *lv = Warning + case "1", `"info"`: + *lv = Info + case "2", `"debug"`: + *lv = Debug + default: + return fmt.Errorf("unknown level %q", s) + } + return nil +} + +// JSONEmitter logs messages in json format. +type JSONEmitter struct { + Writer +} + +// Emit implements Emitter.Emit. +func (e JSONEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) { + j := jsonLog{ + Msg: fmt.Sprintf(format, v...), + Level: level, + Time: timestamp, + } + b, err := json.Marshal(j) + if err != nil { + panic(err) + } + e.Writer.Write(b) +} diff --git a/pkg/log/json_k8s.go b/pkg/log/json_k8s.go new file mode 100644 index 000000000..c2c019915 --- /dev/null +++ b/pkg/log/json_k8s.go @@ -0,0 +1,47 @@ +// 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 ( + "encoding/json" + "fmt" + "time" +) + +type k8sJSONLog struct { + Log string `json:"log"` + Level Level `json:"level"` + Time time.Time `json:"time"` +} + +// K8sJSONEmitter logs messages in json format that is compatible with +// Kubernetes fluent configuration. +type K8sJSONEmitter struct { + Writer +} + +// Emit implements Emitter.Emit. +func (e K8sJSONEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) { + j := k8sJSONLog{ + Log: fmt.Sprintf(format, v...), + Level: level, + Time: timestamp, + } + b, err := json.Marshal(j) + if err != nil { + panic(err) + } + e.Writer.Write(b) +} diff --git a/pkg/log/log.go b/pkg/log/log.go new file mode 100644 index 000000000..7d563241e --- /dev/null +++ b/pkg/log/log.go @@ -0,0 +1,323 @@ +// 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 implements a library for logging. +// +// 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. +package log + +import ( + "fmt" + "io" + stdlog "log" + "os" + "runtime" + "sync" + "sync/atomic" + "syscall" + "time" + + "gvisor.googlesource.com/gvisor/pkg/linewriter" +) + +// Level is the log level. +type Level uint32 + +// The following levels are fixed, and can never be changed. Since some control +// RPCs allow for changing the level as an integer, it is only possible to add +// additional levels, and the existing one cannot be removed. +const ( + // Warning indicates that output should always be emitted. + Warning Level = iota + + // Info indicates that output should normally be emitted. + Info + + // Debug indicates that output should not normally be emitted. + Debug +) + +// Emitter is the final destination for logs. +type Emitter interface { + // Emit emits the given log statement. This allows for control over the + // timestamp used for logging. + Emit(level Level, timestamp time.Time, format string, v ...interface{}) +} + +// Writer writes the output to the given writer. +type Writer struct { + // Next is where output is written. + Next io.Writer + + // mu protects fields below. + mu sync.Mutex + + // errors counts failures to write log messages so it can be reported + // when writer start to work again. Needs to be accessed using atomics + // to make race detector happy because it's read outside the mutex. + errors int32 +} + +// Write writes out the given bytes, handling non-blocking sockets. +func (l *Writer) Write(data []byte) (int, error) { + n := 0 + + for n < len(data) { + w, err := l.Next.Write(data[n:]) + n += w + + // Is it a non-blocking socket? + if pathErr, ok := err.(*os.PathError); ok && pathErr.Err == syscall.EAGAIN { + runtime.Gosched() + continue + } + + // Some other error? + if err != nil { + l.mu.Lock() + atomic.AddInt32(&l.errors, 1) + l.mu.Unlock() + return n, err + } + } + + // Do we need to end with a '\n'? + if len(data) == 0 || data[len(data)-1] != '\n' { + l.Write([]byte{'\n'}) + } + + // Dirty read in case there were errors (rare). + if atomic.LoadInt32(&l.errors) > 0 { + l.mu.Lock() + defer l.mu.Unlock() + + // Recheck condition under lock. + if e := atomic.LoadInt32(&l.errors); e > 0 { + msg := fmt.Sprintf("\n*** Dropped %d log messages ***\n", e) + if _, err := l.Next.Write([]byte(msg)); err == nil { + atomic.StoreInt32(&l.errors, 0) + } + } + } + + return n, nil +} + +// Emit emits the message. +func (l *Writer) Emit(level Level, timestamp time.Time, format string, args ...interface{}) { + fmt.Fprintf(l, format, args...) +} + +// MultiEmitter is an emitter that emits to multiple Emitters. +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 { + e.Emit(level, timestamp, format, v...) + } +} + +// TestLogger is implemented by testing.T and testing.B. +type TestLogger interface { + Logf(format string, v ...interface{}) +} + +// TestEmitter may be used for wrapping tests. +type TestEmitter struct { + TestLogger +} + +// Emit emits to the TestLogger. +func (t TestEmitter) Emit(level Level, timestamp time.Time, format string, v ...interface{}) { + t.Logf(format, v...) +} + +// Logger is a high-level logging interface. It is in fact, not used within the +// log package. Rather it is provided for others to provide contextual loggers +// that may append some addition information to log statement. BasicLogger +// satisfies this interface, and may be passed around as a Logger. +type Logger interface { + // Debugf logs a debug statement. + Debugf(format string, v ...interface{}) + + // Infof logs at an info level. + Infof(format string, v ...interface{}) + + // Warningf logs at a warning level. + Warningf(format string, v ...interface{}) + + // IsLogging returns true iff this level is being logged. This may be + // used to short-circuit expensive operations for debugging calls. + IsLogging(level Level) bool +} + +// BasicLogger is the default implementation of Logger. +type BasicLogger struct { + Level + Emitter +} + +// Debugf implements logger.Debugf. +func (l *BasicLogger) Debugf(format string, v ...interface{}) { + if l.IsLogging(Debug) { + l.Emit(Debug, time.Now(), format, v...) + } +} + +// Infof implements logger.Infof. +func (l *BasicLogger) Infof(format string, v ...interface{}) { + if l.IsLogging(Info) { + l.Emit(Info, time.Now(), format, v...) + } +} + +// Warningf implements logger.Warningf. +func (l *BasicLogger) Warningf(format string, v ...interface{}) { + if l.IsLogging(Warning) { + l.Emit(Warning, time.Now(), format, v...) + } +} + +// IsLogging implements logger.IsLogging. +func (l *BasicLogger) IsLogging(level Level) bool { + return atomic.LoadUint32((*uint32)(&l.Level)) >= uint32(level) +} + +// SetLevel sets the logging level. +func (l *BasicLogger) SetLevel(level Level) { + atomic.StoreUint32((*uint32)(&l.Level), uint32(level)) +} + +// logMu protects Log below. We use atomic operations to read the value, but +// updates require logMu to ensure consistency. +var logMu sync.Mutex + +// log is the default logger. +var log atomic.Value + +// Log retieves the global logger. +func Log() *BasicLogger { + return log.Load().(*BasicLogger) +} + +// SetTarget sets the log target. +// +// This is not thread safe and shouldn't be called concurrently with any +// logging calls. +func SetTarget(target Emitter) { + logMu.Lock() + defer logMu.Unlock() + oldLog := Log() + log.Store(&BasicLogger{Level: oldLog.Level, Emitter: target}) +} + +// SetLevel sets the log level. +func SetLevel(newLevel Level) { + Log().SetLevel(newLevel) +} + +// Debugf logs to the global logger. +func Debugf(format string, v ...interface{}) { + Log().Debugf(format, v...) +} + +// Infof logs to the global logger. +func Infof(format string, v ...interface{}) { + Log().Infof(format, v...) +} + +// Warningf logs to the global logger. +func Warningf(format string, v ...interface{}) { + Log().Warningf(format, v...) +} + +// defaultStackSize is the default buffer size to allocate for stack traces. +const defaultStackSize = 1 << 16 // 64KB + +// maxStackSize is the maximum buffer size to allocate for stack traces. +const maxStackSize = 1 << 26 // 64MB + +// Stacks returns goroutine stacks, like panic. +func Stacks(all bool) []byte { + var trace []byte + for s := defaultStackSize; s <= maxStackSize; s *= 4 { + trace = make([]byte, s) + nbytes := runtime.Stack(trace, all) + if nbytes == s { + continue + } + return trace[:nbytes] + } + trace = append(trace, []byte("\n\n...<too large, truncated>")...) + return trace +} + +// Traceback logs the given message and dumps a stacktrace of the current +// goroutine. +// +// This will be print a traceback, tb, as Warningf(format+":\n%s", v..., tb). +func Traceback(format string, v ...interface{}) { + v = append(v, Stacks(false)) + Warningf(format+":\n%s", v...) +} + +// TracebackAll logs the given message and dumps a stacktrace of all goroutines. +// +// This will be print a traceback, tb, as Warningf(format+":\n%s", v..., tb). +func TracebackAll(format string, v ...interface{}) { + v = append(v, Stacks(true)) + Warningf(format+":\n%s", v...) +} + +// IsLogging returns whether the global logger is logging. +func IsLogging(level Level) bool { + return Log().IsLogging(level) +} + +// CopyStandardLogTo redirects the stdlib log package global output to the global +// logger for the specified level. +func CopyStandardLogTo(l Level) error { + var f func(string, ...interface{}) + + switch l { + case Debug: + f = Debugf + case Info: + f = Infof + case Warning: + f = Warningf + default: + return fmt.Errorf("Unknown log level %v", l) + } + + stdlog.SetOutput(linewriter.NewWriter(func(p []byte) { + // We must not retain p, but log formatting is not required to + // be synchronous (though the in-package implementations are), + // so we must make a copy. + b := make([]byte, len(p)) + copy(b, p) + + f("%s", b) + })) + + return nil +} + +func init() { + // Store the initial value for the log. + log.Store(&BasicLogger{Level: Info, Emitter: GoogleEmitter{&Writer{Next: os.Stderr}}}) +} diff --git a/pkg/log/log_state_autogen.go b/pkg/log/log_state_autogen.go new file mode 100755 index 000000000..010b760a5 --- /dev/null +++ b/pkg/log/log_state_autogen.go @@ -0,0 +1,4 @@ +// automatically generated by stateify. + +package log + |