logger: add WithReportCaller and Clone

Signed-off-by: Adphi <philippe.adrien.nousse@gmail.com>

example/example.go

@@ -103,7 +103,7 @@ func run(opts ...service.Option) {
 	secure := true
 	ctx, cancel := context.WithCancel(context.Background())
 	defer cancel()
-	log := logger.New().WithFields("service", name)
+	log := logger.New().WithFields("service", name).WithReportCaller(true)
 	ctx = logger.Set(ctx, log)
 	done := make(chan struct{})
 	ready := make(chan struct{})

go.mod

@@ -4,7 +4,7 @@ go 1.20
 
 require (
 	github.com/alta/protopatch v0.5.1
-	github.com/bombsimon/logrusr/v2 v2.0.1
+	github.com/bombsimon/logrusr/v4 v4.0.0
 	github.com/caitlinelfring/go-env-default v1.1.0
 	github.com/envoyproxy/protoc-gen-validate v0.9.1
 	github.com/fsnotify/fsnotify v1.5.1
@@ -60,6 +60,7 @@ require (
 	github.com/inconshreveable/mousetrap v1.0.0 // indirect
 	github.com/jhump/protoreflect v1.11.0 // indirect
 	github.com/klauspost/compress v1.11.7 // indirect
+	github.com/kr/text v0.2.0 // indirect
 	github.com/lyft/protoc-gen-star v0.6.2 // indirect
 	github.com/matttproud/golang_protobuf_extensions v1.0.4 // indirect
 	github.com/pmezard/go-difflib v1.0.0 // indirect

go.sum

@@ -93,8 +93,8 @@ github.com/beorn7/perks v1.0.0/go.mod h1:KWe93zE9D1o94FZ5RNwFwVgaQK1VOXiVxmqh+Ce
 github.com/beorn7/perks v1.0.1 h1:VlbKKnNfV8bJzeqoa4cOKqO6bYr3WgKZxO8Z16+hsOM=
 github.com/beorn7/perks v1.0.1/go.mod h1:G2ZrVWU2WbWT9wwq4/hrbKbnv/1ERSJQ0ibhJ6rlkpw=
 github.com/bgentry/speakeasy v0.1.0/go.mod h1:+zsyZBPWlz7T6j88CTgSN5bM796AkVf0kBD4zp0CCIs=
-github.com/bombsimon/logrusr/v2 v2.0.1 h1:1VgxVNQMCvjirZIYaT9JYn6sAVGVEcNtRE0y4mvaOAM=
+github.com/bombsimon/logrusr/v4 v4.0.0 h1:Pm0InGphX0wMhPqC02t31onlq9OVyJ98eP/Vh63t1Oo=
-github.com/bombsimon/logrusr/v2 v2.0.1/go.mod h1:ByVAX+vHdLGAfdroiMg6q0zgq2FODY2lc5YJvzmOJio=
+github.com/bombsimon/logrusr/v4 v4.0.0/go.mod h1:pjfHC5e59CvjTBIU3V3sGhFWFAnsnhOR03TRc6im0l8=
 github.com/caitlinelfring/go-env-default v1.1.0 h1:bhDfXmUolvcIGfQCX8qevQX8wxC54NGz0aimoUnhvDM=
 github.com/caitlinelfring/go-env-default v1.1.0/go.mod h1:tESXPr8zFPP/cRy3cwxrHBmjJIf2A1x/o4C9CET2rEk=
 github.com/casbin/casbin/v2 v2.1.2/go.mod h1:YcPU1XXisHhLzuxH9coDNf2FbKpjGlbCg3n9yuLkIJQ=
@@ -206,7 +206,6 @@ github.com/go-kit/log v0.1.0/go.mod h1:zbhenjAZHb184qTLMA9ZjW7ThYL0H2mk7Q6pNt4vb
 github.com/go-logfmt/logfmt v0.3.0/go.mod h1:Qt1PoO58o5twSAckw1HlFXLmHsOX5/0LbT9GBnD5lWE=
 github.com/go-logfmt/logfmt v0.4.0/go.mod h1:3RMwSq7FuexP4Kalkev3ejPJsZTpXXBr9+V4qmtdjCk=
 github.com/go-logfmt/logfmt v0.5.0/go.mod h1:wCYkCAKZfumFQihp8CzCvQ3paCTfi41vtzG1KdI/P7A=
-github.com/go-logr/logr v1.0.0/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
 github.com/go-logr/logr v1.2.3 h1:2DntVwHkVopvECVRSlL5PSo9eG+cAkDCuckLubN+rq0=
 github.com/go-logr/logr v1.2.3/go.mod h1:jdQByPbusPIv2/zmleS9BjJVeZ6kBagPoEUsqbVz/1A=
 github.com/go-martini/martini v0.0.0-20170121215854-22fa46961aab/go.mod h1:/P9AEU963A2AYjv4d1V5eVL1CQbEJq6aCNHDDjibzu8=
@@ -439,7 +438,6 @@ github.com/kr/fs v0.1.0/go.mod h1:FFnZGqtBN9Gxj7eW1uZ42v5BccTP0vu6NEaFoC2HwRg=
 github.com/kr/logfmt v0.0.0-20140226030751-b84e30acd515/go.mod h1:+0opPa2QZZtGFBFZlji/RkVcI2GknAs/DXo4wKdlNEc=
 github.com/kr/pretty v0.1.0/go.mod h1:dAy3ld7l9f0ibDNOQOHHMYYIIbhfbHSm3C4ZsoJORNo=
 github.com/kr/pretty v0.2.0/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI=
-github.com/kr/pretty v0.2.1/go.mod h1:ipq/a2n7PKx3OHsz4KJII5eveXtPO4qwEXGdVfWzfnI=
 github.com/kr/pretty v0.3.1 h1:flRD4NNwYAUpkphVc1HcthR4KEIFJ65n8Mw5qdRn3LE=
 github.com/kr/pty v1.1.1/go.mod h1:pFQYn66WHrOpPYNljwOMqo10TkYh1fy3cYio2l3bCsQ=
 github.com/kr/text v0.1.0/go.mod h1:4Jbv+DJW3UT/LiOwJeYQe1efqtUx/iVham/4vfdArNI=
@@ -624,7 +622,6 @@ github.com/sirupsen/logrus v1.2.0/go.mod h1:LxeOpSwHxABJmUn/MG1IvRgCAasNZTLOkJPx
 github.com/sirupsen/logrus v1.4.2/go.mod h1:tLMulIdttU9McNUspp0xgXVQah82FyeX6MwdIuYE2rE=
 github.com/sirupsen/logrus v1.6.0/go.mod h1:7uNnSEd1DgxDLC74fIahvMZmmYsHGZGEOFrfsX/uA88=
 github.com/sirupsen/logrus v1.7.0/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
-github.com/sirupsen/logrus v1.8.1/go.mod h1:yWOB1SBYBC5VeMP7gHvWumXLIWorT60ONWic61uBYv0=
 github.com/sirupsen/logrus v1.9.0 h1:trlNQbNUG3OdDrDil03MCb1H2o9nJ1x4/5LYw7byDE0=
 github.com/sirupsen/logrus v1.9.0/go.mod h1:naHLuLoDiP4jHNo9R0sCBMtWGeIprob74mVsIT4qYEQ=
 github.com/smartystreets/assertions v0.0.0-20180927180507-b2de0cb4f26d/go.mod h1:OnSkiWE9lh6wB0YB77sQom3nweQdgAjqCqsofrRNTgc=
@@ -956,7 +953,6 @@ golang.org/x/sys v0.0.0-20210510120138-977fb7262007/go.mod h1:oPkhp1MJrh7nUepCBc
 golang.org/x/sys v0.0.0-20210514084401-e8d321eab015/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210603081109-ebe580a85c40/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210603125802-9665404d3644/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
-golang.org/x/sys v0.0.0-20210608053332-aa57babbf139/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210616094352-59db8d763f22/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
 golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
@@ -1231,7 +1227,6 @@ gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8
 gopkg.in/check.v1 v1.0.0-20180628173108-788fd7840127/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
 gopkg.in/check.v1 v1.0.0-20190902080502-41f04d3bba15/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
 gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c h1:Hei/4ADfdWqJk1ZMxUNpqntNwaWcugrBjAiHlqqRiVk=
-gopkg.in/check.v1 v1.0.0-20201130134442-10cb98267c6c/go.mod h1:JHkPIbrfpd72SG/EVd6muEfDQjcINNoR0C8j2r3qZ4Q=
 gopkg.in/cheggaaa/pb.v1 v1.0.25/go.mod h1:V/YB90LKu/1FcN3WVnfiiE5oMCibMjukxqG/qStrOgw=
 gopkg.in/errgo.v2 v2.1.0/go.mod h1:hNsd1EY+bozCKY1Ytp96fpM3vjJbqLJn88ws8XvfDNI=
 gopkg.in/fsnotify.v1 v1.4.7/go.mod h1:Tz8NjZHkW78fSQdbUxIjBTcgA1z1m8ZHf0WmKUhAMys=

logger/logger.go

@@ -4,8 +4,11 @@ import (
 	"context"
 	"fmt"
 	"io"
+	"path/filepath"
+	"runtime"
+	"strings"
 
-	"github.com/bombsimon/logrusr/v2"
+	"github.com/bombsimon/logrusr/v4"
 	"github.com/go-logr/logr"
 	"github.com/sirupsen/logrus"
 )
@@ -14,6 +17,27 @@ var (
 	standardLogger Logger = &logger{fl: logrus.StandardLogger()}
 )
 
+const (
+	// PanicLevel level, highest level of severity. Logs and then calls panic with the
+	// message passed to Debug, Info, ...
+	PanicLevel Level = iota
+	// FatalLevel level. Logs and then calls `logger.Exit(1)`. It will exit even if the
+	// logging level is set to Panic.
+	FatalLevel
+	// ErrorLevel level. Logs. Used for errors that should definitely be noted.
+	// Commonly used for hooks to send errors to an error tracking service.
+	ErrorLevel
+	// WarnLevel level. Non-critical entries that deserve eyes.
+	WarnLevel
+	// InfoLevel level. General operational entries about what's going on inside the
+	// application.
+	InfoLevel
+	// DebugLevel level. Usually only enabled when debugging. Very verbose logging.
+	DebugLevel
+	// TraceLevel level. Designates finer-grained informational events than the Debug.
+	TraceLevel
+)
+
 func StandardLogger() Logger {
 	return standardLogger
 }
@@ -26,15 +50,19 @@ func FromLogrus(fl logrus.Ext1FieldLogger) Logger {
 	return &logger{fl: fl}
 }
 
+type Level = logrus.Level
+
 type Logger interface {
 	WithContext(ctx context.Context) Logger
 
+	WithReportCaller(b bool) Logger
+
 	WithField(key string, value interface{}) Logger
 	WithFields(kv ...interface{}) Logger
 	WithError(err error) Logger
 
-	SetLevel(level logrus.Level) Logger
+	SetLevel(level Level) Logger
-	WriterLevel(level logrus.Level) *io.PipeWriter
+	WriterLevel(level Level) *io.PipeWriter
 
 	SetOutput(w io.Writer) Logger
 
@@ -75,121 +103,122 @@ type Logger interface {
 
 type logger struct {
 	fl           logrus.Ext1FieldLogger
+	reportCaller bool
 }
 
 func (l *logger) Tracef(format string, args ...interface{}) {
-	l.fl.Tracef(format, args...)
+	l.withCaller().Tracef(format, args...)
 }
 
 func (l *logger) Debugf(format string, args ...interface{}) {
-	l.fl.Debugf(format, args...)
+	l.withCaller().Debugf(format, args...)
 }
 
 func (l *logger) Infof(format string, args ...interface{}) {
-	l.fl.Infof(format, args...)
+	l.withCaller().Infof(format, args...)
 }
 
 func (l *logger) Printf(format string, args ...interface{}) {
-	l.fl.Printf(format, args...)
+	l.withCaller().Printf(format, args...)
 }
 
 func (l *logger) Warnf(format string, args ...interface{}) {
-	l.fl.Warnf(format, args...)
+	l.withCaller().Warnf(format, args...)
 }
 
 func (l *logger) Warningf(format string, args ...interface{}) {
-	l.fl.Warningf(format, args...)
+	l.withCaller().Warningf(format, args...)
 }
 
 func (l *logger) Errorf(format string, args ...interface{}) {
-	l.fl.Errorf(format, args...)
+	l.withCaller().Errorf(format, args...)
 }
 
 func (l *logger) Fatalf(format string, args ...interface{}) {
-	l.fl.Fatalf(format, args...)
+	l.withCaller().Fatalf(format, args...)
 }
 
 func (l *logger) Panicf(format string, args ...interface{}) {
-	l.fl.Panicf(format, args...)
+	l.withCaller().Panicf(format, args...)
 }
 
 func (l *logger) Trace(args ...interface{}) {
-	l.fl.Trace(args...)
+	l.withCaller().Trace(args...)
 }
 
 func (l *logger) Debug(args ...interface{}) {
-	l.fl.Debug(args...)
+	l.withCaller().Debug(args...)
 }
 
 func (l *logger) Info(args ...interface{}) {
-	l.fl.Info(args...)
+	l.withCaller().Info(args...)
 }
 
 func (l *logger) Print(args ...interface{}) {
-	l.fl.Print(args...)
+	l.withCaller().Print(args...)
 }
 
 func (l *logger) Warn(args ...interface{}) {
-	l.fl.Warn(args...)
+	l.withCaller().Warn(args...)
 }
 
 func (l *logger) Warning(args ...interface{}) {
-	l.fl.Warning(args...)
+	l.withCaller().Warning(args...)
 }
 
 func (l *logger) Error(args ...interface{}) {
-	l.fl.Error(args...)
+	l.withCaller().Error(args...)
 }
 
 func (l *logger) Fatal(args ...interface{}) {
-	l.fl.Fatal(args...)
+	l.withCaller().Fatal(args...)
 }
 
 func (l *logger) Panic(args ...interface{}) {
-	l.fl.Panic(args...)
+	l.withCaller().Panic(args...)
 }
 
 func (l *logger) Traceln(args ...interface{}) {
-	l.fl.Traceln(args...)
+	l.withCaller().Traceln(args...)
 }
 
 func (l *logger) Debugln(args ...interface{}) {
-	l.fl.Debugln(args...)
+	l.withCaller().Debugln(args...)
 }
 
 func (l *logger) Infoln(args ...interface{}) {
-	l.fl.Infoln(args...)
+	l.withCaller().Infoln(args...)
 }
 
 func (l *logger) Println(args ...interface{}) {
-	l.fl.Println(args...)
+	l.withCaller().Println(args...)
 }
 
 func (l *logger) Warnln(args ...interface{}) {
-	l.fl.Warnln(args...)
+	l.withCaller().Warnln(args...)
 }
 
 func (l *logger) Warningln(args ...interface{}) {
-	l.fl.Warningln(args...)
+	l.withCaller().Warningln(args...)
 }
 
 func (l *logger) Errorln(args ...interface{}) {
-	l.fl.Errorln(args...)
+	l.withCaller().Errorln(args...)
 }
 
 func (l *logger) Fatalln(args ...interface{}) {
-	l.fl.Fatalln(args...)
+	l.withCaller().Fatalln(args...)
 }
 
 func (l *logger) Panicln(args ...interface{}) {
-	l.fl.Panicln(args...)
+	l.withCaller().Panicln(args...)
 }
 
-func (l *logger) WriterLevel(level logrus.Level) *io.PipeWriter {
+func (l *logger) WriterLevel(level Level) *io.PipeWriter {
 	return l.Logger().WriterLevel(level)
 }
 
-func (l *logger) SetLevel(level logrus.Level) Logger {
+func (l *logger) SetLevel(level Level) Logger {
 	l.Logger().SetLevel(level)
 	return l
 }
@@ -197,27 +226,31 @@ func (l *logger) SetLevel(level logrus.Level) Logger {
 func (l *logger) WithContext(ctx context.Context) Logger {
 	switch t := l.fl.(type) {
 	case *logrus.Logger:
-		return &logger{fl: t.WithContext(ctx)}
+		return &logger{fl: t.WithContext(ctx), reportCaller: l.reportCaller}
 	case *logrus.Entry:
-		return &logger{fl: t.WithContext(ctx)}
+		return &logger{fl: t.WithContext(ctx), reportCaller: l.reportCaller}
 	}
 	panic(fmt.Sprintf("unexpected logger type %T", l.fl))
 }
 
 func (l *logger) WithField(key string, value interface{}) Logger {
-	return &logger{fl: l.fl.WithField(key, value)}
+	return &logger{fl: l.fl.WithField(key, value), reportCaller: l.reportCaller}
 }
 
 func (l *logger) WithFields(kv ...interface{}) Logger {
 	log := &logger{fl: l.fl}
 	for i := 0; i < len(kv); i += 2 {
-		log = &logger{fl: log.fl.WithField(fmt.Sprintf("%v", kv[i]), kv[i+1])}
+		log = &logger{fl: log.fl.WithField(fmt.Sprintf("%v", kv[i]), kv[i+1]), reportCaller: l.reportCaller}
 	}
 	return log
 }
 
 func (l *logger) WithError(err error) Logger {
-	return &logger{fl: l.fl.WithError(err)}
+	return &logger{fl: l.fl.WithError(err), reportCaller: l.reportCaller}
+}
+
+func (l *logger) WithReportCaller(b bool) Logger {
+	return &logger{fl: l.fl, reportCaller: b}
 }
 
 func (l *logger) Logr() logr.Logger {
@@ -242,3 +275,51 @@ func (l *logger) SetOutput(w io.Writer) Logger {
 	l.Logger().SetOutput(w)
 	return l
 }
+
+func (l *logger) Clone() Logger {
+	n := logrus.New()
+	switch t := l.fl.(type) {
+	case *logrus.Logger:
+		n.Level = t.Level
+		n.Out = t.Out
+		n.Formatter = t.Formatter
+		n.Hooks = t.Hooks
+		return &logger{fl: n, reportCaller: l.reportCaller}
+	case *logrus.Entry:
+		t = t.Dup()
+		n.Level = t.Logger.Level
+		n.Out = t.Logger.Out
+		n.Formatter = t.Logger.Formatter
+		n.Hooks = t.Logger.Hooks
+		t.Logger = n
+		return &logger{fl: t, reportCaller: l.reportCaller}
+	}
+	panic(fmt.Sprintf("unexpected logger type %T", l.fl))
+}
+
+func (l *logger) withCaller() logrus.Ext1FieldLogger {
+	if !l.reportCaller {
+		return l.fl
+	}
+	pcs := make([]uintptr, 1)
+	runtime.Callers(3, pcs)
+	f, _ := runtime.CallersFrames(pcs).Next()
+	pkg := getPackageName(f.Function)
+	return l.fl.WithField("caller", fmt.Sprintf("%s/%s:%d", pkg, filepath.Base(f.File), f.Line)).WithField("func", f.Func.Name())
+}
+
+// getPackageName reduces a fully qualified function name to the package name
+// There really ought to be a better way...
+func getPackageName(f string) string {
+	for {
+		lastPeriod := strings.LastIndex(f, ".")
+		lastSlash := strings.LastIndex(f, "/")
+		if lastPeriod > lastSlash {
+			f = f[:lastPeriod]
+		} else {
+			break
+		}
+	}
+
+	return f
+}

service/service.go

@@ -319,9 +319,6 @@ func (s *service) stop() error {
 		s.server.Stop()
 	case <-done:
 	}
-	if err := s.opts.lis.Close(); err != nil {
-		log.Errorf("failed to close listener: %v", err)
-	}
 	s.running = false
 	s.cancel()
 	for i := range s.opts.afterStop {