merge with latest glog

go/glog/glog.go

@@ -37,6 +37,7 @@
 //
 // By default, all log statements write to files in a temporary directory.
 // This package provides several flags that modify this behavior.
+// As a result, flag.Parse must be called before any logging is done.
 //
 //	-logtostderr=false
 //		Logs are written to standard error instead of to files.
@@ -45,6 +46,9 @@
 //	-stderrthreshold=ERROR
 //		Log events at or above this severity are logged to standard
 //		error as well as to files.
+//	-log_dir=""
+//		Log files will be written to this directory instead of the
+//		default temporary directory.
 //
 //	Other flags provide aids to debugging.
 //
@@ -73,6 +77,7 @@ import (
 	"flag"
 	"fmt"
 	"io"
+	stdLog "log"
 	"os"
 	"path/filepath"
 	"runtime"
@@ -89,6 +94,9 @@ import (
 // the corresponding constants in C++.
 type severity int32 // sync/atomic int32
 
+// These constants identify the log levels in order of increasing severity.
+// A message written to a high-severity log file is also written to each
+// lower-severity log file.
 const (
 	infoLog severity = iota
 	warningLog
@@ -307,7 +315,7 @@ func (m *moduleSpec) Set(value string) error {
 // isLiteral reports whether the pattern is a literal string, that is, has no metacharacters
 // that require filepath.Match to be called to match the pattern.
 func isLiteral(pattern string) bool {
-	return !strings.ContainsAny(pattern, `*?[]\`)
+	return !strings.ContainsAny(pattern, `\*?[]`)
 }
 
 // traceLocation represents the setting of the -log_backtrace_at flag.
@@ -446,8 +454,7 @@ type loggingT struct {
 	vmodule   moduleSpec // The state of the -vmodule flag.
 	verbosity Level      // V logging level, the value of the -v flag/
 
-	// If the logging exits, the system should still run.
-	// This flag is to disable the logging if logging exited.
+	// added by seaweedfs
 	exited bool
 }
 
@@ -466,7 +473,7 @@ func (l *loggingT) setVState(verbosity Level, filter []modulePat, setFilter bool
 	// Turn verbosity off so V will not fire while we are in transition.
 	logging.verbosity.set(0)
 	// Ditto for filter length.
-	logging.filterLength = 0
+	atomic.StoreInt32(&logging.filterLength, 0)
 
 	// Set the new filters and wipe the pc->Level map if the filter has changed.
 	if setFilter {
@@ -513,7 +520,8 @@ var timeNow = time.Now // Stubbed out for testing.
 
 /*
 header formats a log header as defined by the C++ implementation.
-It returns a buffer containing the formatted header.
+It returns a buffer containing the formatted header and the user's file and line number.
+The depth specifies how many stack frames above lives the source line to be identified in the log message.
 
 Log lines have this form:
 	Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
@@ -527,10 +535,8 @@ where the fields are defined as follows:
 	line             The line number
 	msg              The user-supplied message
 */
-func (l *loggingT) header(s severity) *buffer {
-	// Lmmdd hh:mm:ss.uuuuuu threadid file:line]
-	now := timeNow()
-	_, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call.
+func (l *loggingT) header(s severity, depth int) (*buffer, string, int) {
+	_, file, line, ok := runtime.Caller(3 + depth)
 	if !ok {
 		file = "???"
 		line = 1
@@ -540,6 +546,12 @@ func (l *loggingT) header(s severity) *buffer {
 			file = file[slash+1:]
 		}
 	}
+	return l.formatHeader(s, file, line), file, line
+}
+
+// formatHeader formats a log header using the provided file name and line number.
+func (l *loggingT) formatHeader(s severity, file string, line int) *buffer {
+	now := timeNow()
 	if line < 0 {
 		line = 0 // not a real line number, but acceptable to someDigits
 	}
@@ -552,6 +564,7 @@ func (l *loggingT) header(s severity) *buffer {
 	// It's worth about 3X. Fprintf is hard.
 	_, month, day := now.Date()
 	hour, minute, second := now.Clock()
+	// Lmmdd hh:mm:ss.uuuuuu threadid file:line]
 	buf.tmp[0] = severityChar[s]
 	buf.twoDigits(1, int(month))
 	buf.twoDigits(3, day)
@@ -562,7 +575,7 @@ func (l *loggingT) header(s severity) *buffer {
 	buf.tmp[11] = ':'
 	buf.twoDigits(12, second)
 	buf.tmp[14] = ' '
-	buf.nDigits(5, 15, pid) // TODO: should be TID
+	buf.nDigits(5, 15, pid, ' ') // TODO: should be TID
 	buf.tmp[20] = ' '
 	buf.Write(buf.tmp[:21])
 	buf.WriteString(file)
@@ -585,12 +598,18 @@ func (buf *buffer) twoDigits(i, d int) {
 	buf.tmp[i] = digits[d%10]
 }
 
-// nDigits formats a zero-prefixed n-digit integer at buf.tmp[i].
-func (buf *buffer) nDigits(n, i, d int) {
-	for j := n - 1; j >= 0; j-- {
+// nDigits formats an n-digit integer at buf.tmp[i],
+// padding with pad on the left.
+// It assumes d >= 0.
+func (buf *buffer) nDigits(n, i, d int, pad byte) {
+	j := n - 1
+	for ; j >= 0 && d > 0; j-- {
 		buf.tmp[i+j] = digits[d%10]
 		d /= 10
 	}
+	for ; j >= 0; j-- {
+		buf.tmp[i+j] = pad
+	}
 }
 
 // someDigits formats a zero-prefixed variable-width integer at buf.tmp[i].
@@ -610,35 +629,50 @@ func (buf *buffer) someDigits(i, d int) int {
 }
 
 func (l *loggingT) println(s severity, args ...interface{}) {
-	buf := l.header(s)
+	buf, file, line := l.header(s, 0)
 	fmt.Fprintln(buf, args...)
-	l.output(s, buf)
+	l.output(s, buf, file, line, false)
 }
 
 func (l *loggingT) print(s severity, args ...interface{}) {
-	buf := l.header(s)
+	l.printDepth(s, 1, args...)
+}
+
+func (l *loggingT) printDepth(s severity, depth int, args ...interface{}) {
+	buf, file, line := l.header(s, depth)
 	fmt.Fprint(buf, args...)
 	if buf.Bytes()[buf.Len()-1] != '\n' {
 		buf.WriteByte('\n')
 	}
-	l.output(s, buf)
+	l.output(s, buf, file, line, false)
 }
 
 func (l *loggingT) printf(s severity, format string, args ...interface{}) {
-	buf := l.header(s)
+	buf, file, line := l.header(s, 0)
 	fmt.Fprintf(buf, format, args...)
 	if buf.Bytes()[buf.Len()-1] != '\n' {
 		buf.WriteByte('\n')
 	}
-	l.output(s, buf)
+	l.output(s, buf, file, line, false)
+}
+
+// printWithFileLine behaves like print but uses the provided file and line number.  If
+// alsoLogToStderr is true, the log message always appears on standard error; it
+// will also appear in the log file unless --logtostderr is set.
+func (l *loggingT) printWithFileLine(s severity, file string, line int, alsoToStderr bool, args ...interface{}) {
+	buf := l.formatHeader(s, file, line)
+	fmt.Fprint(buf, args...)
+	if buf.Bytes()[buf.Len()-1] != '\n' {
+		buf.WriteByte('\n')
+	}
+	l.output(s, buf, file, line, alsoToStderr)
 }
 
 // output writes the data to the log files and releases the buffer.
-func (l *loggingT) output(s severity, buf *buffer) {
+func (l *loggingT) output(s severity, buf *buffer, file string, line int, alsoToStderr bool) {
 	l.mu.Lock()
 	if l.traceLocation.isSet() {
-		_, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call (same as header).
-		if ok && l.traceLocation.match(file, line) {
+		if l.traceLocation.match(file, line) {
 			buf.Write(stacks(false))
 		}
 	}
@@ -646,7 +680,7 @@ func (l *loggingT) output(s severity, buf *buffer) {
 	if l.toStderr {
 		os.Stderr.Write(data)
 	} else {
-		if l.alsoToStderr || s >= l.stderrThreshold.get() {
+		if alsoToStderr || l.alsoToStderr || s >= l.stderrThreshold.get() {
 			os.Stderr.Write(data)
 		}
 		if l.file[s] == nil {
@@ -670,7 +704,16 @@ func (l *loggingT) output(s severity, buf *buffer) {
 		}
 	}
 	if s == fatalLog {
-		// Make sure we see the trace for the current goroutine on standard error.
+		// If we got here via Exit rather than Fatal, print no stacks.
+		if atomic.LoadUint32(&fatalNoStacks) > 0 {
+			l.mu.Unlock()
+			timeoutFlush(10 * time.Second)
+			os.Exit(1)
+		}
+		// Dump all goroutine stacks before exiting.
+		// First, make sure we see the trace for the current goroutine on standard error.
+		// If -logtostderr has been specified, the loop below will do that anyway
+		// as the first stack in the full dump.
 		if !l.toStderr {
 			os.Stderr.Write(stacks(false))
 		}
@@ -862,6 +905,54 @@ func (l *loggingT) flushAll() {
 	}
 }
 
+// CopyStandardLogTo arranges for messages written to the Go "log" package's
+// default logs to also appear in the Google logs for the named and lower
+// severities.  Subsequent changes to the standard log's default output location
+// or format may break this behavior.
+//
+// Valid names are "INFO", "WARNING", "ERROR", and "FATAL".  If the name is not
+// recognized, CopyStandardLogTo panics.
+func CopyStandardLogTo(name string) {
+	sev, ok := severityByName(name)
+	if !ok {
+		panic(fmt.Sprintf("log.CopyStandardLogTo(%q): unrecognized severity name", name))
+	}
+	// Set a log format that captures the user's file and line:
+	//   d.go:23: message
+	stdLog.SetFlags(stdLog.Lshortfile)
+	stdLog.SetOutput(logBridge(sev))
+}
+
+// logBridge provides the Write method that enables CopyStandardLogTo to connect
+// Go's standard logs to the logs provided by this package.
+type logBridge severity
+
+// Write parses the standard logging line and passes its components to the
+// logger for severity(lb).
+func (lb logBridge) Write(b []byte) (n int, err error) {
+	var (
+		file = "???"
+		line = 1
+		text string
+	)
+	// Split "d.go:23: message" into "d.go", "23", and "message".
+	if parts := bytes.SplitN(b, []byte{':'}, 3); len(parts) != 3 || len(parts[0]) < 1 || len(parts[2]) < 1 {
+		text = fmt.Sprintf("bad log format: %s", b)
+	} else {
+		file = string(parts[0])
+		text = string(parts[2][1:]) // skip leading space
+		line, err = strconv.Atoi(string(parts[1]))
+		if err != nil {
+			text = fmt.Sprintf("bad line number: %s", b)
+			line = 1
+		}
+	}
+	// printWithFileLine with alsoToStderr=true, so standard log messages
+	// always appear on standard error.
+	logging.printWithFileLine(severity(lb), file, line, true, text)
+	return len(b), nil
+}
+
 // setV computes and remembers the V level for a given PC
 // when vmodule is enabled.
 // File pattern matching takes the basename of the file, stripped
@@ -965,6 +1056,12 @@ func Info(args ...interface{}) {
 	logging.print(infoLog, args...)
 }
 
+// InfoDepth acts as Info but uses depth to determine which call frame to log.
+// InfoDepth(0, "msg") is the same as Info("msg").
+func InfoDepth(depth int, args ...interface{}) {
+	logging.printDepth(infoLog, depth, args...)
+}
+
 // Infoln logs to the INFO log.
 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
 func Infoln(args ...interface{}) {
@@ -983,6 +1080,12 @@ func Warning(args ...interface{}) {
 	logging.print(warningLog, args...)
 }
 
+// WarningDepth acts as Warning but uses depth to determine which call frame to log.
+// WarningDepth(0, "msg") is the same as Warning("msg").
+func WarningDepth(depth int, args ...interface{}) {
+	logging.printDepth(warningLog, depth, args...)
+}
+
 // Warningln logs to the WARNING and INFO logs.
 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
 func Warningln(args ...interface{}) {
@@ -1001,6 +1104,12 @@ func Error(args ...interface{}) {
 	logging.print(errorLog, args...)
 }
 
+// ErrorDepth acts as Error but uses depth to determine which call frame to log.
+// ErrorDepth(0, "msg") is the same as Error("msg").
+func ErrorDepth(depth int, args ...interface{}) {
+	logging.printDepth(errorLog, depth, args...)
+}
+
 // Errorln logs to the ERROR, WARNING, and INFO logs.
 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
 func Errorln(args ...interface{}) {
@@ -1020,6 +1129,12 @@ func Fatal(args ...interface{}) {
 	logging.print(fatalLog, args...)
 }
 
+// FatalDepth acts as Fatal but uses depth to determine which call frame to log.
+// FatalDepth(0, "msg") is the same as Fatal("msg").
+func FatalDepth(depth int, args ...interface{}) {
+	logging.printDepth(fatalLog, depth, args...)
+}
+
 // Fatalln logs to the FATAL, ERROR, WARNING, and INFO logs,
 // including a stack trace of all running goroutines, then calls os.Exit(255).
 // Arguments are handled in the manner of fmt.Println; a newline is appended if missing.
@@ -1033,3 +1148,34 @@ func Fatalln(args ...interface{}) {
 func Fatalf(format string, args ...interface{}) {
 	logging.printf(fatalLog, format, args...)
 }
+
+// fatalNoStacks is non-zero if we are to exit without dumping goroutine stacks.
+// It allows Exit and relatives to use the Fatal logs.
+var fatalNoStacks uint32
+
+// Exit logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
+// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
+func Exit(args ...interface{}) {
+	atomic.StoreUint32(&fatalNoStacks, 1)
+	logging.print(fatalLog, args...)
+}
+
+// ExitDepth acts as Exit but uses depth to determine which call frame to log.
+// ExitDepth(0, "msg") is the same as Exit("msg").
+func ExitDepth(depth int, args ...interface{}) {
+	atomic.StoreUint32(&fatalNoStacks, 1)
+	logging.printDepth(fatalLog, depth, args...)
+}
+
+// Exitln logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
+func Exitln(args ...interface{}) {
+	atomic.StoreUint32(&fatalNoStacks, 1)
+	logging.println(fatalLog, args...)
+}
+
+// Exitf logs to the FATAL, ERROR, WARNING, and INFO logs, then calls os.Exit(1).
+// Arguments are handled in the manner of fmt.Printf; a newline is appended if missing.
+func Exitf(format string, args ...interface{}) {
+	atomic.StoreUint32(&fatalNoStacks, 1)
+	logging.printf(fatalLog, format, args...)
+}

go/glog/glog_file.go

@@ -115,7 +115,7 @@ func create(tag string, t time.Time) (f *os.File, filename string, err error) {
 		if err == nil {
 			symlink := filepath.Join(dir, link)
 			os.Remove(symlink)        // ignore err
-			os.Symlink(fname, symlink) // ignore err
+			os.Symlink(name, symlink) // ignore err
 			return f, fname, nil
 		}
 		lastErr = err

go/glog/glog_test.go

@@ -19,8 +19,10 @@ package glog
 import (
 	"bytes"
 	"fmt"
+	stdLog "log"
 	"path/filepath"
 	"runtime"
+	"strconv"
 	"strings"
 	"testing"
 	"time"
@@ -96,20 +98,99 @@ func TestInfo(t *testing.T) {
 	}
 }
 
+func TestInfoDepth(t *testing.T) {
+	setFlags()
+	defer logging.swap(logging.newBuffers())
+
+	f := func() { InfoDepth(1, "depth-test1") }
+
+	// The next three lines must stay together
+	_, _, wantLine, _ := runtime.Caller(0)
+	InfoDepth(0, "depth-test0")
+	f()
+
+	msgs := strings.Split(strings.TrimSuffix(contents(infoLog), "\n"), "\n")
+	if len(msgs) != 2 {
+		t.Fatalf("Got %d lines, expected 2", len(msgs))
+	}
+
+	for i, m := range msgs {
+		if !strings.HasPrefix(m, "I") {
+			t.Errorf("InfoDepth[%d] has wrong character: %q", i, m)
+		}
+		w := fmt.Sprintf("depth-test%d", i)
+		if !strings.Contains(m, w) {
+			t.Errorf("InfoDepth[%d] missing %q: %q", i, w, m)
+		}
+
+		// pull out the line number (between : and ])
+		msg := m[strings.LastIndex(m, ":")+1:]
+		x := strings.Index(msg, "]")
+		if x < 0 {
+			t.Errorf("InfoDepth[%d]: missing ']': %q", i, m)
+			continue
+		}
+		line, err := strconv.Atoi(msg[:x])
+		if err != nil {
+			t.Errorf("InfoDepth[%d]: bad line number: %q", i, m)
+			continue
+		}
+		wantLine++
+		if wantLine != line {
+			t.Errorf("InfoDepth[%d]: got line %d, want %d", i, line, wantLine)
+		}
+	}
+}
+
+func init() {
+	CopyStandardLogTo("INFO")
+}
+
+// Test that CopyStandardLogTo panics on bad input.
+func TestCopyStandardLogToPanic(t *testing.T) {
+	defer func() {
+		if s, ok := recover().(string); !ok || !strings.Contains(s, "LOG") {
+			t.Errorf(`CopyStandardLogTo("LOG") should have panicked: %v`, s)
+		}
+	}()
+	CopyStandardLogTo("LOG")
+}
+
+// Test that using the standard log package logs to INFO.
+func TestStandardLog(t *testing.T) {
+	setFlags()
+	defer logging.swap(logging.newBuffers())
+	stdLog.Print("test")
+	if !contains(infoLog, "I", t) {
+		t.Errorf("Info has wrong character: %q", contents(infoLog))
+	}
+	if !contains(infoLog, "test", t) {
+		t.Error("Info failed")
+	}
+}
+
 // Test that the header has the correct format.
 func TestHeader(t *testing.T) {
 	setFlags()
 	defer logging.swap(logging.newBuffers())
 	defer func(previous func() time.Time) { timeNow = previous }(timeNow)
 	timeNow = func() time.Time {
-		return time.Date(2006, 1, 2, 15, 4, 5, .678901e9, time.Local)
+		return time.Date(2006, 1, 2, 15, 4, 5, .067890e9, time.Local)
 	}
+	pid = 1234
 	Info("test")
-	var line, pid int
-	n, err := fmt.Sscanf(contents(infoLog), "I0102 15:04:05 %d glog_test.go:%d] test\n", &pid, &line)
-	if n != 2 || err != nil {
+	var line int
+	format := "I0102 15:04:05.067890    1234 glog_test.go:%d] test\n"
+	n, err := fmt.Sscanf(contents(infoLog), format, &line)
+	if n != 1 || err != nil {
 		t.Errorf("log format error: %d elements, error %s:\n%s", n, err, contents(infoLog))
 	}
+	// Scanf treats multiple spaces as equivalent to a single space,
+	// so check for correct space-padding also.
+	want := fmt.Sprintf(format, line)
+	if contents(infoLog) != want {
+		t.Errorf("log format error: got:\n\t%q\nwant:\t%q", contents(infoLog), want)
+	}
 }
 
 // Test that an Error log goes to Warning and Info.
@@ -328,6 +409,7 @@ func TestLogBacktraceAt(t *testing.T) {
 
 func BenchmarkHeader(b *testing.B) {
 	for i := 0; i < b.N; i++ {
-		logging.putBuffer(logging.header(infoLog))
+		buf, _, _ := logging.header(infoLog, 0)
+		logging.putBuffer(buf)
 	}
 }