Skip to content

Commit

Permalink
Redirect messages written to the standard "log" package to the INFO log,
Browse files Browse the repository at this point in the history
in particular to capture messages from the "net/http" package.

This change only affects programs that import "github.com/golang/glog".

Messages written to the standard "log" package will always appear on standard error,
as they do now, though they will be formatted like INFO log messages. These messages
will also appear in the INFO log file unless --logtostderr is set.
  • Loading branch information
dsymonds committed Nov 5, 2014
1 parent d1c4472 commit 49850ea
Show file tree
Hide file tree
Showing 2 changed files with 113 additions and 16 deletions.
98 changes: 83 additions & 15 deletions glog.go
Original file line number Diff line number Diff line change
Expand Up @@ -77,6 +77,7 @@ import (
"flag"
"fmt"
"io"
stdLog "log"
"os"
"path/filepath"
"runtime"
Expand All @@ -93,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
Expand Down Expand Up @@ -311,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.
Expand Down Expand Up @@ -513,7 +517,7 @@ 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.
Log lines have this form:
Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
Expand All @@ -527,9 +531,7 @@ 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()
func (l *loggingT) header(s severity) (*buffer, string, int) {
_, file, line, ok := runtime.Caller(3) // It's always the same number of frames to the user's call.
if !ok {
file = "???"
Expand All @@ -540,6 +542,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
}
Expand All @@ -552,6 +560,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)
Expand Down Expand Up @@ -612,43 +621,54 @@ 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)
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)
buf, file, line := l.header(s)
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)
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))
}
}
data := buf.Bytes()
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 {
Expand Down Expand Up @@ -861,6 +881,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
Expand Down
31 changes: 30 additions & 1 deletion glog_test.go
Original file line number Diff line number Diff line change
Expand Up @@ -19,6 +19,7 @@ package glog
import (
"bytes"
"fmt"
stdLog "log"
"path/filepath"
"runtime"
"strings"
Expand Down Expand Up @@ -96,6 +97,33 @@ func TestInfo(t *testing.T) {
}
}

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()
Expand Down Expand Up @@ -328,6 +356,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)
logging.putBuffer(buf)
}
}

0 comments on commit 49850ea

Please sign in to comment.