Adopt pion logging initialization moving to protocol (#1667)

cmd/server/main.go

@@ -12,7 +12,6 @@ import (
 
 	"github.com/urfave/cli/v2"
 
-	serverlogger "github.com/livekit/livekit-server/pkg/logger"
 	"github.com/livekit/livekit-server/pkg/rtc"
 	"github.com/livekit/livekit-server/pkg/telemetry/prometheus"
 	"github.com/livekit/protocol/logger"
@@ -188,7 +187,7 @@ func getConfig(c *cli.Context) (*config.Config, error) {
 	if err != nil {
 		return nil, err
 	}
-	serverlogger.InitFromConfig(conf.Logging)
+	config.InitLoggerFromConfig(conf.Logging)
 
 	if c.String("config") == "" && c.String("config-body") == "" && conf.Development {
 		// use single port UDP when no config is provided

go.mod

@@ -18,7 +18,7 @@ require (
 	github.com/jxskiss/base62 v1.1.0
 	github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1
 	github.com/livekit/mediatransportutil v0.0.0-20230326055817-ed569ca13d26
-	github.com/livekit/protocol v1.5.6-0.20230427055046-79477e28a150
+	github.com/livekit/protocol v1.5.6-0.20230428011359-db5afb1c7f9b
 	github.com/livekit/psrpc v0.3.1-0.20230425025640-5390915734c3
 	github.com/mackerelio/go-osstat v0.2.4
 	github.com/magefile/mage v1.14.0
@@ -28,7 +28,6 @@ require (
 	github.com/pion/dtls/v2 v2.2.6
 	github.com/pion/ice/v2 v2.3.2
 	github.com/pion/interceptor v0.1.13
-	github.com/pion/logging v0.2.2
 	github.com/pion/rtcp v1.2.10
 	github.com/pion/rtp v1.7.13
 	github.com/pion/sdp/v3 v3.0.6
@@ -47,7 +46,6 @@ require (
 	github.com/urfave/cli/v2 v2.25.1
 	github.com/urfave/negroni/v3 v3.0.0
 	go.uber.org/atomic v1.10.0
-	go.uber.org/zap v1.24.0
 	golang.org/x/sync v0.1.0
 	google.golang.org/protobuf v1.30.0
 	gopkg.in/yaml.v3 v3.0.1
@@ -79,6 +77,7 @@ require (
 	github.com/nats-io/nkeys v0.4.4 // indirect
 	github.com/nats-io/nuid v1.0.1 // indirect
 	github.com/pion/datachannel v1.5.5 // indirect
+	github.com/pion/logging v0.2.2 // indirect
 	github.com/pion/mdns v0.0.7 // indirect
 	github.com/pion/randutil v0.1.0 // indirect
 	github.com/pion/sctp v1.8.6 // indirect
@@ -91,6 +90,7 @@ require (
 	github.com/russross/blackfriday/v2 v2.1.0 // indirect
 	github.com/xrash/smetrics v0.0.0-20201216005158-039620a65673 // indirect
 	go.uber.org/multierr v1.6.0 // indirect
+	go.uber.org/zap v1.24.0 // indirect
 	golang.org/x/crypto v0.8.0 // indirect
 	golang.org/x/exp v0.0.0-20230425010034-47ecfdc1ba53 // indirect
 	golang.org/x/mod v0.8.0 // indirect

go.sum

@@ -121,8 +121,8 @@ github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1 h1:jm09419p0lqTkD
 github.com/livekit/mageutil v0.0.0-20230125210925-54e8a70427c1/go.mod h1:Rs3MhFwutWhGwmY1VQsygw28z5bWcnEYmS1OG9OxjOQ=
 github.com/livekit/mediatransportutil v0.0.0-20230326055817-ed569ca13d26 h1:QlQFyMwCDgjyySsrgmrMcVbEBA6KZcyTzvK+z346tUA=
 github.com/livekit/mediatransportutil v0.0.0-20230326055817-ed569ca13d26/go.mod h1:eDA41kiySZoG+wy4Etsjb3w0jjLx69i/vAmSjG4bteA=
-github.com/livekit/protocol v1.5.6-0.20230427055046-79477e28a150 h1:jN0fW8H8Qgi5xsmmbk1s2qsXg1Y873zeWghE4mRV1Cc=
-github.com/livekit/protocol v1.5.6-0.20230427055046-79477e28a150/go.mod h1:MBW05GWdhbl+o6u2gLLCQtDvr9EvcV4VWckpIYtoM2c=
+github.com/livekit/protocol v1.5.6-0.20230428011359-db5afb1c7f9b h1:UEFMJr1OTF0yAX9mRRaQQ/YrTA6H7hCkbuABWfT6wLk=
+github.com/livekit/protocol v1.5.6-0.20230428011359-db5afb1c7f9b/go.mod h1:MBW05GWdhbl+o6u2gLLCQtDvr9EvcV4VWckpIYtoM2c=
 github.com/livekit/psrpc v0.3.1-0.20230425025640-5390915734c3 h1:NXcxrluYLng7LTHcYNOj/MdR4SHWrKQAG2G+U930mTA=
 github.com/livekit/psrpc v0.3.1-0.20230425025640-5390915734c3/go.mod h1:n6JntEg+zT6Ji8InoyTpV7wusPNwGqqtxmHlkNhDN0U=
 github.com/mackerelio/go-osstat v0.2.4 h1:qxGbdPkFo65PXOb/F/nhDKpF2nGmGaCFDLXoZjJTtUs=

pkg/config/config.go

@@ -14,6 +14,7 @@ import (
 	"gopkg.in/yaml.v3"
 
 	"github.com/livekit/protocol/logger"
+	"github.com/livekit/protocol/logger/pionlogger"
 	redisLiveKit "github.com/livekit/protocol/redis"
 )
 
@@ -744,3 +745,13 @@ func (conf *Config) unmarshalKeys(keys string) error {
 	}
 	return nil
 }
+
+// Note: only pass in logr.Logger with default depth
+func SetLogger(l logger.Logger) {
+	logger.SetLogger(l, "livekit")
+}
+
+func InitLoggerFromConfig(config LoggingConfig) {
+	pionlogger.SetLogLevel(config.PionLevel)
+	logger.InitFromConfig(config.Config, "livekit")
+}

pkg/logger/logadapter.go

@@ -1,118 +0,0 @@
-package serverlogger
-
-import (
-	"fmt"
-	"strings"
-
-	"go.uber.org/zap/zapcore"
-
-	"github.com/livekit/protocol/logger"
-)
-
-// implements webrtc.LeveledLogger
-type logAdapter struct {
-	logger          logger.Logger
-	level           zapcore.Level
-	ignoredPrefixes []string
-}
-
-func (l *logAdapter) Trace(msg string) {
-	// ignore trace
-}
-
-func (l *logAdapter) Tracef(format string, args ...interface{}) {
-	// ignore trace
-}
-
-func (l *logAdapter) Debug(msg string) {
-	if l.level > zapcore.DebugLevel {
-		return
-	}
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Debugw(msg)
-}
-
-func (l *logAdapter) Debugf(format string, args ...interface{}) {
-	if l.level > zapcore.DebugLevel {
-		return
-	}
-	msg := fmt.Sprintf(format, args...)
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Debugw(msg)
-}
-
-func (l *logAdapter) Info(msg string) {
-	if l.level > zapcore.InfoLevel {
-		return
-	}
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Infow(msg)
-}
-
-func (l *logAdapter) Infof(format string, args ...interface{}) {
-	if l.level > zapcore.InfoLevel {
-		return
-	}
-	msg := fmt.Sprintf(format, args...)
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Infow(msg)
-}
-
-func (l *logAdapter) Warn(msg string) {
-	if l.level > zapcore.WarnLevel {
-		return
-	}
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Warnw(msg, nil)
-}
-
-func (l *logAdapter) Warnf(format string, args ...interface{}) {
-	if l.level > zapcore.WarnLevel {
-		return
-	}
-	msg := fmt.Sprintf(format, args...)
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Warnw(msg, nil)
-}
-
-func (l *logAdapter) Error(msg string) {
-	if l.level > zapcore.ErrorLevel {
-		return
-	}
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Errorw(msg, nil)
-}
-
-func (l *logAdapter) Errorf(format string, args ...interface{}) {
-	if l.level > zapcore.ErrorLevel {
-		return
-	}
-	msg := fmt.Sprintf(format, args...)
-	if l.shouldIgnore(msg) {
-		return
-	}
-	l.logger.Errorw(msg, nil)
-}
-
-func (l *logAdapter) shouldIgnore(msg string) bool {
-	for _, prefix := range l.ignoredPrefixes {
-		if strings.HasPrefix(msg, prefix) {
-			return true
-		}
-	}
-	return false
-}

pkg/logger/logger.go

@@ -1,66 +0,0 @@
-package serverlogger
-
-import (
-	"github.com/pion/logging"
-	"go.uber.org/zap/zapcore"
-
-	"github.com/livekit/protocol/logger"
-
-	"github.com/livekit/livekit-server/pkg/config"
-)
-
-var (
-	pionLevel           zapcore.Level
-	pionIgnoredPrefixes = map[string][]string{
-		"ice": {
-			"pingAllCandidates called with no candidate pairs",
-			"failed to send packet: io: read/write on closed pipe",
-			"Ignoring remote candidate with tcpType active",
-			"discard message from",
-			"Failed to discover mDNS candidate",
-			"Failed to read from candidate tcp",
-			"remote mDNS candidate added, but mDNS is disabled",
-		},
-		"pc": {
-			"Failed to accept RTCP stream is already closed",
-			"Failed to accept RTP stream is already closed",
-			"Incoming unhandled RTCP ssrc",
-		},
-		"tcp_mux": {
-			"Error reading first packet from",
-			"error closing connection",
-		},
-		"turn": {
-			"error when handling datagram",
-		},
-	}
-)
-
-// implements webrtc.LoggerFactory
-type LoggerFactory struct {
-	logger logger.Logger
-}
-
-func NewLoggerFactory(logger logger.Logger) *LoggerFactory {
-	return &LoggerFactory{
-		logger: logger,
-	}
-}
-
-func (f *LoggerFactory) NewLogger(scope string) logging.LeveledLogger {
-	return &logAdapter{
-		logger:          f.logger.WithName(scope),
-		level:           pionLevel,
-		ignoredPrefixes: pionIgnoredPrefixes[scope],
-	}
-}
-
-// Note: only pass in logr.Logger with default depth
-func SetLogger(l logger.Logger) {
-	logger.SetLogger(l, "livekit")
-}
-
-func InitFromConfig(config config.LoggingConfig) {
-	pionLevel = logger.ParseZapLevel(config.PionLevel)
-	logger.InitFromConfig(config.Config, "livekit")
-}

pkg/rtc/config.go

@@ -15,10 +15,10 @@ import (
 	"github.com/pion/webrtc/v3"
 
 	"github.com/livekit/livekit-server/pkg/config"
-	logging "github.com/livekit/livekit-server/pkg/logger"
 	"github.com/livekit/livekit-server/pkg/sfu/buffer"
 	dd "github.com/livekit/livekit-server/pkg/sfu/dependencydescriptor"
 	"github.com/livekit/protocol/logger"
+	"github.com/livekit/protocol/logger/pionlogger"
 )
 
 const (
@@ -73,7 +73,7 @@ func NewWebRTCConfig(conf *config.Config, externalIP string) (*WebRTCConfig, err
 		SDPSemantics: webrtc.SDPSemanticsUnifiedPlan,
 	}
 	s := webrtc.SettingEngine{
-		LoggerFactory: logging.NewLoggerFactory(logger.GetLogger()),
+		LoggerFactory: pionlogger.NewLoggerFactory(logger.GetLogger()),
 	}
 
 	var ifFilter func(string) bool

pkg/rtc/room_test.go

@@ -14,7 +14,6 @@ import (
 	"github.com/livekit/protocol/webhook"
 
 	"github.com/livekit/livekit-server/pkg/config"
-	serverlogger "github.com/livekit/livekit-server/pkg/logger"
 	"github.com/livekit/livekit-server/pkg/rtc/types"
 	"github.com/livekit/livekit-server/pkg/rtc/types/typesfakes"
 	"github.com/livekit/livekit-server/pkg/sfu/audio"
@@ -30,7 +29,7 @@ const (
 )
 
 func init() {
-	serverlogger.InitFromConfig(config.LoggingConfig{
+	config.InitLoggerFromConfig(config.LoggingConfig{
 		Config: logger.Config{Level: "debug"},
 	})
 	// allow immediate closure in testing

pkg/rtc/transport.go

@@ -22,10 +22,10 @@ import (
 
 	"github.com/livekit/protocol/livekit"
 	"github.com/livekit/protocol/logger"
+	"github.com/livekit/protocol/logger/pionlogger"
 	lksdp "github.com/livekit/protocol/sdp"
 
 	"github.com/livekit/livekit-server/pkg/config"
-	serverlogger "github.com/livekit/livekit-server/pkg/logger"
 	"github.com/livekit/livekit-server/pkg/rtc/types"
 	"github.com/livekit/livekit-server/pkg/sfu/streamallocator"
 	"github.com/livekit/livekit-server/pkg/telemetry"
@@ -298,7 +298,7 @@ func newPeerConnection(params TransportParams, onBandwidthEstimator func(estimat
 		}
 	}
 
-	lf := serverlogger.NewLoggerFactory(params.Logger)
+	lf := pionlogger.NewLoggerFactory(params.Logger)
 	if lf != nil {
 		se.LoggerFactory = lf
 	}

pkg/service/turn.go

@@ -11,9 +11,9 @@ import (
 
 	"github.com/livekit/protocol/livekit"
 	"github.com/livekit/protocol/logger"
+	"github.com/livekit/protocol/logger/pionlogger"
 
 	"github.com/livekit/livekit-server/pkg/config"
-	logging "github.com/livekit/livekit-server/pkg/logger"
 	"github.com/livekit/livekit-server/pkg/telemetry"
 	"github.com/livekit/livekit-server/pkg/telemetry/prometheus"
 )
@@ -39,7 +39,7 @@ func NewTurnServer(conf *config.Config, authHandler turn.AuthHandler, standalone
 	serverConfig := turn.ServerConfig{
 		Realm:         LivekitRealm,
 		AuthHandler:   authHandler,
-		LoggerFactory: logging.NewLoggerFactory(logger.GetLogger()),
+		LoggerFactory: pionlogger.NewLoggerFactory(logger.GetLogger()),
 	}
 	var relayAddrGen turn.RelayAddressGenerator = &turn.RelayAddressGeneratorPortRange{
 		RelayAddress: net.ParseIP(conf.RTC.NodeIP),

test/integration_helpers.go

@@ -12,7 +12,6 @@ import (
 	"github.com/twitchtv/twirp"
 
 	"github.com/livekit/livekit-server/pkg/config"
-	serverlogger "github.com/livekit/livekit-server/pkg/logger"
 	"github.com/livekit/livekit-server/pkg/routing"
 	"github.com/livekit/livekit-server/pkg/service"
 	"github.com/livekit/livekit-server/pkg/telemetry/prometheus"
@@ -42,7 +41,7 @@ const (
 var roomClient livekit.RoomService
 
 func init() {
-	serverlogger.InitFromConfig(config.LoggingConfig{
+	config.InitLoggerFromConfig(config.LoggingConfig{
 		Config: logger.Config{Level: "debug"},
 	})