glog: add context variants to most log functions
We export this new API to make the internal and external versions
identical.
The context is currently plumbed through to the internal/logsink
package, but effectively discarded there.
cl/560684897 (google-internal)
cl/579771826 (google-internal)
diff --git a/glog.go b/glog.go
index dd0ed10..8c00e73 100644
--- a/glog.go
+++ b/glog.go
@@ -15,8 +15,26 @@
// limitations under the License.
// Package glog implements logging analogous to the Google-internal C++ INFO/ERROR/V setup.
-// It provides functions Info, Warning, Error, Fatal, plus formatting variants such as
-// Infof. It also provides V-style logging controlled by the -v and -vmodule=file=2 flags.
+// It provides functions that have a name matched by regex:
+//
+// (Info|Warning|Error|Fatal)(Context)?(Depth)?(f)?
+//
+// If Context is present, function takes context.Context argument. The
+// context is used to pass through the Trace Context to log sinks that can make use
+// of it.
+// It is recommended to use the context variant of the functions over the non-context
+// variants if a context is available to make sure the Trace Contexts are present
+// in logs.
+//
+// If Depth is present, this function calls log from a different depth in the call stack.
+// This enables a callee to emit logs that use the callsite information of its caller
+// or any other callers in the stack. When depth == 0, the original callee's line
+// information is emitted. When depth > 0, depth frames are skipped in the call stack
+// and the final frame is treated like the original callee to Info.
+//
+// If 'f' is present, function formats according to a format specifier.
+//
+// This package also provides V-style logging controlled by the -v and -vmodule=file=2 flags.
//
// Basic examples:
//
@@ -82,6 +100,7 @@
import (
"bytes"
+ "context"
"errors"
"fmt"
stdLog "log"
@@ -182,9 +201,14 @@
return format, args
}
-// logf writes a log message for a log function call (or log function wrapper)
-// at the given depth in the current goroutine's stack.
+// logf acts as ctxlogf, but doesn't expect a context.
func logf(depth int, severity logsink.Severity, verbose bool, stack stack, format string, args ...any) {
+ ctxlogf(nil, depth+1, severity, verbose, stack, format, args...)
+}
+
+// ctxlogf writes a log message for a log function call (or log function wrapper)
+// at the given depth in the current goroutine's stack.
+func ctxlogf(ctx context.Context, depth int, severity logsink.Severity, verbose bool, stack stack, format string, args ...any) {
now := timeNow()
_, file, line, ok := runtime.Caller(depth + 1)
if !ok {
@@ -198,6 +222,7 @@
metai, meta := metaPoolGet()
*meta = logsink.Meta{
+ Context: ctx,
Time: now,
File: file,
Line: line,
@@ -207,6 +232,9 @@
Thread: int64(pid),
}
sinkf(meta, format, args...)
+ // Clear pointer fields so they can be garbage collected early.
+ meta.Context = nil
+ meta.Stack = nil
metaPool.Put(metai)
}
@@ -418,6 +446,36 @@
}
}
+// InfoContext is equivalent to the global InfoContext function, guarded by the value of v.
+// See the documentation of V for usage.
+func (v Verbose) InfoContext(ctx context.Context, args ...any) {
+ v.InfoContextDepth(ctx, 1, args...)
+}
+
+// InfoContextf is equivalent to the global InfoContextf function, guarded by the value of v.
+// See the documentation of V for usage.
+func (v Verbose) InfoContextf(ctx context.Context, format string, args ...any) {
+ if v {
+ ctxlogf(ctx, 1, logsink.Info, true, noStack, format, args...)
+ }
+}
+
+// InfoContextDepth is equivalent to the global InfoContextDepth function, guarded by the value of v.
+// See the documentation of V for usage.
+func (v Verbose) InfoContextDepth(ctx context.Context, depth int, args ...any) {
+ if v {
+ ctxlogf(ctx, depth+1, logsink.Info, true, noStack, defaultFormat(args), args...)
+ }
+}
+
+// InfoContextDepthf is equivalent to the global InfoContextDepthf function, guarded by the value of v.
+// See the documentation of V for usage.
+func (v Verbose) InfoContextDepthf(ctx context.Context, depth int, format string, args ...any) {
+ if v {
+ ctxlogf(ctx, depth+1, logsink.Info, true, noStack, format, args...)
+ }
+}
+
// Info logs to the INFO log.
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
func Info(args ...any) {
@@ -450,6 +508,30 @@
logf(1, logsink.Info, false, noStack, format, args...)
}
+// InfoContext is like [Info], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func InfoContext(ctx context.Context, args ...any) {
+ InfoContextDepth(ctx, 1, args...)
+}
+
+// InfoContextf is like [Infof], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func InfoContextf(ctx context.Context, format string, args ...any) {
+ ctxlogf(ctx, 1, logsink.Info, false, noStack, format, args...)
+}
+
+// InfoContextDepth is like [InfoDepth], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func InfoContextDepth(ctx context.Context, depth int, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Info, false, noStack, defaultFormat(args), args...)
+}
+
+// InfoContextDepthf is like [InfoDepthf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func InfoContextDepthf(ctx context.Context, depth int, format string, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Info, false, noStack, format, args...)
+}
+
// Warning logs to the WARNING and INFO logs.
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
func Warning(args ...any) {
@@ -480,6 +562,30 @@
logf(1, logsink.Warning, false, noStack, format, args...)
}
+// WarningContext is like [Warning], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func WarningContext(ctx context.Context, args ...any) {
+ WarningContextDepth(ctx, 1, args...)
+}
+
+// WarningContextf is like [Warningf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func WarningContextf(ctx context.Context, format string, args ...any) {
+ ctxlogf(ctx, 1, logsink.Warning, false, noStack, format, args...)
+}
+
+// WarningContextDepth is like [WarningDepth], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func WarningContextDepth(ctx context.Context, depth int, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Warning, false, noStack, defaultFormat(args), args...)
+}
+
+// WarningContextDepthf is like [WarningDepthf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func WarningContextDepthf(ctx context.Context, depth int, format string, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Warning, false, noStack, format, args...)
+}
+
// Error logs to the ERROR, WARNING, and INFO logs.
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
func Error(args ...any) {
@@ -510,8 +616,32 @@
logf(1, logsink.Error, false, noStack, format, args...)
}
-func fatalf(depth int, format string, args ...any) {
- logf(depth+1, logsink.Fatal, false, withStack, format, args...)
+// ErrorContext is like [Error], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ErrorContext(ctx context.Context, args ...any) {
+ ErrorContextDepth(ctx, 1, args...)
+}
+
+// ErrorContextf is like [Errorf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ErrorContextf(ctx context.Context, format string, args ...any) {
+ ctxlogf(ctx, 1, logsink.Error, false, noStack, format, args...)
+}
+
+// ErrorContextDepth is like [ErrorDepth], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ErrorContextDepth(ctx context.Context, depth int, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Error, false, noStack, defaultFormat(args), args...)
+}
+
+// ErrorContextDepthf is like [ErrorDepthf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ErrorContextDepthf(ctx context.Context, depth int, format string, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Error, false, noStack, format, args...)
+}
+
+func ctxfatalf(ctx context.Context, depth int, format string, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Fatal, false, withStack, format, args...)
sinks.file.Flush()
err := abortProcess() // Should not return.
@@ -523,6 +653,10 @@
os.Exit(2) // Exit with the same code as the default SIGABRT handler.
}
+func fatalf(depth int, format string, args ...any) {
+ ctxfatalf(nil, depth+1, format, args...)
+}
+
// Fatal logs to the FATAL, ERROR, WARNING, and INFO logs,
// including a stack trace of all running goroutines, then calls os.Exit(2).
// Arguments are handled in the manner of fmt.Print; a newline is appended if missing.
@@ -556,12 +690,39 @@
fatalf(1, format, args...)
}
-func exitf(depth int, format string, args ...any) {
- logf(depth+1, logsink.Fatal, false, noStack, format, args...)
+// FatalContext is like [Fatal], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func FatalContext(ctx context.Context, args ...any) {
+ FatalContextDepth(ctx, 1, args...)
+}
+
+// FatalContextf is like [Fatalf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func FatalContextf(ctx context.Context, format string, args ...any) {
+ ctxfatalf(ctx, 1, format, args...)
+}
+
+// FatalContextDepth is like [FatalDepth], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func FatalContextDepth(ctx context.Context, depth int, args ...any) {
+ ctxfatalf(ctx, depth+1, defaultFormat(args), args...)
+}
+
+// FatalContextDepthf is like [FatalDepthf], but with an extra [context.Context] parameter.
+func FatalContextDepthf(ctx context.Context, depth int, format string, args ...any) {
+ ctxfatalf(ctx, depth+1, format, args...)
+}
+
+func ctxexitf(ctx context.Context, depth int, format string, args ...any) {
+ ctxlogf(ctx, depth+1, logsink.Fatal, false, noStack, format, args...)
sinks.file.Flush()
os.Exit(1)
}
+func exitf(depth int, format string, args ...any) {
+ ctxexitf(nil, depth+1, format, args...)
+}
+
// 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 ...any) {
@@ -590,3 +751,27 @@
func Exitf(format string, args ...any) {
exitf(1, format, args...)
}
+
+// ExitContext is like [Exit], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ExitContext(ctx context.Context, args ...any) {
+ ExitContextDepth(ctx, 1, args...)
+}
+
+// ExitContextf is like [Exitf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ExitContextf(ctx context.Context, format string, args ...any) {
+ ctxexitf(ctx, 1, format, args...)
+}
+
+// ExitContextDepth is like [ExitDepth], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ExitContextDepth(ctx context.Context, depth int, args ...any) {
+ ctxexitf(ctx, depth+1, defaultFormat(args), args...)
+}
+
+// ExitContextDepthf is like [ExitDepthf], but with an extra [context.Context] parameter. The
+// context is used to pass the Trace Context to log sinks.
+func ExitContextDepthf(ctx context.Context, depth int, format string, args ...any) {
+ ctxexitf(ctx, depth+1, format, args...)
+}
diff --git a/glog_context_test.go b/glog_context_test.go
new file mode 100644
index 0000000..9dbac83
--- /dev/null
+++ b/glog_context_test.go
@@ -0,0 +1,62 @@
+package glog
+
+import (
+ "context"
+ "flag"
+ "testing"
+
+ "github.com/golang/glog/internal/logsink"
+)
+
+type contextKey string
+type fakeLogSink struct {
+ context context.Context
+}
+
+var ctxKey = contextKey("key")
+var ctxValue = "some-value"
+var originalSinks = logsink.StructuredSinks
+
+func (s *fakeLogSink) Printf(meta *logsink.Meta, format string, args ...any) (int, error) {
+ s.context = meta.Context
+ return 0, nil
+}
+
+// Test that log.(Info|Error|Warning)Context functions behave the same as non context variants
+// and pass right context.
+func TestLogContext(t *testing.T) {
+ fakeLogSink := &fakeLogSink{}
+ logsink.StructuredSinks = append([]logsink.Structured{fakeLogSink}, originalSinks...)
+
+ funcs := map[string]func(ctx context.Context, args ...any){
+ "InfoContext": InfoContext,
+ "InfoContextDepth": func(ctx context.Context, args ...any) { InfoContextDepth(ctx, 2, args) },
+ "ErrorContext": ErrorContext,
+ "WarningContext": WarningContext,
+ }
+
+ ctx := context.WithValue(context.Background(), ctxKey, ctxValue)
+ for name, f := range funcs {
+ f(ctx, "test")
+ want := ctxValue
+ if got := fakeLogSink.context.Value(ctxKey); got != want {
+ t.Errorf("%s: context value unexpectedly missing: got %q, want %q", name, got, want)
+ }
+ }
+}
+
+// Test that V.InfoContext behaves the same as V.Info and passes right context.
+func TestVInfoContext(t *testing.T) {
+ fakeLogSink := &fakeLogSink{}
+ logsink.StructuredSinks = append([]logsink.Structured{fakeLogSink}, originalSinks...)
+ if err := flag.Lookup("v").Value.Set("2"); err != nil {
+ t.Fatalf("Failed to set -v=2: %v", err)
+ }
+ defer flag.Lookup("v").Value.Set("0")
+ ctx := context.WithValue(context.Background(), ctxKey, ctxValue)
+ V(2).InfoContext(ctx, "test")
+ want := ctxValue
+ if got := fakeLogSink.context.Value(ctxKey); got != want {
+ t.Errorf("V.InfoContext: context value unexpectedly missing: got %q, want %q", got, want)
+ }
+}
diff --git a/glog_test.go b/glog_test.go
index 81c43ce..54762c5 100644
--- a/glog_test.go
+++ b/glog_test.go
@@ -2,6 +2,7 @@
import (
"bytes"
+ "context"
"flag"
"fmt"
"io/ioutil"
@@ -36,6 +37,7 @@
}
func (f *flushBuffer) Flush() error {
+ f.Buffer.Reset()
return nil
}
@@ -63,6 +65,16 @@
return s.swap(severityWriters{new(flushBuffer), new(flushBuffer), new(flushBuffer), new(flushBuffer)})
}
+func (s *fileSink) resetBuffers() {
+ s.mu.Lock()
+ defer s.mu.Unlock()
+ for _, buf := range s.file {
+ if buf != nil {
+ buf.Flush()
+ }
+ }
+}
+
// contents returns the specified log value as a string.
func contents(s logsink.Severity) string {
return sinks.file.file[s].(*flushBuffer).String()
@@ -82,12 +94,20 @@
func TestInfo(t *testing.T) {
setFlags()
defer sinks.file.swap(sinks.file.newBuffers())
- Info("test")
- if !contains(logsink.Info, "I", t) {
- t.Errorf("Info has wrong character: %q", contents(logsink.Info))
+ funcs := []func(args ...any){
+ Info,
+ func(args ...any) { InfoContext(context.Background(), args) },
}
- if !contains(logsink.Info, "test", t) {
- t.Error("Info failed")
+
+ for _, f := range funcs {
+ sinks.file.resetBuffers()
+ f("test")
+ if !contains(logsink.Info, "I", t) {
+ t.Errorf("Info has wrong character: %q", contents(logsink.Info))
+ }
+ if !contains(logsink.Info, "test", t) {
+ t.Error("Info failed")
+ }
}
}
@@ -95,42 +115,50 @@
setFlags()
defer sinks.file.swap(sinks.file.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(logsink.Info), "\n"), "\n")
- if len(msgs) != 2 {
- t.Fatalf("Got %d lines, expected 2", len(msgs))
+ funcs := []func(d int, args ...any){
+ InfoDepth,
+ func(d int, args ...any) { InfoContextDepth(context.Background(), d+1, args) },
}
- 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)
+ for _, infoDepth := range funcs {
+ sinks.file.resetBuffers()
+ 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(logsink.Info), "\n"), "\n")
+ if len(msgs) != 2 {
+ t.Fatalf("Got %d lines, expected 2", len(msgs))
}
- // 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)
+ 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)
+ }
}
}
}
@@ -204,19 +232,28 @@
func TestError(t *testing.T) {
setFlags()
defer sinks.file.swap(sinks.file.newBuffers())
- Error("test")
- if !contains(logsink.Error, "E", t) {
- t.Errorf("Error has wrong character: %q", contents(logsink.Error))
+
+ funcs := []func(args ...any){
+ Error,
+ func(args ...any) { ErrorContext(context.Background(), args) },
}
- if !contains(logsink.Error, "test", t) {
- t.Error("Error failed")
- }
- str := contents(logsink.Error)
- if !contains(logsink.Warning, str, t) {
- t.Error("Warning failed")
- }
- if !contains(logsink.Info, str, t) {
- t.Error("Info failed")
+
+ for _, error := range funcs {
+ sinks.file.resetBuffers()
+ error("test")
+ if !contains(logsink.Error, "E", t) {
+ t.Errorf("Error has wrong character: %q", contents(logsink.Error))
+ }
+ if !contains(logsink.Error, "test", t) {
+ t.Error("Error failed")
+ }
+ str := contents(logsink.Error)
+ if !contains(logsink.Warning, str, t) {
+ t.Error("Warning failed")
+ }
+ if !contains(logsink.Info, str, t) {
+ t.Error("Info failed")
+ }
}
}
@@ -226,16 +263,25 @@
func TestWarning(t *testing.T) {
setFlags()
defer sinks.file.swap(sinks.file.newBuffers())
- Warning("test")
- if !contains(logsink.Warning, "W", t) {
- t.Errorf("Warning has wrong character: %q", contents(logsink.Warning))
+
+ funcs := []func(args ...any){
+ Warning,
+ func(args ...any) { WarningContext(context.Background(), args) },
}
- if !contains(logsink.Warning, "test", t) {
- t.Error("Warning failed")
- }
- str := contents(logsink.Warning)
- if !contains(logsink.Info, str, t) {
- t.Error("Info failed")
+
+ for _, warning := range funcs {
+ sinks.file.resetBuffers()
+ warning("test")
+ if !contains(logsink.Warning, "W", t) {
+ t.Errorf("Warning has wrong character: %q", contents(logsink.Warning))
+ }
+ if !contains(logsink.Warning, "test", t) {
+ t.Error("Warning failed")
+ }
+ str := contents(logsink.Warning)
+ if !contains(logsink.Info, str, t) {
+ t.Error("Info failed")
+ }
}
}
@@ -248,12 +294,19 @@
}
defer flag.Lookup("v").Value.Set("0")
- V(2).Info("test")
- if !contains(logsink.Info, "I", t) {
- t.Errorf("Info has wrong character: %q", contents(logsink.Info))
+ funcs := []func(args ...any){
+ V(2).Info,
+ func(args ...any) { V(2).InfoContext(context.Background(), args) },
}
- if !contains(logsink.Info, "test", t) {
- t.Error("Info failed")
+ for _, info := range funcs {
+ sinks.file.resetBuffers()
+ info("test")
+ if !contains(logsink.Info, "I", t) {
+ t.Errorf("Info has wrong character: %q", contents(logsink.Info))
+ }
+ if !contains(logsink.Info, "test", t) {
+ t.Error("Info failed")
+ }
}
}
diff --git a/internal/logsink/logsink.go b/internal/logsink/logsink.go
index 53758e1..28c38a6 100644
--- a/internal/logsink/logsink.go
+++ b/internal/logsink/logsink.go
@@ -16,6 +16,7 @@
import (
"bytes"
+ "context"
"fmt"
"strconv"
"strings"
@@ -77,6 +78,11 @@
// Meta is metadata about a logging call.
type Meta struct {
+ // The context with which the log call was made (or nil). If set, the context
+ // is only valid during the logsink.Structured.Printf call, it should not be
+ // retained.
+ Context context.Context
+
// Time is the time at which the log call was made.
Time time.Time
