From 32307153bf8d1597f9f4463dec0e752799653f45 Mon Sep 17 00:00:00 2001 From: Michael MacDonald Date: Mon, 19 Nov 2018 11:22:55 -0500 Subject: [PATCH] Add leveled/scoped logging facility Allow package-scoped logging at user-defined levels. Logs are at ERROR by default, for critical errors which should be handled by users. More verbose logging may be enabled via combinations of environment variables, e.g. PIONS_LOG_TRACE=ice PIONS_LOG_DEBUG=pc,dtls PIONS_LOG_INFO=all Relates to #222 --- pkg/ice/agent.go | 37 +++--- pkg/ice/candidate.go | 4 +- pkg/ice/candidatepair.go | 10 +- pkg/ice/logging.go | 5 + pkg/logging/leveled.go | 219 ++++++++++++++++++++++++++++++++++++ pkg/logging/logging_test.go | 56 +++++++++ pkg/logging/scoped.go | 105 +++++++++++++++++ rtcpeerconnection.go | 17 ++- 8 files changed, 422 insertions(+), 31 deletions(-) create mode 100644 pkg/ice/logging.go create mode 100644 pkg/logging/leveled.go create mode 100644 pkg/logging/logging_test.go create mode 100644 pkg/logging/scoped.go diff --git a/pkg/ice/agent.go b/pkg/ice/agent.go index 19f6267a38..a2cd3b4a25 100644 --- a/pkg/ice/agent.go +++ b/pkg/ice/agent.go @@ -163,14 +163,14 @@ func (a *Agent) gatherCandidatesLocal() { for _, network := range supportedNetworks { conn, err := a.listenUDP(network, &net.UDPAddr{IP: ip, Port: 0}) if err != nil { - fmt.Printf("could not listen %s %s\n", network, ip) + iceLog.Warningf("could not listen %s %s\n", network, ip) continue } port := conn.LocalAddr().(*net.UDPAddr).Port c, err := NewCandidateHost(network, ip, port) if err != nil { - fmt.Printf("Failed to create host candidate: %s %s %d: %v\n", network, ip, port, err) + iceLog.Warningf("Failed to create host candidate: %s %s %d: %v\n", network, ip, port, err) continue } @@ -192,12 +192,12 @@ func (a *Agent) gatherCandidatesReflective(urls []*URL) { case SchemeTypeSTUN: laddr, xoraddr, err := allocateUDP(network, url) if err != nil { - fmt.Printf("could not allocate %s %s: %v\n", network, url, err) + iceLog.Warningf("could not allocate %s %s: %v\n", network, url, err) continue } conn, err := net.ListenUDP(network, laddr) if err != nil { - fmt.Printf("could not listen %s %s: %v\n", network, laddr, err) + iceLog.Warningf("could not listen %s %s: %v\n", network, laddr, err) } ip := xoraddr.IP @@ -206,7 +206,7 @@ func (a *Agent) gatherCandidatesReflective(urls []*URL) { relPort := laddr.Port c, err := NewCandidateServerReflexive(network, ip, port, relIP, relPort) if err != nil { - fmt.Printf("Failed to create server reflexive candidate: %s %s %d: %v\n", network, ip, port, err) + iceLog.Warningf("Failed to create server reflexive candidate: %s %s %d: %v\n", network, ip, port, err) continue } @@ -218,7 +218,7 @@ func (a *Agent) gatherCandidatesReflective(urls []*URL) { c.start(a, conn) default: - fmt.Printf("scheme %s is not implemented\n", url.Scheme.String()) + iceLog.Warningf("scheme %s is not implemented\n", url.Scheme) continue } } @@ -266,6 +266,7 @@ func (a *Agent) startConnectivityChecks(isControlling bool, remoteUfrag, remoteP } else if remotePwd == "" { return errors.Errorf("remotePwd is empty") } + iceLog.Debugf("Started agent: isControlling? %t, remoteUfrag: %q, remotePwd: %q", isControlling, remoteUfrag, remotePwd) return a.run(func(agent *Agent) { agent.isControlling = isControlling @@ -314,7 +315,7 @@ func (a *Agent) pingCandidate(local, remote *Candidate) { } if err != nil { - fmt.Println(err) + iceLog.Debug(err.Error()) return } @@ -335,6 +336,7 @@ func (a *Agent) updateConnectionState(newState ConnectionState) { func (a *Agent) setValidPair(local, remote *Candidate, selected bool) { // TODO: avoid duplicates p := newCandidatePair(local, remote) + iceLog.Debugf("Found valid candidate pair: %s <-> %s (selected? %t)", local, remote, selected) if selected { a.selectedPair = p @@ -374,8 +376,10 @@ func (a *Agent) taskLoop() { select { case <-a.connectivityChan: if a.validateSelectedPair() { + iceLog.Trace("checking keepalive") a.checkKeepalive() } else { + iceLog.Trace("pinging all candidates") a.pingAllCandidates() } @@ -490,7 +494,7 @@ func (a *Agent) Close() error { for _, c := range cs { err := c.close() if err != nil { - fmt.Printf("Failed to close candidate %s: %v", c, err) + iceLog.Warningf("Failed to close candidate %s: %v", c, err) } } delete(agent.localCandidates, net) @@ -499,7 +503,7 @@ func (a *Agent) Close() error { for _, c := range cs { err := c.close() if err != nil { - fmt.Printf("Failed to close candidate %s: %v", c, err) + iceLog.Warningf("Failed to close candidate %s: %v", c, err) } } delete(agent.remoteCandidates, net) @@ -526,7 +530,7 @@ func (a *Agent) findRemoteCandidate(networkType NetworkType, addr net.Addr) *Can ip = a.IP port = a.Port default: - fmt.Printf("unsupported address type %T", a) + iceLog.Warningf("unsupported address type %T", a) return nil } @@ -555,7 +559,7 @@ func (a *Agent) sendBindingSuccess(m *stun.Message, local, remote *Candidate) { }, &stun.Fingerprint{}, ); err != nil { - fmt.Printf("Failed to handle inbound ICE from: %s to: %s error: %s", local.String(), remote.String(), err.Error()) + iceLog.Warningf("Failed to handle inbound ICE from: %s to: %s error: %s", local, remote, err) } else { a.sendSTUN(out, local, remote) } @@ -563,12 +567,13 @@ func (a *Agent) sendBindingSuccess(m *stun.Message, local, remote *Candidate) { func (a *Agent) handleInboundControlled(m *stun.Message, localCandidate, remoteCandidate *Candidate) { if _, isControlled := m.GetOneAttribute(stun.AttrIceControlled); isControlled && !a.isControlling { - fmt.Println("inbound isControlled && a.isControlling == false") + iceLog.Debug("inbound isControlled && a.isControlling == false") return } successResponse := m.Method == stun.MethodBinding && m.Class == stun.ClassSuccessResponse _, usepair := m.GetOneAttribute(stun.AttrUseCandidate) + iceLog.Debugf("got controlled message (success? %t, usepair? %t)", successResponse, usepair) // Remember the working pair and select it when marked with usepair a.setValidPair(localCandidate, remoteCandidate, usepair) @@ -580,12 +585,13 @@ func (a *Agent) handleInboundControlled(m *stun.Message, localCandidate, remoteC func (a *Agent) handleInboundControlling(m *stun.Message, localCandidate, remoteCandidate *Candidate) { if _, isControlling := m.GetOneAttribute(stun.AttrIceControlling); isControlling && a.isControlling { - fmt.Println("inbound isControlling && a.isControlling == true") + iceLog.Debug("inbound isControlling && a.isControlling == true") return } else if _, useCandidate := m.GetOneAttribute(stun.AttrUseCandidate); useCandidate && a.isControlling { - fmt.Println("useCandidate && a.isControlling == true") + iceLog.Debug("useCandidate && a.isControlling == true") return } + iceLog.Debugf("got controlling message: %#v", m) successResponse := m.Method == stun.MethodBinding && m.Class == stun.ClassSuccessResponse // Remember the working pair and select it when receiving a success response @@ -604,8 +610,7 @@ func (a *Agent) handleInboundControlling(m *stun.Message, localCandidate, remote func (a *Agent) handleInbound(m *stun.Message, local *Candidate, remote net.Addr) { remoteCandidate := a.findRemoteCandidate(local.NetworkType, remote) if remoteCandidate == nil { - // TODO debug - // fmt.Printf("Could not find remote candidate for %s:%d ", remote.IP.String(), remote.Port) + iceLog.Debugf("Could not find remote candidate for %s ", remote) return } diff --git a/pkg/ice/candidate.go b/pkg/ice/candidate.go index 7a7f9b7eac..f647a45a2b 100644 --- a/pkg/ice/candidate.go +++ b/pkg/ice/candidate.go @@ -89,14 +89,14 @@ func (c *Candidate) recvLoop() { if stun.IsSTUN(buffer[:n]) { m, err := stun.NewMessage(buffer[:n]) if err != nil { - fmt.Println(fmt.Sprintf("Failed to handle decode ICE from %s to %s: %v", c.addr(), srcAddr, err)) + iceLog.Warningf("Failed to handle decode ICE from %s to %s: %v", c.addr(), srcAddr, err) continue } err = c.agent.run(func(agent *Agent) { agent.handleInbound(m, c, srcAddr) }) if err != nil { - fmt.Println(fmt.Sprintf("Failed to handle message: %v", err)) + iceLog.Warningf("Failed to handle message: %v", err) } continue diff --git a/pkg/ice/candidatepair.go b/pkg/ice/candidatepair.go index 2884974861..c274d9dad9 100644 --- a/pkg/ice/candidatepair.go +++ b/pkg/ice/candidatepair.go @@ -1,8 +1,6 @@ package ice import ( - "fmt" - "github.com/pions/pkg/stun" ) @@ -34,7 +32,7 @@ func (a *Agent) keepaliveCandidate(local, remote *Candidate) { ) if err != nil { - fmt.Println(err) + iceLog.Warning(err.Error()) return } @@ -44,10 +42,6 @@ func (a *Agent) keepaliveCandidate(local, remote *Candidate) { func (a *Agent) sendSTUN(msg *stun.Message, local, remote *Candidate) { _, err := local.writeTo(msg.Pack(), remote) if err != nil { - // TODO: Determine if we should always drop the err - // E.g.: maybe handle for known valid pairs or to - // discard pairs faster. - _ = err - // fmt.Printf("failed to send STUN message: %v", err) + iceLog.Warningf("failed to send STUN message: %s", err) } } diff --git a/pkg/ice/logging.go b/pkg/ice/logging.go new file mode 100644 index 0000000000..086cc335e7 --- /dev/null +++ b/pkg/ice/logging.go @@ -0,0 +1,5 @@ +package ice + +import "github.com/pions/webrtc/pkg/logging" + +var iceLog = logging.NewScopedLogger("ice") diff --git a/pkg/logging/leveled.go b/pkg/logging/leveled.go new file mode 100644 index 0000000000..377a3e675b --- /dev/null +++ b/pkg/logging/leveled.go @@ -0,0 +1,219 @@ +package logging + +import ( + "fmt" + "io" + "log" + "os" + "sync" + "sync/atomic" +) + +// LogLevel represents the level at which the logger will emit log messages +type LogLevel int32 + +// Set updates the LogLevel to the supplied value +func (ll *LogLevel) Set(newLevel LogLevel) { + atomic.StoreInt32((*int32)(ll), int32(newLevel)) +} + +// Get retrieves the current LogLevel value +func (ll *LogLevel) Get() LogLevel { + return LogLevel(atomic.LoadInt32((*int32)(ll))) +} + +const ( + // LogLevelDisabled completely disables logging of any events + LogLevelDisabled LogLevel = iota + // LogLevelError is for fatal errors which should be handled by user code, + // but are logged to ensure that they are seen + LogLevelError + // LogLevelWarning is for logging abnormal, but non-fatal library operation + LogLevelWarning + // LogLevelInfo is for logging normal library operation (e.g. state transitions, etc.) + LogLevelInfo + // LogLevelDebug is for logging low-level library information (e.g. internal operations) + LogLevelDebug + // LogLevelTrace is for logging very low-level library information (e.g. network traces) + LogLevelTrace +) + +// Use this abstraction to ensure thread-safe access to the logger's io.Writer +// (which could change at runtime) +type loggerWriter struct { + sync.RWMutex + output io.Writer +} + +func (lw *loggerWriter) SetOutput(output io.Writer) { + lw.Lock() + defer lw.Unlock() + lw.output = output +} + +func (lw *loggerWriter) Write(data []byte) (int, error) { + lw.RLock() + defer lw.RUnlock() + return lw.output.Write(data) +} + +// provide a package-level default destination that can be changed +// at runtime +var defaultWriter = &loggerWriter{ + output: os.Stdout, +} + +// SetDefaultWriter changes the default logging destination to the +// supplied io.Writer +func SetDefaultWriter(w io.Writer) { + defaultWriter.SetOutput(w) +} + +// LeveledLogger encapsulates functionality for providing logging at +// user-defined levels +type LeveledLogger struct { + level LogLevel + writer *loggerWriter + trace *log.Logger + debug *log.Logger + info *log.Logger + warn *log.Logger + err *log.Logger +} + +// WithTraceLogger is a chainable configuration function which sets the +// Trace-level logger +func (ll *LeveledLogger) WithTraceLogger(log *log.Logger) *LeveledLogger { + ll.trace = log + return ll +} + +// WithDebugLogger is a chainable configuration function which sets the +// Debug-level logger +func (ll *LeveledLogger) WithDebugLogger(log *log.Logger) *LeveledLogger { + ll.debug = log + return ll +} + +// WithInfoLogger is a chainable configuration function which sets the +// Info-level logger +func (ll *LeveledLogger) WithInfoLogger(log *log.Logger) *LeveledLogger { + ll.info = log + return ll +} + +// WithWarningLogger is a chainable configuration function which sets the +// Warning-level logger +func (ll *LeveledLogger) WithWarningLogger(log *log.Logger) *LeveledLogger { + ll.warn = log + return ll +} + +// WithErrorLogger is a chainable configuration function which sets the +// Error-level logger +func (ll *LeveledLogger) WithErrorLogger(log *log.Logger) *LeveledLogger { + ll.err = log + return ll +} + +// WithLogLevel is a chainable configuration function which sets the logger's +// logging level threshold, at or below which all messages will be logged +func (ll *LeveledLogger) WithLogLevel(level LogLevel) *LeveledLogger { + ll.level.Set(level) + return ll +} + +// WithOutput is a chainable configuration function which sets the logger's +// logging output to the supplied io.Writer +func (ll *LeveledLogger) WithOutput(output io.Writer) *LeveledLogger { + ll.writer.SetOutput(output) + return ll +} + +// SetLevel sets the logger's logging level +func (ll *LeveledLogger) SetLevel(newLevel LogLevel) { + ll.level.Set(newLevel) +} + +func (ll *LeveledLogger) logf(logger *log.Logger, level LogLevel, format string, args ...interface{}) { + if ll.level.Get() < level { + return + } + + callDepth := 3 // this frame + wrapper func + caller + msg := fmt.Sprintf(format, args...) + if err := logger.Output(callDepth, msg); err != nil { + fmt.Fprintf(os.Stderr, "Unable to log: %s", err) + } +} + +// Trace emits the preformatted message if the logger is at or below LogLevelTrace +func (ll *LeveledLogger) Trace(msg string) { + ll.logf(ll.trace, LogLevelTrace, msg) +} + +// Tracef formats and emits a message if the logger is at or below LogLevelTrace +func (ll *LeveledLogger) Tracef(format string, args ...interface{}) { + ll.logf(ll.trace, LogLevelTrace, format, args...) +} + +// Debug emits the preformatted message if the logger is at or below LogLevelDebug +func (ll *LeveledLogger) Debug(msg string) { + ll.logf(ll.debug, LogLevelDebug, msg) +} + +// Debugf formats and emits a message if the logger is at or below LogLevelDebug +func (ll *LeveledLogger) Debugf(format string, args ...interface{}) { + ll.logf(ll.debug, LogLevelDebug, format, args...) +} + +// Info emits the preformatted message if the logger is at or below LogLevelInfo +func (ll *LeveledLogger) Info(msg string) { + ll.logf(ll.info, LogLevelInfo, msg) +} + +// Infof formats and emits a message if the logger is at or below LogLevelInfo +func (ll *LeveledLogger) Infof(format string, args ...interface{}) { + ll.logf(ll.info, LogLevelInfo, format, args...) +} + +// Warning emits the preformatted message if the logger is at or below LogLevelWarning +func (ll *LeveledLogger) Warning(msg string) { + ll.logf(ll.warn, LogLevelWarning, msg) +} + +// Warningf formats and emits a message if the logger is at or below LogLevelWarning +func (ll *LeveledLogger) Warningf(format string, args ...interface{}) { + ll.logf(ll.warn, LogLevelWarning, format, args...) +} + +// Error emits the preformatted message if the logger is at or below LogLevelError +func (ll *LeveledLogger) Error(msg string) { + ll.logf(ll.err, LogLevelError, msg) +} + +// Errorf formats and emits a message if the logger is at or below LogLevelError +func (ll *LeveledLogger) Errorf(format string, args ...interface{}) { + ll.logf(ll.err, LogLevelError, format, args...) +} + +// NewLeveledLogger returns a configured *LeveledLogger +func NewLeveledLogger() *LeveledLogger { + return NewLeveledLoggerForScope("PIONS") +} + +// NewLeveledLoggerForScope returns a configured *LeveledLogger for the given scope +func NewLeveledLoggerForScope(scope string) *LeveledLogger { + logger := &LeveledLogger{ + writer: &loggerWriter{ + output: defaultWriter, + }, + level: LogLevelError, // TODO: Should this be the default? Or disabled? + } + return logger. + WithTraceLogger(log.New(logger.writer, fmt.Sprintf("%s TRACE: ", scope), log.Lmicroseconds|log.Lshortfile)). + WithDebugLogger(log.New(logger.writer, fmt.Sprintf("%s DEBUG: ", scope), log.Lmicroseconds|log.Lshortfile)). + WithInfoLogger(log.New(logger.writer, fmt.Sprintf("%s INFO: ", scope), log.LstdFlags)). + WithWarningLogger(log.New(logger.writer, fmt.Sprintf("%s WARNING: ", scope), log.LstdFlags)). + WithErrorLogger(log.New(logger.writer, fmt.Sprintf("%s ERROR: ", scope), log.LstdFlags)) +} diff --git a/pkg/logging/logging_test.go b/pkg/logging/logging_test.go new file mode 100644 index 0000000000..8a5541efe1 --- /dev/null +++ b/pkg/logging/logging_test.go @@ -0,0 +1,56 @@ +package logging_test + +import ( + "bytes" + "strings" + "testing" + + "github.com/pions/webrtc/pkg/logging" +) + +func TestScopedLogger(t *testing.T) { + var outBuf bytes.Buffer + logger := logging.NewScopedLogger("test1"). + WithOutput(&outBuf). + WithLogLevel(logging.LogLevelWarning) + + logger.Debug("this shouldn't be logged") + if outBuf.Len() > 0 { + t.Error("Debug was logged when it shouldn't have been") + } + + warnMsg := "this is a warning message" + logger.Warning(warnMsg) + if !strings.Contains(outBuf.String(), warnMsg) { + t.Errorf("Expected to find %q in %q, but didn't", warnMsg, outBuf.String()) + } + + errMsg := "this is an error message" + logger.Error(errMsg) + if !strings.Contains(outBuf.String(), errMsg) { + t.Errorf("Expected to find %q in %q, but didn't", errMsg, outBuf.String()) + } +} + +func TestPackageLevelSettings(t *testing.T) { + var outBuf bytes.Buffer + logger := logging.NewScopedLogger("test2") + + // set the package-level writer + logging.SetDefaultWriter(&outBuf) + + traceMsg := "this is a trace messages" + logger.Trace(traceMsg) + + if outBuf.Len() > 0 { + t.Error("Trace was logged when it shouldn't have been") + } + + // set the logging scope via package + logging.SetLogLevelForScope("test2", logging.LogLevelTrace) + + logger.Trace(traceMsg) + if !strings.Contains(outBuf.String(), traceMsg) { + t.Errorf("Expected to find %q in %q, but didn't", traceMsg, outBuf.String()) + } +} diff --git a/pkg/logging/scoped.go b/pkg/logging/scoped.go new file mode 100644 index 0000000000..797c417102 --- /dev/null +++ b/pkg/logging/scoped.go @@ -0,0 +1,105 @@ +package logging + +import ( + "fmt" + "os" + "strings" + "sync" +) + +type loggerRegistry struct { + sync.RWMutex + scopeLoggers map[string]*LeveledLogger + scopeLevels map[string]LogLevel +} + +var ( + registry = &loggerRegistry{ + scopeLoggers: make(map[string]*LeveledLogger), + scopeLevels: make(map[string]LogLevel), + } +) + +// SetLogLevelForScope sets the logging level for the given +// scope, or all scopes if "all" is provided. If a logger +// for the scope does not yet exist, the desired logging +// level is recorded and applied when the scoped logger +// is created. +func SetLogLevelForScope(scope string, level LogLevel) { + registry.Lock() + defer registry.Unlock() + + scope = strings.ToLower(scope) + registry.scopeLevels[scope] = level + + if scope == "all" { + for _, logger := range registry.scopeLoggers { + logger.SetLevel(level) + } + return + } + + if logger, found := registry.scopeLoggers[scope]; found { + logger.SetLevel(level) + } +} + +// NewScopedLogger returns a predefined logger for the given logging scope +// NB: Can be used idempotently +func NewScopedLogger(scope string) *LeveledLogger { + registry.Lock() + defer registry.Unlock() + + scope = strings.ToLower(scope) + if _, found := registry.scopeLoggers[scope]; !found { + registry.scopeLoggers[scope] = NewLeveledLoggerForScope(scope) + + // Handle a logger being created after init() is run + level := LogLevelDisabled + if allLevel, found := registry.scopeLevels["all"]; found { + level = allLevel + } + if scopeLevel, found := registry.scopeLevels[scope]; found { + if scopeLevel > level { + level = scopeLevel + } + } + if level > LogLevelDisabled { + registry.scopeLoggers[scope].SetLevel(level) + } + } + return registry.scopeLoggers[scope] +} + +func init() { + logLevels := map[string]LogLevel{ + "ERROR": LogLevelError, + "WARNING": LogLevelWarning, + "INFO": LogLevelInfo, + "DEBUG": LogLevelDebug, + "TRACE": LogLevelTrace, + } + + for name, level := range logLevels { + env := os.Getenv(fmt.Sprintf("PIONS_LOG_%s", name)) + if env == "" { + continue + } + + if strings.ToLower(env) == "all" { + for _, logger := range registry.scopeLoggers { + logger.SetLevel(level) + } + registry.scopeLevels["all"] = level + continue + } + + scopes := strings.Split(strings.ToLower(env), ",") + for _, scope := range scopes { + registry.scopeLevels[scope] = level + if logger, found := registry.scopeLoggers[strings.TrimSpace(scope)]; found { + logger.SetLevel(level) + } + } + } +} diff --git a/rtcpeerconnection.go b/rtcpeerconnection.go index 09b6f4380a..23bbc5dc53 100644 --- a/rtcpeerconnection.go +++ b/rtcpeerconnection.go @@ -17,6 +17,7 @@ import ( "github.com/pions/sdp" "github.com/pions/webrtc/internal/network" "github.com/pions/webrtc/pkg/ice" + "github.com/pions/webrtc/pkg/logging" "github.com/pions/webrtc/pkg/media" "github.com/pions/webrtc/pkg/rtcerr" "github.com/pions/webrtc/pkg/rtcp" @@ -24,6 +25,8 @@ import ( "github.com/pkg/errors" ) +var pcLog = logging.NewScopedLogger("pc") + // Unknown defines default public constant to use for "enum" like struct // comparisons when no value was defined. const Unknown = iota @@ -237,6 +240,7 @@ func (pc *RTCPeerConnection) onSignalingStateChange(newState RTCSignalingState) hdlr := pc.onSignalingStateChangeHandler pc.RUnlock() + pcLog.Infof("signaling state changed to %s", newState) done = make(chan struct{}) if hdlr == nil { close(done) @@ -264,6 +268,7 @@ func (pc *RTCPeerConnection) onDataChannel(dc *RTCDataChannel) (done chan struct hdlr := pc.onDataChannelHandler pc.RUnlock() + pcLog.Debugf("got new datachannel: %+v", dc) done = make(chan struct{}) if hdlr == nil || dc == nil { close(done) @@ -293,6 +298,7 @@ func (pc *RTCPeerConnection) onTrack(t *RTCTrack) (done chan struct{}) { hdlr := pc.onTrackHandler pc.RUnlock() + pcLog.Debugf("got new track: %+v", t) done = make(chan struct{}) if hdlr == nil || t == nil { close(done) @@ -320,6 +326,7 @@ func (pc *RTCPeerConnection) onICEConnectionStateChange(cs ice.ConnectionState) hdlr := pc.onICEConnectionStateChangeHandler pc.RUnlock() + pcLog.Infof("ICE connection state changed: %s", cs) done = make(chan struct{}) if hdlr == nil { close(done) @@ -742,7 +749,7 @@ func (pc *RTCPeerConnection) SetRemoteDescription(desc RTCSessionDescription) er remoteUfrag, remotePwd, cert.x509Cert, cert.privateKey, fingerprint, fingerprintHash) if err != nil { - fmt.Println("Failed to start manager", err) + pcLog.Warningf("Failed to start manager: %s", err) } // Temporary data channel glue @@ -768,7 +775,7 @@ func (pc *RTCPeerConnection) openDataChannels() { Label: rtcDC.Label, }) if err != nil { - fmt.Println("failed to open data channel", err) + pcLog.Warningf("failed to open data channel: %s", err) continue } rtcDC.ReadyState = RTCDataChannelStateOpen @@ -782,7 +789,7 @@ func (pc *RTCPeerConnection) acceptDataChannels() { for { dc, err := pc.networkManager.AcceptDataChannel() if err != nil { - fmt.Println("Failed to accept data channel:", err) + pcLog.Warningf("Failed to accept data channel: %s", err) // TODO: Kill DataChannel/PeerConnection? return } @@ -1109,13 +1116,13 @@ func (pc *RTCPeerConnection) generateChannel(ssrc uint32, payloadType uint8) (tp sdpCodec, err := pc.CurrentLocalDescription.parsed.GetCodecForPayloadType(payloadType) if err != nil { - fmt.Printf("No codec could be found in RemoteDescription for payloadType %d \n", payloadType) + pcLog.Warningf("No codec could be found in RemoteDescription for payloadType %d \n", payloadType) return nil } codec, err := pc.mediaEngine.getCodecSDP(sdpCodec) if err != nil { - fmt.Printf("Codec %s in not registered\n", sdpCodec) + pcLog.Warningf("Codec %s in not registered\n", sdpCodec) return nil }