From 281d2b674b12dde2c9a8a34aaf7efc0397f2b759 Mon Sep 17 00:00:00 2001 From: Raja Subramanian Date: Wed, 20 Sep 2023 14:13:48 +0530 Subject: [PATCH] Changing some log levels (#2094) Logging expected WS close at Infow to understand reasons for closure. Moving "read from ws" to Debugw as it happens when signalling closes. Also filter out a data channel abort chunk log as it shows a bunch of errors, but those are expected though. --- pkg/rtc/participant.go | 14 ++++++-------- pkg/rtc/room.go | 1 - pkg/rtc/transport.go | 2 +- pkg/service/rtcservice.go | 16 ++++++++-------- 4 files changed, 15 insertions(+), 18 deletions(-) diff --git a/pkg/rtc/participant.go b/pkg/rtc/participant.go index 07ae3036b..30dfea7d0 100644 --- a/pkg/rtc/participant.go +++ b/pkg/rtc/participant.go @@ -561,10 +561,9 @@ func (p *ParticipantImpl) HandleSignalSourceClose() { p.TransportManager.SetSignalSourceValid(false) if !p.TransportManager.HasPublisherEverConnected() && !p.TransportManager.HasSubscriberEverConnected() { - p.params.Logger.Infow("closing disconnected participant", - "reason", types.ParticipantCloseReasonJoinFailed, - ) - _ = p.Close(false, types.ParticipantCloseReasonJoinFailed, false) + reason := types.ParticipantCloseReasonJoinFailed + p.params.Logger.Infow("closing disconnected participant", "reason", reason) + _ = p.Close(false, reason, false) } } @@ -1404,10 +1403,9 @@ func (p *ParticipantImpl) setupDisconnectTimer() { if p.IsClosed() || p.IsDisconnected() { return } - p.params.Logger.Infow("closing disconnected participant", - "reason", types.ParticipantCloseReasonPeerConnectionDisconnected, - ) - _ = p.Close(true, types.ParticipantCloseReasonPeerConnectionDisconnected, false) + reason := types.ParticipantCloseReasonPeerConnectionDisconnected + p.params.Logger.Infow("closing disconnected participant", "reason", reason) + _ = p.Close(true, reason, false) }) p.lock.Unlock() } diff --git a/pkg/rtc/room.go b/pkg/rtc/room.go index cbc1cf54c..7d28fd0be 100644 --- a/pkg/rtc/room.go +++ b/pkg/rtc/room.go @@ -426,7 +426,6 @@ func (r *Room) ReplaceParticipantRequestSource(identity livekit.ParticipantIdent rs.Close() } r.participantRequestSources[identity] = reqSource - r.lock.Unlock() } diff --git a/pkg/rtc/transport.go b/pkg/rtc/transport.go index 33ba7ade2..517c90c1f 100644 --- a/pkg/rtc/transport.go +++ b/pkg/rtc/transport.go @@ -832,7 +832,7 @@ func (t *PCTransport) CreateDataChannel(label string, dci *webrtc.DataChannelIni } dcErrorHandler := func(err error) { - if !errors.Is(err, sctp.ErrResetPacketInStateNotExist) { + if !errors.Is(err, sctp.ErrResetPacketInStateNotExist) && !errors.Is(err, sctp.ErrChunk) { t.params.Logger.Errorw(dc.Label()+" data channel error", err) } } diff --git a/pkg/service/rtcservice.go b/pkg/service/rtcservice.go index ab49ba24a..dc203fec9 100644 --- a/pkg/service/rtcservice.go +++ b/pkg/service/rtcservice.go @@ -257,7 +257,7 @@ func (s *RTCService) ServeHTTP(w http.ResponseWriter, r *http.Request) { ) done := make(chan struct{}) - // function exits when websocket terminates, it'll close the event reading off of response sink as well + // function exits when websocket terminates, it'll close the event reading off of request sink and response source as well defer func() { pLogger.Infow("finishing WS connection", "connID", cr.ConnectionID) cr.ResponseSource.Close() @@ -288,13 +288,13 @@ func (s *RTCService) ServeHTTP(w http.ResponseWriter, r *http.Request) { // websocket established sigConn := NewWSSignalConnection(conn) - if count, err := sigConn.WriteResponse(initialResponse); err != nil { + count, err := sigConn.WriteResponse(initialResponse) + if err != nil { pLogger.Warnw("could not write initial response", err) return - } else { - if signalStats != nil { - signalStats.AddBytes(uint64(count), true) - } + } + if signalStats != nil { + signalStats.AddBytes(uint64(count), true) } pLogger.Infow("new client WS connected", "connID", cr.ConnectionID, @@ -321,7 +321,7 @@ func (s *RTCService) ServeHTTP(w http.ResponseWriter, r *http.Request) { return case msg := <-cr.ResponseSource.ReadChan(): if msg == nil { - pLogger.Infow("nothing to read from response source", "connID", cr.ConnectionID) + pLogger.Debugw("nothing to read from response source", "connID", cr.ConnectionID) return } res, ok := msg.(*livekit.SignalResponse) @@ -372,7 +372,7 @@ func (s *RTCService) ServeHTTP(w http.ResponseWriter, r *http.Request) { websocket.CloseNormalClosure, websocket.CloseNoStatusReceived, ) { - pLogger.Debugw("exit ws read loop for closed connection", "connID", cr.ConnectionID, "wsError", err) + pLogger.Infow("exit ws read loop for closed connection", "connID", cr.ConnectionID, "wsError", err) } else { pLogger.Errorw("error reading from websocket", err, "connID", cr.ConnectionID) }