From c122c98e4d32af34cf7efe17c97e22bfb8975344 Mon Sep 17 00:00:00 2001 From: David Zhao Date: Sat, 15 Jan 2022 10:28:03 -0800 Subject: [PATCH] Improved logging configuration (#342) --- cmd/server/main.go | 32 +++++++------ config-sample.yaml | 16 +++++-- pkg/config/config.go | 26 ++++++++++- pkg/{rtc => logger}/logadapter.go | 49 ++++++++------------ pkg/logger/logger.go | 76 +++++++++++++++++++++++-------- pkg/rtc/config.go | 5 +- pkg/rtc/room.go | 4 +- pkg/rtc/room_test.go | 2 +- pkg/rtc/transport.go | 3 +- pkg/service/turn.go | 2 +- test/integration_helpers.go | 2 +- 11 files changed, 139 insertions(+), 78 deletions(-) rename pkg/{rtc => logger}/logadapter.go (55%) diff --git a/cmd/server/main.go b/cmd/server/main.go index 67ecb4423..86264279d 100644 --- a/cmd/server/main.go +++ b/cmd/server/main.go @@ -59,6 +59,11 @@ func main() { Usage: "IP address of the current node, used to advertise to clients. Automatically determined by default", EnvVars: []string{"NODE_IP"}, }, + &cli.IntFlag{ + Name: "udp-port", + Usage: "Single UDP port to use for WebRTC traffic", + EnvVars: []string{"UDP_PORT"}, + }, &cli.StringFlag{ Name: "redis-host", Usage: "host (incl. port) to redis server", @@ -69,6 +74,17 @@ func main() { Usage: "password to redis", EnvVars: []string{"REDIS_PASSWORD"}, }, + &cli.StringFlag{ + Name: "turn-cert", + Usage: "tls cert file for TURN server", + EnvVars: []string{"LIVEKIT_TURN_CERT"}, + }, + &cli.StringFlag{ + Name: "turn-key", + Usage: "tls key file for TURN server", + EnvVars: []string{"LIVEKIT_TURN_KEY"}, + }, + // debugging flags &cli.StringFlag{ Name: "cpuprofile", Usage: "write cpu profile to `file`", @@ -81,16 +97,6 @@ func main() { Name: "dev", Usage: "sets log-level to debug, and console formatter", }, - &cli.StringFlag{ - Name: "turn-cert", - Usage: "tls cert file for TURN server", - EnvVars: []string{"LIVEKIT_TURN_CERT"}, - }, - &cli.StringFlag{ - Name: "turn-key", - Usage: "tls key file for TURN server", - EnvVars: []string{"LIVEKIT_TURN_KEY"}, - }, }, Action: startServer, Commands: []*cli.Command{ @@ -160,11 +166,7 @@ func startServer(c *cli.Context) error { return err } - if conf.Development { - serverlogger.InitDevelopment(conf.LogLevel) - } else { - serverlogger.InitProduction(conf.LogLevel) - } + serverlogger.InitFromConfig(conf.Logging) if cpuProfile != "" { if f, err := os.Create(cpuProfile); err != nil { diff --git a/config-sample.yaml b/config-sample.yaml index fbaa843f0..0a0d8ca27 100644 --- a/config-sample.yaml +++ b/config-sample.yaml @@ -2,9 +2,6 @@ # for production setups, this port should be placed behind a load balancer with TLS port: 7880 -# log level, valid values: debug, info, warning, error -log_level: info - # when redis is set, LiveKit will automatically operate in a fully distributed fashion # clients could connect to any node and be routed to the same room redis: @@ -67,6 +64,19 @@ keys: key1: secret1 key2: secret2 +# Logging config +# logging: +# # log level, valid values: debug, info, warning, error +# level: info +# # log level for pion, default error +# pion_level: error +# # when set to true, emit json fields +# json: false +# # for production setups, enables sampling algorithm +# # https://github.com/uber-go/zap/blob/master/FAQ.md#why-sample-application-logs +# sample: false + + # Default room config # Each room created will inherit these settings. If rooms are created explicitly with CreateRoom, they will take # precedence over defaults diff --git a/pkg/config/config.go b/pkg/config/config.go index 7b47d3857..65454e0c2 100644 --- a/pkg/config/config.go +++ b/pkg/config/config.go @@ -37,8 +37,10 @@ type Config struct { KeyFile string `yaml:"key_file"` Keys map[string]string `yaml:"keys"` Region string `yaml:"region"` - LogLevel string `yaml:"log_level"` - Limit LimitConfig `yaml:"limit"` + // LogLevel is deprecated + LogLevel string `yaml:"log_level"` + Logging LoggingConfig `yaml:"logging"` + Limit LimitConfig `yaml:"limit"` Development bool `yaml:"development"` } @@ -112,6 +114,13 @@ type CodecSpec struct { FmtpLine string `yaml:"fmtp_line"` } +type LoggingConfig struct { + JSON bool `yaml:"json"` + Level string `yaml:"level"` + Sample bool `yaml:"sample"` + PionLevel string `yaml:"pion_level"` +} + type TURNConfig struct { Enabled bool `yaml:"enabled"` Domain string `yaml:"domain"` @@ -187,6 +196,9 @@ func NewConfig(confString string, c *cli.Context) (*Config, error) { }, EmptyTimeout: 5 * 60, }, + Logging: LoggingConfig{ + PionLevel: "error", + }, TURN: TURNConfig{ Enabled: false, }, @@ -244,6 +256,13 @@ func NewConfig(confString string, c *cli.Context) (*Config, error) { conf.Limit.BytesPerSec = defaultLimitBytesPerSec } + if conf.LogLevel != "" { + conf.Logging.Level = conf.LogLevel + } + if conf.Logging.Level == "" && conf.Development { + conf.Logging.Level = "debug" + } + return conf, nil } @@ -281,6 +300,9 @@ func (conf *Config) updateFromCLI(c *cli.Context) error { if c.IsSet("node-ip") { conf.RTC.NodeIP = c.String("node-ip") } + if c.IsSet("udp-port") { + conf.RTC.UDPPort = uint32(c.Int("udp-port")) + } return nil } diff --git a/pkg/rtc/logadapter.go b/pkg/logger/logadapter.go similarity index 55% rename from pkg/rtc/logadapter.go rename to pkg/logger/logadapter.go index 248261277..031eeb8d2 100644 --- a/pkg/rtc/logadapter.go +++ b/pkg/logger/logadapter.go @@ -1,47 +1,24 @@ -package rtc +package serverlogger import ( "fmt" "github.com/go-logr/logr" - "github.com/pion/logging" + "go.uber.org/zap/zapcore" ) -// implements webrtc.LoggerFactory -type loggerFactory struct { - logger logr.Logger -} - -func newLoggerFactory(logger logr.Logger) *loggerFactory { - if logger.GetSink() == nil { - return nil - } - return &loggerFactory{ - logger: logger, - } -} - -func (f *loggerFactory) NewLogger(scope string) logging.LeveledLogger { - return &logAdapter{ - logger: f.logger.WithName(scope), - // treat info as debug - verbosity: 1, - } -} - // implements webrtc.LeveledLogger type logAdapter struct { logger logr.Logger - // 0 - most verbose - verbosity int + level zapcore.Level } func (l *logAdapter) Trace(msg string) { - l.Tracef(msg) + // ignore trace } func (l *logAdapter) Tracef(format string, args ...interface{}) { - l.logger.V(2 + l.verbosity).Info(fmt.Sprintf(format, args...)) + // ignore trace } func (l *logAdapter) Debug(msg string) { @@ -49,7 +26,10 @@ func (l *logAdapter) Debug(msg string) { } func (l *logAdapter) Debugf(format string, args ...interface{}) { - l.logger.V(1 + l.verbosity).Info(fmt.Sprintf(format, args...)) + if l.level > zapcore.DebugLevel { + return + } + l.logger.V(1).Info(fmt.Sprintf(format, args...)) } func (l *logAdapter) Info(msg string) { @@ -57,7 +37,10 @@ func (l *logAdapter) Info(msg string) { } func (l *logAdapter) Infof(format string, args ...interface{}) { - l.logger.V(l.verbosity).Info(fmt.Sprintf(format, args...)) + if l.level > zapcore.InfoLevel { + return + } + l.logger.Info(fmt.Sprintf(format, args...)) } func (l *logAdapter) Warn(msg string) { @@ -65,6 +48,9 @@ func (l *logAdapter) Warn(msg string) { } func (l *logAdapter) Warnf(format string, args ...interface{}) { + if l.level > zapcore.WarnLevel { + return + } l.logger.Info(fmt.Sprintf(format, args...)) } @@ -73,5 +59,8 @@ func (l *logAdapter) Error(msg string) { } func (l *logAdapter) Errorf(format string, args ...interface{}) { + if l.level > zapcore.ErrorLevel { + return + } l.logger.Error(nil, fmt.Sprintf(format, args...)) } diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index cd06d2796..248a76747 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -3,6 +3,7 @@ package serverlogger import ( "github.com/go-logr/logr" "github.com/go-logr/zapr" + "github.com/livekit/livekit-server/pkg/config" "github.com/livekit/protocol/logger" "github.com/pion/logging" "go.uber.org/zap" @@ -13,15 +14,29 @@ import ( ) var ( - // pion/webrtc, pion/turn - defaultFactory logging.LoggerFactory + logConfig config.LoggingConfig + pionLevel zapcore.Level ) -func LoggerFactory() logging.LoggerFactory { - if defaultFactory == nil { - defaultFactory = logging.NewDefaultLoggerFactory() +// implements webrtc.LoggerFactory +type LoggerFactory struct { + logger logr.Logger +} + +func NewLoggerFactory(logger logr.Logger) *LoggerFactory { + if logger.GetSink() == nil { + logger = logr.Discard() + } + return &LoggerFactory{ + logger: logger, + } +} + +func (f *LoggerFactory) NewLogger(scope string) logging.LeveledLogger { + return &logAdapter{ + logger: f.logger.WithName(scope), + level: pionLevel, } - return defaultFactory } // Note: only pass in logr.Logger with default depth @@ -31,24 +46,45 @@ func SetLogger(l logr.Logger) { buffer.Logger = sfu.Logger } -func InitProduction(logLevel string) { - initLogger(zap.NewProductionConfig(), logLevel) -} - -func InitDevelopment(logLevel string) { - initLogger(zap.NewDevelopmentConfig(), logLevel) +func InitFromConfig(config config.LoggingConfig) { + logConfig = config + lvl := parseLevel(config.Level) + pionLevel = parseLevel(config.PionLevel) + if lvl > pionLevel { + pionLevel = lvl + } + zapConfig := zap.Config{ + Level: zap.NewAtomicLevelAt(lvl), + Development: false, + Encoding: "console", + EncoderConfig: zap.NewDevelopmentEncoderConfig(), + OutputPaths: []string{"stderr"}, + ErrorOutputPaths: []string{"stderr"}, + } + if config.Sample { + zapConfig.Sampling = &zap.SamplingConfig{ + Initial: 100, + Thereafter: 100, + } + } + if config.JSON { + zapConfig.Encoding = "json" + zapConfig.EncoderConfig = zap.NewProductionEncoderConfig() + } + initLogger(zapConfig) } // valid levels: debug, info, warn, error, fatal, panic -func initLogger(config zap.Config, level string) { - if level != "" { - lvl := zapcore.Level(0) - if err := lvl.UnmarshalText([]byte(level)); err == nil { - config.Level = zap.NewAtomicLevelAt(lvl) - } - } - +func initLogger(config zap.Config) { l, _ := config.Build() zapLogger := zapr.NewLogger(l) SetLogger(zapLogger) } + +func parseLevel(level string) zapcore.Level { + lvl := zapcore.InfoLevel + if level != "" { + _ = lvl.UnmarshalText([]byte(level)) + } + return lvl +} diff --git a/pkg/rtc/config.go b/pkg/rtc/config.go index 687f297d9..2fca981b0 100644 --- a/pkg/rtc/config.go +++ b/pkg/rtc/config.go @@ -4,12 +4,13 @@ import ( "errors" "net" + logging "github.com/livekit/livekit-server/pkg/logger" + "github.com/livekit/protocol/logger" "github.com/pion/ice/v2" "github.com/pion/sdp/v3" "github.com/pion/webrtc/v3" "github.com/livekit/livekit-server/pkg/config" - serverlogger "github.com/livekit/livekit-server/pkg/logger" "github.com/livekit/livekit-server/pkg/sfu/buffer" ) @@ -60,7 +61,7 @@ func NewWebRTCConfig(conf *config.Config, externalIP string) (*WebRTCConfig, err SDPSemantics: webrtc.SDPSemanticsUnifiedPlan, } s := webrtc.SettingEngine{ - LoggerFactory: serverlogger.LoggerFactory(), + LoggerFactory: logging.NewLoggerFactory(logger.GetLogger()), } s.SetLite(true) diff --git a/pkg/rtc/room.go b/pkg/rtc/room.go index 543738467..a65706b23 100644 --- a/pkg/rtc/room.go +++ b/pkg/rtc/room.go @@ -215,8 +215,8 @@ func (r *Room) Join(participant types.LocalParticipant, opts *ParticipantOptions "pID", participant.ID(), "participant", participant.Identity(), "protocol", participant.ProtocolVersion(), - "room", r.Room.Name, - "roomID", r.Room.Sid) + "roomID", r.Room.Sid, + "options", opts) if participant.IsRecorder() && !r.Room.ActiveRecording { r.Room.ActiveRecording = true diff --git a/pkg/rtc/room_test.go b/pkg/rtc/room_test.go index 9786bf35e..82bf317fe 100644 --- a/pkg/rtc/room_test.go +++ b/pkg/rtc/room_test.go @@ -24,7 +24,7 @@ const ( ) func init() { - serverlogger.InitDevelopment("") + serverlogger.InitFromConfig(config.LoggingConfig{Level: "debug"}) } var iceServersForRoom = []*livekit.ICEServer{{Urls: []string{"stun:stun.l.google.com:19302"}}} diff --git a/pkg/rtc/transport.go b/pkg/rtc/transport.go index 5b5a38b75..eb553a443 100644 --- a/pkg/rtc/transport.go +++ b/pkg/rtc/transport.go @@ -8,6 +8,7 @@ import ( "github.com/bep/debounce" "github.com/go-logr/logr" + "github.com/livekit/livekit-server/pkg/logger" "github.com/livekit/protocol/livekit" "github.com/livekit/protocol/logger" "github.com/pion/interceptor" @@ -85,7 +86,7 @@ func newPeerConnection(params TransportParams) (*webrtc.PeerConnection, *webrtc. se := params.Config.SettingEngine se.DisableMediaEngineCopy(true) - lf := newLoggerFactory(logr.Logger(params.Logger)) + lf := serverlogger.NewLoggerFactory(logr.Logger(params.Logger)) if lf != nil { se.LoggerFactory = lf } diff --git a/pkg/service/turn.go b/pkg/service/turn.go index 97b2f9bfd..7334190bc 100644 --- a/pkg/service/turn.go +++ b/pkg/service/turn.go @@ -36,7 +36,7 @@ func NewTurnServer(conf *config.Config, authHandler turn.AuthHandler) (*turn.Ser serverConfig := turn.ServerConfig{ Realm: LivekitRealm, AuthHandler: authHandler, - LoggerFactory: logging.LoggerFactory(), + LoggerFactory: logging.NewLoggerFactory(logger.GetLogger()), } relayAddrGen := &turn.RelayAddressGeneratorPortRange{ RelayAddress: net.ParseIP(conf.RTC.NodeIP), diff --git a/test/integration_helpers.go b/test/integration_helpers.go index 145fd8d24..b44416efd 100644 --- a/test/integration_helpers.go +++ b/test/integration_helpers.go @@ -43,7 +43,7 @@ var ( ) func init() { - serverlogger.InitDevelopment("") + serverlogger.InitFromConfig(config.LoggingConfig{Level: "debug"}) } func setupSingleNodeTest(name string, roomName string) (*service.LivekitServer, func()) {