Merge branch 'jv-logger-pid' into 'master'

Include process PID in log messages

Closes #1849

See merge request gitlab-org/gitaly!1422

11 files changed, 39 insertions, 30 deletions

diff --git a/changelogs/unreleased/jv-logger-pid.yml b/changelogs/unreleased/jv-logger-pid.yml
new file mode 100644
index 000000000..e835aaf0b
--- /dev/null
+++ b/changelogs/unreleased/jv-logger-pid.yml
@@ -0,0 +1,5 @@
+---
+title: Include process PID in log messages
+merge_request: 1422
+author:
+type: added
diff --git a/cmd/praefect/main.go b/cmd/praefect/main.go
index 8f40578ab..7119b864f 100644
--- a/cmd/praefect/main.go
+++ b/cmd/praefect/main.go
@@ -15,8 +15,8 @@ import (
 
 	"github.com/prometheus/client_golang/prometheus"
 	"github.com/prometheus/client_golang/prometheus/promhttp"
-	"github.com/sirupsen/logrus"
 
+	"gitlab.com/gitlab-org/gitaly/internal/log"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/config"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/protoregistry"
@@ -27,7 +27,7 @@ import (
 var (
 	flagConfig  = flag.String("config", "", "Location for the config.toml")
 	flagVersion = flag.Bool("version", false, "Print version and exit")
-	logger      = logrus.New()
+	logger      = log.Default()
 
 	errNoConfigFile = errors.New("the config flag must be passed")
 )
diff --git a/internal/log/log.go b/internal/log/log.go
index dec2579e1..e1d565d45 100644
--- a/internal/log/log.go
+++ b/internal/log/log.go
@@ -7,16 +7,12 @@ import (
 )
 
 var (
-	// Default is the default logrus logger
-	Default = logrus.StandardLogger()
-
-	// GrpcGo is a dedicated logrus logger for the grpc-go library. We use it
-	// to control the library's chattiness.
-	GrpcGo = logrus.New()
+	defaultLogger = logrus.StandardLogger()
+	grpcGo        = logrus.New()
 
 	// Loggers is convenient when you want to apply configuration to all
 	// loggers
-	Loggers = []*logrus.Logger{Default, GrpcGo}
+	Loggers = []*logrus.Logger{defaultLogger, grpcGo}
 )
 
 func init() {
@@ -48,7 +44,7 @@ func Configure(format string, level string) {
 	}
 
 	for _, l := range Loggers {
-		if l == GrpcGo {
+		if l == grpcGo {
 			l.SetLevel(mapGrpcLogLevel(logrusLevel))
 		} else {
 			l.SetLevel(logrusLevel)
@@ -65,3 +61,10 @@ func mapGrpcLogLevel(level logrus.Level) logrus.Level {
 
 	return level
 }
+
+// Default is the default logrus logger
+func Default() *logrus.Entry { return defaultLogger.WithField("pid", os.Getpid()) }
+
+// GrpcGo is a dedicated logrus logger for the grpc-go library. We use it
+// to control the library's chattiness.
+func GrpcGo() *logrus.Entry { return grpcGo.WithField("pid", os.Getpid()) }
diff --git a/internal/praefect/config/log.go b/internal/praefect/config/log.go
index 7d0bb314b..724d81f92 100644
--- a/internal/praefect/config/log.go
+++ b/internal/praefect/config/log.go
@@ -7,8 +7,8 @@ import (
 
 // ConfigureLogger applies the settings from the configuration file to the
 // logger, setting the log level and format.
-func (c Config) ConfigureLogger() *logrus.Logger {
+func (c Config) ConfigureLogger() *logrus.Entry {
 	log.Configure(c.Logging.Format, c.Logging.Level)
 
-	return log.Default
+	return log.Default()
 }
diff --git a/internal/praefect/coordinator.go b/internal/praefect/coordinator.go
index c6c1e762a..bee103b7c 100644
--- a/internal/praefect/coordinator.go
+++ b/internal/praefect/coordinator.go
@@ -28,7 +28,7 @@ import (
 // downstream server. The coordinator is thread safe; concurrent calls to
 // register nodes are safe.
 type Coordinator struct {
-	log           *logrus.Logger
+	log           *logrus.Entry
 	failoverMutex sync.RWMutex
 	connMutex     sync.RWMutex
 
@@ -39,7 +39,7 @@ type Coordinator struct {
 }
 
 // NewCoordinator returns a new Coordinator that utilizes the provided logger
-func NewCoordinator(l *logrus.Logger, datastore ReplicasDatastore, fileDescriptors ...*descriptor.FileDescriptorProto) *Coordinator {
+func NewCoordinator(l *logrus.Entry, datastore ReplicasDatastore, fileDescriptors ...*descriptor.FileDescriptorProto) *Coordinator {
 	registry := protoregistry.New()
 	registry.RegisterFiles(fileDescriptors...)
 
diff --git a/internal/praefect/replicator.go b/internal/praefect/replicator.go
index ebba87641..b865edfcb 100644
--- a/internal/praefect/replicator.go
+++ b/internal/praefect/replicator.go
@@ -19,7 +19,7 @@ type Replicator interface {
 }
 
 type defaultReplicator struct {
-	log *logrus.Logger
+	log *logrus.Entry
 }
 
 func (dr defaultReplicator) Replicate(ctx context.Context, job ReplJob, targetCC *grpc.ClientConn) error {
@@ -60,7 +60,7 @@ func (dr defaultReplicator) Replicate(ctx context.Context, job ReplJob, targetCC
 
 // ReplMgr is a replication manager for handling replication jobs
 type ReplMgr struct {
-	log         *logrus.Logger
+	log         *logrus.Entry
 	datastore   Datastore
 	coordinator *Coordinator
 	targetNode  string     // which replica is this replicator responsible for?
@@ -75,7 +75,7 @@ type ReplMgrOpt func(*ReplMgr)
 
 // NewReplMgr initializes a replication manager with the provided dependencies
 // and options
-func NewReplMgr(targetNode string, log *logrus.Logger, datastore Datastore, c *Coordinator, opts ...ReplMgrOpt) ReplMgr {
+func NewReplMgr(targetNode string, log *logrus.Entry, datastore Datastore, c *Coordinator, opts ...ReplMgrOpt) ReplMgr {
 	r := ReplMgr{
 		log:         log,
 		datastore:   datastore,
diff --git a/internal/praefect/replicator_test.go b/internal/praefect/replicator_test.go
index b669e6875..f035d925e 100644
--- a/internal/praefect/replicator_test.go
+++ b/internal/praefect/replicator_test.go
@@ -10,7 +10,6 @@ import (
 	"testing"
 	"time"
 
-	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
 	"google.golang.org/grpc"
@@ -18,6 +17,7 @@ import (
 	gitalyauth "gitlab.com/gitlab-org/gitaly/auth"
 	gitaly_config "gitlab.com/gitlab-org/gitaly/internal/config"
 	"gitlab.com/gitlab-org/gitaly/internal/helper"
+	gitalylog "gitlab.com/gitlab-org/gitaly/internal/log"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/config"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/models"
 	"gitlab.com/gitlab-org/gitaly/internal/rubyserver"
@@ -42,11 +42,12 @@ func TestReplicatorProcessJobsWhitelist(t *testing.T) {
 		Whitelist: []string{"abcd1234", "edfg5678"},
 	})
 
-	coordinator := NewCoordinator(logrus.New(), datastore)
+	logEntry := gitalylog.Default()
+	coordinator := NewCoordinator(logEntry, datastore)
 	resultsCh := make(chan result)
 	replman := NewReplMgr(
 		"default",
-		logrus.New(),
+		logEntry,
 		datastore,
 		coordinator,
 		WithReplicator(&mockReplicator{resultsCh}),
diff --git a/internal/praefect/server.go b/internal/praefect/server.go
index 766123584..3a7c0fabe 100644
--- a/internal/praefect/server.go
+++ b/internal/praefect/server.go
@@ -27,7 +27,7 @@ type Server struct {
 
 // NewServer returns an initialized praefect gPRC proxy server configured
 // with the provided gRPC server options
-func NewServer(c *Coordinator, repl ReplMgr, grpcOpts []grpc.ServerOption, l *logrus.Logger) *Server {
+func NewServer(c *Coordinator, repl ReplMgr, grpcOpts []grpc.ServerOption, l *logrus.Entry) *Server {
 	grpcOpts = append(grpcOpts, proxyRequiredOpts(c.streamDirector)...)
 	grpcOpts = append(grpcOpts, []grpc.ServerOption{
 		grpc.StreamInterceptor(grpc_middleware.ChainStreamServer(
diff --git a/internal/praefect/server_test.go b/internal/praefect/server_test.go
index 5f231071b..d04f61121 100644
--- a/internal/praefect/server_test.go
+++ b/internal/praefect/server_test.go
@@ -8,9 +8,9 @@ import (
 	"time"
 
 	"github.com/golang/protobuf/proto"
-	"github.com/sirupsen/logrus"
 	"github.com/stretchr/testify/require"
 	"gitlab.com/gitlab-org/gitaly/client"
+	"gitlab.com/gitlab-org/gitaly/internal/log"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/config"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/grpc-proxy/proxy"
 	"gitlab.com/gitlab-org/gitaly/internal/praefect/mock"
@@ -69,7 +69,8 @@ func TestServerSimpleUnaryUnary(t *testing.T) {
 					}},
 			})
 
-			coordinator := NewCoordinator(logrus.New(), datastore, fd)
+			logEntry := log.Default()
+			coordinator := NewCoordinator(logEntry, datastore, fd)
 
 			for id, nodeStorage := range datastore.storageNodes.m {
 				backend, cleanup := newMockDownstream(t, tt.callback)
@@ -82,7 +83,7 @@ func TestServerSimpleUnaryUnary(t *testing.T) {
 
 			replmgr := NewReplMgr(
 				storagePrimary,
-				logrus.New(),
+				logEntry,
 				datastore,
 				coordinator,
 			)
@@ -90,7 +91,7 @@ func TestServerSimpleUnaryUnary(t *testing.T) {
 				coordinator,
 				replmgr,
 				nil,
-				logrus.New(),
+				logEntry,
 			)
 
 			listener, port := listenAvailPort(t)
diff --git a/internal/server/server.go b/internal/server/server.go
index 7b3d340c5..8be44a7ae 100644
--- a/internal/server/server.go
+++ b/internal/server/server.go
@@ -60,10 +60,10 @@ func init() {
 	}
 
 	// logrusEntry is used by middlewares below
-	logrusEntry = log.NewEntry(gitalylog.Default)
+	logrusEntry = gitalylog.Default()
 
 	// grpc-go gets a custom logger; it is too chatty
-	grpc_logrus.ReplaceGrpcLogger(log.NewEntry(gitalylog.GrpcGo))
+	grpc_logrus.ReplaceGrpcLogger(gitalylog.GrpcGo())
 }
 
 // createNewServer returns a GRPC server with all Gitaly services and interceptors set up.
diff --git a/internal/testhelper/testhelper.go b/internal/testhelper/testhelper.go
index 664587ac7..adee54c2d 100644
--- a/internal/testhelper/testhelper.go
+++ b/internal/testhelper/testhelper.go
@@ -46,9 +46,6 @@ const (
 )
 
 func init() {
-	gitalylog.GrpcGo.SetLevel(log.WarnLevel)
-	grpc_logrus.ReplaceGrpcLogger(log.NewEntry(gitalylog.GrpcGo))
-
 	if err := configure(); err != nil {
 		log.Fatal(err)
 	}
@@ -70,6 +67,8 @@ func configure() error {
 		}
 	}
 
+	gitalylog.Configure("", "info")
+
 	return nil
 }