From abedc05ce595affa07d52ec517c3e963e8021cb5 Mon Sep 17 00:00:00 2001 From: David Zhao Date: Wed, 9 Jun 2021 12:31:29 -0700 Subject: [PATCH] Improve logging, hook up ion with zap logger --- go.mod | 2 +- go.sum | 8 ++----- pkg/logger/logger.go | 45 ++++++++++++++++++---------------- pkg/rtc/config.go | 49 ++++++++++++++++++++------------------ pkg/rtc/utils.go | 2 +- pkg/service/roommanager.go | 2 +- pkg/service/rtcservice.go | 7 +----- pkg/service/utils.go | 2 +- version/version.go | 2 +- 9 files changed, 59 insertions(+), 60 deletions(-) diff --git a/go.mod b/go.mod index 388f747c4..186caf133 100644 --- a/go.mod +++ b/go.mod @@ -16,7 +16,7 @@ require ( github.com/mitchellh/go-homedir v1.1.0 github.com/pion/ice/v2 v2.1.7 github.com/pion/interceptor v0.0.12 - github.com/pion/ion-sfu v1.10.3 + github.com/pion/ion-sfu v1.10.5 github.com/pion/logging v0.2.2 github.com/pion/rtcp v1.2.6 github.com/pion/rtp v1.6.5 diff --git a/go.sum b/go.sum index c560b6e39..3af9a0808 100644 --- a/go.sum +++ b/go.sum @@ -230,8 +230,6 @@ github.com/lightstep/lightstep-tracer-common/golang/gogo v0.0.0-20190605223551-b github.com/lightstep/lightstep-tracer-go v0.18.1/go.mod h1:jlF1pusYV4pidLvZ+XD0UBX0ZE6WURAspgAczcDHrL4= github.com/lithammer/shortuuid/v3 v3.0.6 h1:pr15YQyvhiSX/qPxncFtqk+v4xLEpOZObbsY/mKrcvA= github.com/lithammer/shortuuid/v3 v3.0.6/go.mod h1:vMk8ke37EmiewwolSO1NLW8vP4ZaKlRuDIi8tWWmAts= -github.com/livekit/protocol v0.5.1 h1:RSX0sQM2+NK2kCHTg/n6wPf0d3qYskc611GYV3h+5+8= -github.com/livekit/protocol v0.5.1/go.mod h1:wo3CGfYB7XMF8GoVJAfTARrYSP/ombi+sbLl6AYdKP0= github.com/livekit/protocol v0.5.2 h1:jYj+50gKBrtJ1q6iEVdHDruHVllA1xtOhiM1/YKqgMk= github.com/livekit/protocol v0.5.2/go.mod h1:wo3CGfYB7XMF8GoVJAfTARrYSP/ombi+sbLl6AYdKP0= github.com/lucsky/cuid v1.0.2 h1:z4XlExeoderxoPj2/dxKOyPxe9RCOu7yNq9/XWxIUMQ= @@ -317,10 +315,8 @@ github.com/pion/ice/v2 v2.1.7 h1:FjgDfUNrVYTxQabJrkBX6ld12tvYbgzHenqPh3PJF6E= github.com/pion/ice/v2 v2.1.7/go.mod h1:kV4EODVD5ux2z8XncbLHIOtcXKtYXVgLVCeVqnpoeP0= github.com/pion/interceptor v0.0.12 h1:eC1iVneBIAQJEfaNAfDqAncJWhMDAnaXPRCJsltdokE= github.com/pion/interceptor v0.0.12/go.mod h1:qzeuWuD/ZXvPqOnxNcnhWfkCZ2e1kwwslicyyPnhoK4= -github.com/pion/ion-log v1.0.1 h1:D3kW75Xa6mxxTSNUP0xoYeDa/C+hINdB04XjicJ7H0Q= -github.com/pion/ion-log v1.0.1/go.mod h1:jwcla9KoB9bB/4FxYDSRJPcPYSLp5XiUUMnOLaqwl4E= -github.com/pion/ion-sfu v1.10.3 h1:/kliY0pRoE87v+PF3k472u3fVDIBA+tK/xJSaltRUDQ= -github.com/pion/ion-sfu v1.10.3/go.mod h1:xdD571H5V7bHaHg6gcg/mqnuXPIljv5In6U5O+576Xs= +github.com/pion/ion-sfu v1.10.5 h1:8VH7IwEEyAr/RiHtAyM2vSmaP0oGKGVD3sFlFCVQ6cg= +github.com/pion/ion-sfu v1.10.5/go.mod h1:Wx6b4qGUjvSo1kGl+/fHl0ZF48g2IJOjzUFg0yCo9qY= github.com/pion/logging v0.2.2 h1:M9+AIj/+pxNsDfAT64+MAVgJO0rsyLnoJKCqf//DoeY= github.com/pion/logging v0.2.2/go.mod h1:k0/tDVsRCX2Mb2ZEmTqNa7CWsQPc+YYCB7Q+5pahoms= github.com/pion/mdns v0.0.5 h1:Q2oj/JB3NqfzY9xGZ1fPzZzK7sDSD8rZPOvcIQ10BCw= diff --git a/pkg/logger/logger.go b/pkg/logger/logger.go index c0fded4b2..04d2372d8 100644 --- a/pkg/logger/logger.go +++ b/pkg/logger/logger.go @@ -1,21 +1,27 @@ package logger import ( + "github.com/go-logr/zapr" + "github.com/pion/ion-sfu/pkg/buffer" + "github.com/pion/ion-sfu/pkg/sfu" "go.uber.org/zap" "go.uber.org/zap/zapcore" ) var ( - logger *zap.SugaredLogger + wrappedLogger *zap.SugaredLogger + // zap logger + defaultLogger *zap.Logger ) -func getLogger() *zap.SugaredLogger { - if logger == nil { +func GetLogger() *zap.Logger { + if defaultLogger == nil { InitDevelopment("") } - return logger + return defaultLogger } +// valid levels: debug, info, warn, error, fatal, panic func initLogger(config zap.Config, level string) { if level != "" { lvl := zapcore.Level(0) @@ -23,8 +29,14 @@ func initLogger(config zap.Config, level string) { config.Level = zap.NewAtomicLevelAt(lvl) } } + // skip one level to remove this helper file l, _ := config.Build(zap.AddCallerSkip(1)) - logger = l.Sugar() + wrappedLogger = l.Sugar() + + defaultLogger, _ = config.Build() + ionLogger := zapr.NewLogger(defaultLogger) + sfu.Logger = ionLogger + buffer.Logger = ionLogger } func InitProduction(logLevel string) { @@ -36,42 +48,35 @@ func InitDevelopment(logLevel string) { } func Debugw(msg string, keysAndValues ...interface{}) { - if logger == nil { + if wrappedLogger == nil { return } - logger.Debugw(msg, keysAndValues...) + wrappedLogger.Debugw(msg, keysAndValues...) } func Infow(msg string, keysAndValues ...interface{}) { - if logger == nil { + if wrappedLogger == nil { return } - logger.Infow(msg, keysAndValues...) + wrappedLogger.Infow(msg, keysAndValues...) } func Warnw(msg string, err error, keysAndValues ...interface{}) { - if logger == nil { + if wrappedLogger == nil { return } if err != nil { keysAndValues = append([]interface{}{"error", err}, keysAndValues...) } - logger.Warnw(msg, keysAndValues...) + wrappedLogger.Warnw(msg, keysAndValues...) } func Errorw(msg string, err error, keysAndValues ...interface{}) { - if logger == nil { + if wrappedLogger == nil { return } if err != nil { keysAndValues = append([]interface{}{"error", err}, keysAndValues...) } - logger.Errorw(msg, keysAndValues...) -} - -func Desugar() *zap.Logger { - if logger == nil { - getLogger() - } - return logger.Desugar() + wrappedLogger.Errorw(msg, keysAndValues...) } diff --git a/pkg/rtc/config.go b/pkg/rtc/config.go index 1e4a25827..50473078d 100644 --- a/pkg/rtc/config.go +++ b/pkg/rtc/config.go @@ -39,7 +39,8 @@ type ReceiverConfig struct { // number of packets to buffer up const readBufferSize = 50 -func NewWebRTCConfig(conf *config.RTCConfig, externalIP string) (*WebRTCConfig, error) { +func NewWebRTCConfig(conf *config.Config, externalIP string) (*WebRTCConfig, error) { + rtcConf := conf.RTC c := webrtc.Configuration{ SDPSemantics: webrtc.SDPSemanticsUnifiedPlan, } @@ -48,7 +49,7 @@ func NewWebRTCConfig(conf *config.RTCConfig, externalIP string) (*WebRTCConfig, lkLogger := loggerFactory.NewLogger("livekit-mux") iceUrls := make([]string, 0) - for _, stunServer := range conf.StunServers { + for _, stunServer := range rtcConf.StunServers { iceUrls = append(iceUrls, fmt.Sprintf("stun:%s", stunServer)) } c.ICEServers = []webrtc.ICEServer{ @@ -56,18 +57,18 @@ func NewWebRTCConfig(conf *config.RTCConfig, externalIP string) (*WebRTCConfig, URLs: iceUrls, }, } - if conf.UseExternalIP && externalIP != "" { + if rtcConf.UseExternalIP && externalIP != "" { s.SetNAT1To1IPs([]string{externalIP}, webrtc.ICECandidateTypeHost) } - if conf.PacketBufferSize == 0 { - conf.PacketBufferSize = 500 + if rtcConf.PacketBufferSize == 0 { + rtcConf.PacketBufferSize = 500 } - bufferFactory := buffer.NewBufferFactory(conf.PacketBufferSize, zapr.NewLogger(logger.Desugar())) + bufferFactory := buffer.NewBufferFactory(rtcConf.PacketBufferSize, zapr.NewLogger(logger.GetLogger())) s.BufferFactory = bufferFactory.GetOrNew networkTypes := make([]webrtc.NetworkType, 0, 4) - if !conf.ForceTCP { + if !rtcConf.ForceTCP { networkTypes = append(networkTypes, webrtc.NetworkTypeUDP4, ) @@ -76,9 +77,9 @@ func NewWebRTCConfig(conf *config.RTCConfig, externalIP string) (*WebRTCConfig, var udpMux *ice.UDPMuxDefault var udpMuxConn *net.UDPConn var err error - if conf.UDPPort != 0 { + if rtcConf.UDPPort != 0 { udpMuxConn, err = net.ListenUDP("udp4", &net.UDPAddr{ - Port: int(conf.UDPPort), + Port: int(rtcConf.UDPPort), }) if err != nil { return nil, err @@ -91,30 +92,32 @@ func NewWebRTCConfig(conf *config.RTCConfig, externalIP string) (*WebRTCConfig, UDPConn: udpMuxConn, }) s.SetICEUDPMux(udpMux) - val, err := checkUDPReadBuffer() - if err == nil { - if val < minUDPBufferSize { - logger.Warnw("UDP receive buffer is too small for a production set-up", nil, - "current", val, - "suggested", minUDPBufferSize) - } else { - logger.Debugw("UDP receive buffer size", "current", val) + if !conf.Development { + val, err := checkUDPReadBuffer() + if err == nil { + if val < minUDPBufferSize { + logger.Warnw("UDP receive buffer is too small for a production set-up", nil, + "current", val, + "suggested", minUDPBufferSize) + } else { + logger.Debugw("UDP receive buffer size", "current", val) + } } } - } else if conf.ICEPortRangeStart != 0 && conf.ICEPortRangeEnd != 0 { - if err := s.SetEphemeralUDPPortRange(uint16(conf.ICEPortRangeStart), uint16(conf.ICEPortRangeEnd)); err != nil { + } else if rtcConf.ICEPortRangeStart != 0 && rtcConf.ICEPortRangeEnd != 0 { + if err := s.SetEphemeralUDPPortRange(uint16(rtcConf.ICEPortRangeStart), uint16(rtcConf.ICEPortRangeEnd)); err != nil { return nil, err } } // use TCP mux when it's set var tcpListener *net.TCPListener - if conf.TCPPort != 0 { + if rtcConf.TCPPort != 0 { networkTypes = append(networkTypes, webrtc.NetworkTypeTCP4, ) tcpListener, err = net.ListenTCP("tcp4", &net.TCPAddr{ - Port: int(conf.TCPPort), + Port: int(rtcConf.TCPPort), }) if err != nil { return nil, err @@ -134,8 +137,8 @@ func NewWebRTCConfig(conf *config.RTCConfig, externalIP string) (*WebRTCConfig, SettingEngine: s, BufferFactory: bufferFactory, Receiver: ReceiverConfig{ - packetBufferSize: conf.PacketBufferSize, - maxBitrate: conf.MaxBitrate, + packetBufferSize: rtcConf.PacketBufferSize, + maxBitrate: rtcConf.MaxBitrate, }, UDPMux: udpMux, UDPMuxConn: udpMuxConn, diff --git a/pkg/rtc/utils.go b/pkg/rtc/utils.go index fb8b741e2..49dd1215d 100644 --- a/pkg/rtc/utils.go +++ b/pkg/rtc/utils.go @@ -122,7 +122,7 @@ func RecoverSilent() { func Recover() { if r := recover(); r != nil { - log := logger.Desugar().WithOptions(zap.AddCallerSkip(1)) + log := logger.GetLogger().WithOptions(zap.AddCallerSkip(1)) log.Error("recovered panic", zap.Any("error", r)) } } diff --git a/pkg/service/roommanager.go b/pkg/service/roommanager.go index c5e2d2a6c..6c639fc91 100644 --- a/pkg/service/roommanager.go +++ b/pkg/service/roommanager.go @@ -34,7 +34,7 @@ type RoomManager struct { } func NewRoomManager(rp RoomStore, router routing.Router, currentNode routing.LocalNode, selector routing.NodeSelector, conf *config.Config) (*RoomManager, error) { - rtcConf, err := rtc.NewWebRTCConfig(&conf.RTC, currentNode.Ip) + rtcConf, err := rtc.NewWebRTCConfig(conf, currentNode.Ip) if err != nil { return nil, err } diff --git a/pkg/service/rtcservice.go b/pkg/service/rtcservice.go index f36dd4346..f7faae6c7 100644 --- a/pkg/service/rtcservice.go +++ b/pkg/service/rtcservice.go @@ -28,12 +28,7 @@ func NewRTCService(conf *config.Config, roomStore RoomStore, roomManager *RoomMa s := &RTCService{ router: router, roomManager: roomManager, - upgrader: websocket.Upgrader{ - // increase buffer size to avoid errors such as - // read: connection reset by peer - // ReadBufferSize: 10240, - // WriteBufferSize: 10240, - }, + upgrader: websocket.Upgrader{}, currentNode: currentNode, isDev: conf.Development, } diff --git a/pkg/service/utils.go b/pkg/service/utils.go index 76acf99dc..5d2e02391 100644 --- a/pkg/service/utils.go +++ b/pkg/service/utils.go @@ -22,7 +22,7 @@ var ServiceSet = wire.NewSet( ) func handleError(w http.ResponseWriter, status int, msg string) { - l := logger.Desugar().WithOptions(zap.AddCallerSkip(1)) + l := logger.GetLogger().WithOptions(zap.AddCallerSkip(1)) l.Debug("error handling request", zap.String("error", msg), zap.Int("status", status)) w.WriteHeader(status) _, _ = w.Write([]byte(msg)) diff --git a/version/version.go b/version/version.go index d2f63ee82..438835cf0 100644 --- a/version/version.go +++ b/version/version.go @@ -1,3 +1,3 @@ package version -const Version = "0.9.8" +const Version = "0.9.9"