Check in gVisor.

PiperOrigin-RevId: 194583126
Change-Id: Ica1d8821a90f74e7e745962d71801c598c652463

7 files changed, 756 insertions, 0 deletions

diff --git a/pkg/log/BUILD b/pkg/log/BUILD
new file mode 100644
index 000000000..2530cfd18
--- /dev/null
+++ b/pkg/log/BUILD
@@ -0,0 +1,28 @@
+package(licenses = ["notice"])  # Apache 2.0
+
+load("@io_bazel_rules_go//go:def.bzl", "go_library", "go_test")
+
+go_library(
+    name = "log",
+    srcs = [
+        "glog.go",
+        "glog_unsafe.go",
+        "json.go",
+        "log.go",
+    ],
+    importpath = "gvisor.googlesource.com/gvisor/pkg/log",
+    visibility = [
+        "//visibility:public",
+    ],
+    deps = ["//pkg/linewriter"],
+)
+
+go_test(
+    name = "log_test",
+    size = "small",
+    srcs = [
+        "json_test.go",
+        "log_test.go",
+    ],
+    embed = [":log"],
+)
diff --git a/pkg/log/glog.go b/pkg/log/glog.go
new file mode 100644
index 000000000..58b4052e6
--- /dev/null
+++ b/pkg/log/glog.go
@@ -0,0 +1,163 @@
+// Copyright 2018 Google Inc.
+//
+// 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: 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..c320190b8
--- /dev/null
+++ b/pkg/log/glog_unsafe.go
@@ -0,0 +1,32 @@
+// Copyright 2018 Google Inc.
+//
+// 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..3887f1cd5
--- /dev/null
+++ b/pkg/log/json.go
@@ -0,0 +1,76 @@
+// Copyright 2018 Google Inc.
+//
+// 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_test.go b/pkg/log/json_test.go
new file mode 100644
index 000000000..3b167dab0
--- /dev/null
+++ b/pkg/log/json_test.go
@@ -0,0 +1,64 @@
+// Copyright 2018 Google Inc.
+//
+// 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"
+	"testing"
+)
+
+// Tests that Level can marshal/unmarshal properly.
+func TestLevelMarshal(t *testing.T) {
+	lvs := []Level{Warning, Info, Debug}
+	for _, lv := range lvs {
+		bs, err := lv.MarshalJSON()
+		if err != nil {
+			t.Errorf("error marshaling %v: %v", lv, err)
+		}
+		var lv2 Level
+		if err := lv2.UnmarshalJSON(bs); err != nil {
+			t.Errorf("error unmarshaling %v: %v", bs, err)
+		}
+		if lv != lv2 {
+			t.Errorf("marshal/unmarshal level got %v wanted %v", lv2, lv)
+		}
+	}
+}
+
+// Test that integers can be properly unmarshaled.
+func TestUnmarshalFromInt(t *testing.T) {
+	tcs := []struct {
+		i    int
+		want Level
+	}{
+		{0, Warning},
+		{1, Info},
+		{2, Debug},
+	}
+
+	for _, tc := range tcs {
+		j, err := json.Marshal(tc.i)
+		if err != nil {
+			t.Errorf("error marshaling %v: %v", tc.i, err)
+		}
+		var lv Level
+		if err := lv.UnmarshalJSON(j); err != nil {
+			t.Errorf("error unmarshaling %v: %v", j, err)
+		}
+		if lv != tc.want {
+			t.Errorf("marshal/unmarshal %v got %v want %v", tc.i, lv, tc.want)
+		}
+	}
+}
diff --git a/pkg/log/log.go b/pkg/log/log.go
new file mode 100644
index 000000000..110e0e196
--- /dev/null
+++ b/pkg/log/log.go
@@ -0,0 +1,323 @@
+// Copyright 2018 Google Inc.
+//
+// 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
+// satifies 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_test.go b/pkg/log/log_test.go
new file mode 100644
index 000000000..d93e989dc
--- /dev/null
+++ b/pkg/log/log_test.go
@@ -0,0 +1,70 @@
+// Copyright 2018 Google Inc.
+//
+// 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 (
+	"fmt"
+	"testing"
+)
+
+type testWriter struct {
+	lines []string
+	fail  bool
+}
+
+func (w *testWriter) Write(bytes []byte) (int, error) {
+	if w.fail {
+		return 0, fmt.Errorf("simulated failure")
+	}
+	w.lines = append(w.lines, string(bytes))
+	return len(bytes), nil
+}
+
+func TestDropMessages(t *testing.T) {
+	tw := &testWriter{}
+	w := Writer{Next: tw}
+	if _, err := w.Write([]byte("line 1\n")); err != nil {
+		t.Fatalf("Write failed, err: %v", err)
+	}
+
+	tw.fail = true
+	if _, err := w.Write([]byte("error\n")); err == nil {
+		t.Fatalf("Write should have failed")
+	}
+	if _, err := w.Write([]byte("error\n")); err == nil {
+		t.Fatalf("Write should have failed")
+	}
+
+	fmt.Printf("writer: %+v\n", w)
+
+	tw.fail = false
+	if _, err := w.Write([]byte("line 2\n")); err != nil {
+		t.Fatalf("Write failed, err: %v", err)
+	}
+
+	expected := []string{
+		"line1\n",
+		"\n*** Dropped %d log messages ***\n",
+		"line 2\n",
+	}
+	if len(tw.lines) != len(expected) {
+		t.Fatalf("Writer should have logged %d lines, got: %v, expected: %v", len(expected), tw.lines, expected)
+	}
+	for i, l := range tw.lines {
+		if l == expected[i] {
+			t.Fatalf("line %d doesn't match, got: %v, expected: %v", i, l, expected[i])
+		}
+	}
+}