RSDK-8320: Allow RDK Loggers to Call Sublogger() (#311)

logger.go

@@ -1,6 +1,8 @@
 package utils
 
 import (
+	"reflect"
+
 	"github.com/edaniels/golog"
 	"go.uber.org/zap"
 )
@@ -22,7 +24,6 @@ type ILogger interface {
 // ZapCompatibleLogger is a basic logging interface for golog.Logger (alias for *zap.SugaredLogger) and RDK loggers.
 type ZapCompatibleLogger interface {
 	Desugar() *zap.Logger
-	Named(name string) *zap.SugaredLogger
 	With(args ...interface{}) *zap.SugaredLogger
 
 	Debug(args ...interface{})
@@ -45,3 +46,36 @@ type ZapCompatibleLogger interface {
 	Fatalf(template string, args ...interface{})
 	Fatalw(msg string, keysAndValues ...interface{})
 }
+
+// Sublogger creates a sublogger from the given ZapCompatibleLogger instance.
+// This function uses reflection to dynamically create a sublogger from the provided logger by
+// calling its `Sublogger` method if it is an RDK logger, or its `Named` method if it is a Zap logger.
+// If neither method is available, it logs a debug message and returns the original logger.
+func Sublogger(inp ZapCompatibleLogger, subname string) (loggerRet ZapCompatibleLogger) {
+	loggerRet = inp
+
+	defer func() {
+		if r := recover(); r != nil {
+			inp.Debugf("panic occurred while creating sublogger: %v, returning self", r)
+		}
+	}()
+
+	typ := reflect.TypeOf(inp)
+	sublogger, ok := typ.MethodByName("Sublogger")
+	if !ok {
+		sublogger, ok = typ.MethodByName("Named")
+		if !ok {
+			inp.Debugf("could not create sublogger from logger of type %s, returning self", typ.String())
+			return inp
+		}
+	}
+
+	ret := sublogger.Func.Call([]reflect.Value{reflect.ValueOf(inp), reflect.ValueOf(subname)})
+	loggerRet, ok = ret[0].Interface().(ZapCompatibleLogger)
+	if !ok {
+		inp.Debug("sublogger func returned an unexpected type, returning self")
+		return inp
+	}
+
+	return loggerRet
+}

logger_test.go

@@ -0,0 +1,103 @@
+package utils
+
+import (
+	"reflect"
+	"testing"
+
+	"github.com/edaniels/golog"
+	"go.uber.org/zap"
+	"go.viam.com/test"
+)
+
+// InvalidLogger fulfills the ZapCompatibleLogger interface without a Named() or Sublogger() method, used to test
+// that utils.Sublogger() should fail without either of these methods.
+type InvalidLogger struct {
+	name string
+}
+
+func (m *InvalidLogger) Desugar() *zap.Logger {
+	return zap.NewNop()
+}
+
+func (m *InvalidLogger) With(args ...interface{}) *zap.SugaredLogger {
+	return zap.NewNop().Sugar()
+}
+
+func (m *InvalidLogger) Debug(args ...interface{}) {
+}
+
+func (m *InvalidLogger) Debugf(template string, args ...interface{}) {
+}
+
+func (m *InvalidLogger) Debugw(msg string, keysAndValues ...interface{}) {
+}
+
+func (m *InvalidLogger) Info(args ...interface{}) {
+}
+
+func (m *InvalidLogger) Infof(template string, args ...interface{}) {
+}
+
+func (m *InvalidLogger) Infow(msg string, keysAndValues ...interface{}) {
+}
+
+func (m *InvalidLogger) Warn(args ...interface{}) {
+}
+
+func (m *InvalidLogger) Warnf(template string, args ...interface{}) {
+}
+
+func (m *InvalidLogger) Warnw(msg string, keysAndValues ...interface{}) {
+}
+
+func (m *InvalidLogger) Error(args ...interface{}) {
+}
+
+func (m *InvalidLogger) Errorf(template string, args ...interface{}) {
+}
+
+func (m *InvalidLogger) Errorw(msg string, keysAndValues ...interface{}) {
+}
+
+func (m *InvalidLogger) Fatal(args ...interface{}) {
+}
+
+func (m *InvalidLogger) Fatalf(template string, args ...interface{}) {
+}
+
+func (m *InvalidLogger) Fatalw(msg string, keysAndValues ...interface{}) {
+}
+
+// MockLogger fulfills the ZapCompatibleLogger interface by extending InvalidLogger with a Sublogger() method. This type
+// is used to simulate calling utils.Sublogger() on an RDK logger.
+type MockLogger struct {
+	InvalidLogger
+	name string
+}
+
+func (m *MockLogger) Sublogger(subname string) ZapCompatibleLogger {
+	return &MockLogger{name: m.name + "." + subname}
+}
+
+func TestSubloggerWithZapLogger(t *testing.T) {
+	logger := golog.NewTestLogger(t)
+	sublogger := Sublogger(logger, "sub")
+	test.That(t, sublogger, test.ShouldNotBeNil)
+	test.That(t, sublogger, test.ShouldNotEqual, logger)
+	test.That(t, reflect.TypeOf(sublogger), test.ShouldEqual, reflect.TypeOf(logger))
+}
+
+func TestSubloggerWithMockRDKLogger(t *testing.T) {
+	logger := &MockLogger{name: "main"}
+	sublogger := Sublogger(logger, "sub")
+	test.That(t, sublogger, test.ShouldNotBeNil)
+	test.That(t, sublogger, test.ShouldNotEqual, logger)
+	test.That(t, reflect.TypeOf(sublogger), test.ShouldEqual, reflect.TypeOf(logger))
+}
+
+func TestSubloggerWithInvalidLogger(t *testing.T) {
+	logger := &InvalidLogger{name: "main"}
+	sublogger := Sublogger(logger, "sub")
+	// Sublogger returns logger (itself) if creating a sublogger fails, which we expect
+	test.That(t, sublogger, test.ShouldEqual, logger)
+}

pexec/managed_process.go

@@ -39,7 +39,7 @@ type ManagedProcess interface {
 
 // NewManagedProcess returns a new, unstarted, from the given configuration.
 func NewManagedProcess(config ProcessConfig, logger utils.ZapCompatibleLogger) ManagedProcess {
-	logger = logger.Named(fmt.Sprintf("process.%s_%s", config.ID, config.Name))
+	logger = utils.Sublogger(logger, fmt.Sprintf("process.%s_%s", config.ID, config.Name))
 
 	if config.StopSignal == 0 {
 		config.StopSignal = syscall.SIGTERM
@@ -257,7 +257,7 @@ func (p *managedProcess) manage(stdOut, stdErr io.ReadCloser) {
 	var activeLoggers sync.WaitGroup
 	if p.shouldLog || p.logWriter != nil {
 		logPipe := func(name string, pipe io.ReadCloser, isErr bool) {
-			logger := p.logger.Named(name)
+			logger := utils.Sublogger(p.logger, name)
 			defer activeLoggers.Done()
 			pipeR := bufio.NewReader(pipe)
 			logWriterError := false

rpc/server.go

@@ -607,7 +607,7 @@ func NewServer(logger utils.ZapCompatibleLogger, opts ...ServerOption) (Server,
 				server.webrtcServer,
 				sOpts.webrtcOpts.ExternalSignalingDialOpts,
 				config,
-				logger.Named("external_signaler"),
+				utils.Sublogger(logger, "external_signaler"),
 				true, // logStats == true
 			))
 		} else {
@@ -651,7 +651,7 @@ func NewServer(logger utils.ZapCompatibleLogger, opts ...ServerOption) (Server,
 				server.webrtcServer,
 				answererDialOpts,
 				config,
-				logger.Named("internal_signaler"),
+				utils.Sublogger(logger, "internal_signaler"),
 				false, // logStats == false
 			))
 		}

rpc/wrtc_client.go

@@ -104,7 +104,7 @@ func dialWebRTC(
 ) (ch *webrtcClientChannel, err error) {
 	dialStart := time.Now()
 
-	logger = logger.Named("webrtc")
+	logger = utils.Sublogger(logger, "webrtc")
 	dialCtx, timeoutCancel := context.WithTimeout(ctx, getDefaultOfferDeadline())
 	defer timeoutCancel()
 

rpc/wrtc_logger.go

@@ -62,5 +62,5 @@ func (l webrtcLogger) Errorf(format string, args ...interface{}) {
 
 // NewLogger returns a new webrtc logger under the given scope.
 func (lf WebRTCLoggerFactory) NewLogger(scope string) logging.LeveledLogger {
-	return webrtcLogger{lf.Logger.Named(scope)}
+	return webrtcLogger{utils.Sublogger(lf.Logger, scope)}
 }