Fix to prevent data races

internal/manager/manager.go

@@ -27,6 +27,9 @@ import (
 	"sync"
 	"time"
 
+	"github.com/networkservicemesh/sdk/pkg/tools/log/logruslogger"
+	"github.com/networkservicemesh/sdk/pkg/tools/log/spanlogger"
+
 	"github.com/edwarnicke/grpcfd"
 	"github.com/sirupsen/logrus"
 	"github.com/spiffe/go-spiffe/v2/spiffetls/tlsconfig"
@@ -39,8 +42,6 @@ import (
 	"github.com/networkservicemesh/sdk/pkg/networkservice/common/authorize"
 	"github.com/networkservicemesh/sdk/pkg/tools/grpcutils"
 	"github.com/networkservicemesh/sdk/pkg/tools/log"
-	"github.com/networkservicemesh/sdk/pkg/tools/log/logruslogger"
-	"github.com/networkservicemesh/sdk/pkg/tools/log/spanlogger"
 	"github.com/networkservicemesh/sdk/pkg/tools/opentracing"
 	"github.com/networkservicemesh/sdk/pkg/tools/spiffejwt"
 	"github.com/networkservicemesh/sdk/pkg/tools/token"
@@ -54,6 +55,7 @@ const (
 
 type manager struct {
 	ctx           context.Context
+	logger        log.Logger
 	configuration *config.Config
 	cancelFunc    context.CancelFunc
 	mgr           nsmgr.Nsmgr
@@ -87,20 +89,22 @@ func (m *manager) initSecurity() (err error) {
 func RunNsmgr(ctx context.Context, configuration *config.Config) error {
 	starttime := time.Now()
 
+	_, sLogger, span, sFinish := spanlogger.FromContext(ctx, "cmd-nsmgr")
+	defer sFinish()
+	_, lLogger, lFinish := logruslogger.FromSpan(ctx, span, "cmd-nsmgr")
+	defer lFinish()
+	logger := log.Combine(sLogger, lLogger)
+
 	m := &manager{
 		configuration: configuration,
+		logger:        logger,
 	}
-	log.EnableTracing(true)
-	traceCtx, finish := withTraceLogger(ctx, "start")
-	defer finish()
 
 	// Context to use for all things started in main
 	m.ctx, m.cancelFunc = context.WithCancel(ctx)
-	m.ctx = log.WithFields(m.ctx, map[string]interface{}{"cmd": "Nsmgr"})
-	m.ctx = log.WithLog(m.ctx, logruslogger.New(m.ctx))
 
 	if err := m.initSecurity(); err != nil {
-		log.FromContext(traceCtx).Errorf("failed to create new spiffe TLS Peer %v", err)
+		m.logger.Errorf("failed to create new spiffe TLS Peer %v", err)
 		return err
 	}
 
@@ -161,25 +165,16 @@ func RunNsmgr(ctx context.Context, configuration *config.Config) error {
 	// Create GRPC server
 	m.startServers(m.server)
 
-	log.FromContext(m.ctx).Infof("Startup completed in %v", time.Since(starttime))
+	m.logger.Infof("Startup completed in %v", time.Since(starttime))
 	starttime = time.Now()
 	<-m.ctx.Done()
 
-	log.FromContext(m.ctx).Infof("Exit requested. Uptime: %v", time.Since(starttime))
+	m.logger.Infof("Exit requested. Uptime: %v", time.Since(starttime))
 	// If we here we need to call Stop
 	m.Stop()
 	return nil
 }
 
-func withTraceLogger(ctx context.Context, operation string) (c context.Context, f func()) {
-	ctx, sLogger, span, sFinish := spanlogger.FromContext(ctx, operation)
-	ctx, lLogger, lFinish := logruslogger.FromSpan(ctx, span, operation)
-	return log.WithLog(ctx, sLogger, lLogger), func() {
-		sFinish()
-		lFinish()
-	}
-}
-
 func createListenFolders(configuration *config.Config) {
 	for i := 0; i < len(configuration.ListenOn); i++ {
 		u := &configuration.ListenOn[i]
@@ -196,7 +191,7 @@ func waitErrChan(ctx context.Context, errChan <-chan error, m *manager) {
 	case err := <-errChan:
 		// We need to cal cancel global context, since it could be multiple context of this kind
 		m.cancelFunc()
-		log.FromContext(ctx).Warnf("failed to serve: %v", err)
+		m.logger.Warnf("failed to serve: %v", err)
 	}
 }
 
@@ -217,7 +212,7 @@ func (m *manager) getPublicURL() string {
 	}
 	addrs, err := net.InterfaceAddrs()
 	if err != nil {
-		logrus.Warn(err.Error())
+		m.logger.Warn(err.Error())
 		return u.String()
 	}
 	for _, a := range addrs {
@@ -239,7 +234,7 @@ func (m *manager) startServers(server *grpc.Server) {
 		go func() {
 			// Create a required number of servers
 			errChan := grpcutils.ListenAndServe(m.ctx, listenURL, server)
-			logrus.Infof("NSMGR Listening on: %v", listenURL.String())
+			m.logger.Infof("NSMGR Listening on: %v", listenURL.String())
 			// For public schemas we need to perform registation of nsmgr into registry.
 			wg.Done()
 

main.go

@@ -24,18 +24,16 @@ import (
 	"os/signal"
 	"syscall"
 
-	nested "github.com/antonfisher/nested-logrus-formatter"
 	"github.com/kelseyhightower/envconfig"
 	"github.com/sirupsen/logrus"
 
+	"github.com/networkservicemesh/cmd-nsmgr/internal/config"
+	"github.com/networkservicemesh/cmd-nsmgr/internal/manager"
 	"github.com/networkservicemesh/sdk/pkg/tools/debug"
 	"github.com/networkservicemesh/sdk/pkg/tools/jaeger"
 	"github.com/networkservicemesh/sdk/pkg/tools/log"
 	"github.com/networkservicemesh/sdk/pkg/tools/log/logruslogger"
 	"github.com/networkservicemesh/sdk/pkg/tools/log/spanlogger"
-
-	"github.com/networkservicemesh/cmd-nsmgr/internal/config"
-	"github.com/networkservicemesh/cmd-nsmgr/internal/manager"
 )
 
 func main() {
@@ -51,57 +49,47 @@ func main() {
 	)
 	defer cancel()
 
-	logrus.SetFormatter(&nested.Formatter{})
-	ctx = log.WithFields(ctx, map[string]interface{}{"cmd": os.Args[:1]})
-	ctx = log.WithLog(ctx, logruslogger.New(ctx))
+	_, sLogger, span, sFinish := spanlogger.FromContext(ctx, "cmd-nsmgr")
+	defer sFinish()
+	_, lLogger, lFinish := logruslogger.FromSpan(ctx, span, "cmd-nsmgr")
+	defer lFinish()
+	logger := log.Combine(sLogger, lLogger)
 
 	// ********************************************************************************
 	// Debug self if necessary
 	// ********************************************************************************
 	if err := debug.Self(); err != nil {
-		log.FromContext(ctx).Infof("%s", err)
+		logger.Infof("%s", err)
 	}
 
 	// ********************************************************************************
 	// Configure open tracing
 	// ********************************************************************************
 	// Enable Jaeger
 	log.EnableTracing(true)
-	jaegerCloser := jaeger.InitJaeger(ctx, "nsmgr")
+	jaegerCloser := jaeger.InitJaeger(log.WithLog(ctx, logger), "nsmgr")
 	defer func() { _ = jaegerCloser.Close() }()
-	traceCtx, finish := withTraceLogger(ctx, "nsmgr")
 
 	// Get cfg from environment
 	cfg := &config.Config{}
 	if err := envconfig.Usage("nsm", cfg); err != nil {
-		logrus.Fatal(err)
+		logger.Fatal(err)
 	}
 	if err := envconfig.Process("nsm", cfg); err != nil {
-		logrus.Fatalf("error processing cfg from env: %+v", err)
+		logger.Fatalf("error processing cfg from env: %+v", err)
 	}
 
-	logrus.Infof("Using configuration: %v", cfg)
+	logger.Infof("Using configuration: %v", cfg)
 
 	level, err := logrus.ParseLevel(cfg.LogLevel)
 	if err != nil {
-		logrus.Fatalf("invalid log level %s", cfg.LogLevel)
+		logger.Fatalf("invalid log level %s", cfg.LogLevel)
 	}
 	logrus.SetLevel(level)
+	sFinish()
 
-	// Startup is finished
-	finish()
-
-	err = manager.RunNsmgr(traceCtx, cfg)
+	err = manager.RunNsmgr(ctx, cfg)
 	if err != nil {
-		logrus.Fatalf("error executing rootCmd: %v", err)
-	}
-}
-
-func withTraceLogger(ctx context.Context, operation string) (c context.Context, f func()) {
-	ctx, sLogger, span, sFinish := spanlogger.FromContext(ctx, operation)
-	ctx, lLogger, lFinish := logruslogger.FromSpan(ctx, span, operation)
-	return log.WithLog(ctx, sLogger, lLogger), func() {
-		sFinish()
-		lFinish()
+		logger.Fatalf("error executing rootCmd: %v", err)
 	}
 }