diff --git a/pkg/rtc/participant.go b/pkg/rtc/participant.go index 101eeecac..f2b7892d0 100644 --- a/pkg/rtc/participant.go +++ b/pkg/rtc/participant.go @@ -480,7 +480,7 @@ func (p *ParticipantImpl) OnClaimsChanged(callback func(types.LocalParticipant)) // HandleOffer an offer from remote participant, used when clients make the initial connection func (p *ParticipantImpl) HandleOffer(offer webrtc.SessionDescription) { - p.params.Logger.Infow("received offer", "transport", livekit.SignalTarget_PUBLISHER) + p.params.Logger.Debugw("received offer", "transport", livekit.SignalTarget_PUBLISHER) shouldPend := false if p.MigrateState() == types.MigrateStateInit { shouldPend = true @@ -494,7 +494,7 @@ func (p *ParticipantImpl) HandleOffer(offer webrtc.SessionDescription) { // HandleAnswer handles a client answer response, with subscriber PC, server initiates the // offer and client answers func (p *ParticipantImpl) HandleAnswer(answer webrtc.SessionDescription) { - p.params.Logger.Infow("received answer", "transport", livekit.SignalTarget_SUBSCRIBER) + p.params.Logger.Debugw("received answer", "transport", livekit.SignalTarget_SUBSCRIBER) /* from server received join request to client answer * 1. server send join response & offer @@ -508,7 +508,7 @@ func (p *ParticipantImpl) HandleAnswer(answer webrtc.SessionDescription) { } func (p *ParticipantImpl) onPublisherAnswer(answer webrtc.SessionDescription) error { - p.params.Logger.Infow("sending answer", "transport", livekit.SignalTarget_PUBLISHER) + p.params.Logger.Debugw("sending answer", "transport", livekit.SignalTarget_PUBLISHER) answer = p.configurePublisherAnswer(answer) if err := p.writeMessage(&livekit.SignalResponse{ Message: &livekit.SignalResponse_Answer{ @@ -1121,7 +1121,7 @@ func (p *ParticipantImpl) setIsPublisher(isPublisher bool) { // when the server has an offer for participant func (p *ParticipantImpl) onSubscriberOffer(offer webrtc.SessionDescription) error { - p.params.Logger.Infow("sending offer", "transport", livekit.SignalTarget_SUBSCRIBER) + p.params.Logger.Debugw("sending offer", "transport", livekit.SignalTarget_SUBSCRIBER) return p.writeMessage(&livekit.SignalResponse{ Message: &livekit.SignalResponse_Offer{ Offer: ToProtoSessionDescription(offer), @@ -1894,7 +1894,7 @@ func (p *ParticipantImpl) publisherRTCPWorker() { // read from rtcpChan for pkts := range p.rtcpCh { if pkts == nil { - p.params.Logger.Infow("exiting publisher RTCP worker") + p.params.Logger.Debugw("exiting publisher RTCP worker") return } diff --git a/pkg/rtc/participant_signal.go b/pkg/rtc/participant_signal.go index 60c5e4e79..cc1c0ea62 100644 --- a/pkg/rtc/participant_signal.go +++ b/pkg/rtc/participant_signal.go @@ -265,7 +265,7 @@ func (p *ParticipantImpl) writeMessage(msg *livekit.SignalResponse) error { sink := p.getResponseSink() if sink == nil { - p.params.Logger.Infow("could not send message to participant", "messageType", fmt.Sprintf("%T", msg.Message)) + p.params.Logger.Debugw("could not send message to participant", "messageType", fmt.Sprintf("%T", msg.Message)) return nil } diff --git a/pkg/rtc/uptrackmanager.go b/pkg/rtc/uptrackmanager.go index 93309a83a..76c380a5b 100644 --- a/pkg/rtc/uptrackmanager.go +++ b/pkg/rtc/uptrackmanager.go @@ -145,7 +145,7 @@ func (u *UpTrackManager) UpdateSubscriptionPermission( if u.subscriptionPermission != nil { perms = u.subscriptionPermission.String() } - u.params.Logger.Infow( + u.params.Logger.Debugw( "skipping older subscription permission version", "existingValue", perms, "existingVersion", u.subscriptionPermissionVersion.ToProto().String(), diff --git a/pkg/sfu/buffer/fps.go b/pkg/sfu/buffer/fps.go index 6efffe682..c44efc559 100644 --- a/pkg/sfu/buffer/fps.go +++ b/pkg/sfu/buffer/fps.go @@ -222,7 +222,7 @@ func (f *FrameRateCalculatorDD) RecvPacket(ep *ExtPacket) bool { } if ep.DependencyDescriptor == nil { - f.logger.Infow("dependency descriptor is nil") + f.logger.Debugw("dependency descriptor is nil") return false } diff --git a/pkg/sfu/buffer/rtpstats.go b/pkg/sfu/buffer/rtpstats.go index 8a68a1232..2a59a1c44 100644 --- a/pkg/sfu/buffer/rtpstats.go +++ b/pkg/sfu/buffer/rtpstats.go @@ -21,7 +21,7 @@ const ( FirstSnapshotId = 1 SnInfoSize = 2048 SnInfoMask = SnInfoSize - 1 - TooLargeOWD = 400 * time.Millisecond + TooLargeOWDDelta = 400 * time.Millisecond ) type RTPFlowState struct { @@ -704,8 +704,8 @@ func (r *RTPStats) SetRtcpSenderReportData(srData *RTCPSenderReportData) { owd := srData.ArrivalTime.Sub(srData.NTPTimestamp.Time()) if r.srDataExt != nil { prevOwd := r.srDataExt.SenderReportData.ArrivalTime.Sub(r.srDataExt.SenderReportData.NTPTimestamp.Time()) - if time.Duration(math.Abs(float64(owd)-float64(prevOwd))) > TooLargeOWD { - r.logger.Infow("large one-way-delay", "owd", owd, "prevOwd", prevOwd) + if time.Duration(math.Abs(float64(owd)-float64(prevOwd))) > TooLargeOWDDelta { + r.logger.Debugw("large delta in one-way-delay", "owd", owd, "prevOwd", prevOwd) } } @@ -756,7 +756,7 @@ func (r *RTPStats) GetRtcpSenderReport(ssrc uint32, srDataExt *RTCPSenderReportD smoothedLocalTimeOfLatestSenderReportNTP := srDataExt.SenderReportData.NTPTimestamp.Time().Add(srDataExt.SmoothedOWD) if smoothedLocalTimeOfLatestSenderReportNTP.After(now) { - r.logger.Infow("smoothed time of NTP is ahead", + r.logger.Debugw("smoothed time of NTP is ahead", "now", now, "smoothed", smoothedLocalTimeOfLatestSenderReportNTP, "diff", smoothedLocalTimeOfLatestSenderReportNTP.Sub(now), diff --git a/pkg/sfu/forwarder.go b/pkg/sfu/forwarder.go index c5dd4df47..296f5be3b 100644 --- a/pkg/sfu/forwarder.go +++ b/pkg/sfu/forwarder.go @@ -252,7 +252,7 @@ func (f *Forwarder) SetMaxPublishedLayer(maxPublishedLayer int32) { } f.maxPublishedLayer = maxPublishedLayer - f.logger.Infow("setting max published layer", "maxPublishedLayer", f.maxPublishedLayer) + f.logger.Debugw("setting max published layer", "maxPublishedLayer", f.maxPublishedLayer) } func (f *Forwarder) SetMaxTemporalLayerSeen(maxTemporalLayerSeen int32) { @@ -264,7 +264,7 @@ func (f *Forwarder) SetMaxTemporalLayerSeen(maxTemporalLayerSeen int32) { } f.maxTemporalLayerSeen = maxTemporalLayerSeen - f.logger.Infow("setting max temporal layer seen", "maxTemporalLayerSeen", f.maxTemporalLayerSeen) + f.logger.Debugw("setting max temporal layer seen", "maxTemporalLayerSeen", f.maxTemporalLayerSeen) } func (f *Forwarder) OnParkedLayersExpired(fn func()) { @@ -414,7 +414,7 @@ func (f *Forwarder) SetMaxSpatialLayer(spatialLayer int32) (bool, VideoLayers, V return false, f.maxLayers, f.currentLayers } - f.logger.Infow("setting max spatial layer", "layer", spatialLayer) + f.logger.Debugw("setting max spatial layer", "layer", spatialLayer) f.maxLayers.Spatial = spatialLayer f.clearParkedLayers() @@ -430,7 +430,7 @@ func (f *Forwarder) SetMaxTemporalLayer(temporalLayer int32) (bool, VideoLayers, return false, f.maxLayers, f.currentLayers } - f.logger.Infow("setting max temporal layer", "layer", temporalLayer) + f.logger.Debugw("setting max temporal layer", "layer", temporalLayer) f.maxLayers.Temporal = temporalLayer f.clearParkedLayers() @@ -1269,7 +1269,11 @@ func (f *Forwarder) updateAllocation(alloc VideoAllocation, reason string) Video alloc.pauseReason != f.lastAllocation.pauseReason || alloc.targetLayers != f.lastAllocation.targetLayers || alloc.requestLayerSpatial != f.lastAllocation.requestLayerSpatial { - f.logger.Infow(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc) + if reason == "optimal" { + f.logger.Debugw(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc) + } else { + f.logger.Infow(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc) + } } f.lastAllocation = alloc @@ -1416,11 +1420,11 @@ func (f *Forwarder) getTranslationParamsCommon(extPkt *buffer.ExtPacket, layer i last := f.rtpMunger.GetLast() td = refTS - last.LastTS if td == 0 || td > (1<<31) { - f.logger.Infow("reference timestamp out-of-order, using default", "lastTS", last.LastTS, "refTS", refTS, "td", int32(td)) + f.logger.Debugw("reference timestamp out-of-order, using default", "lastTS", last.LastTS, "refTS", refTS, "td", int32(td)) td = 1 } } else { - f.logger.Infow("reference timestamp get error, using default", "error", err) + f.logger.Debugw("reference timestamp get error, using default", "error", err) } } diff --git a/pkg/sfu/streamtrackermanager.go b/pkg/sfu/streamtrackermanager.go index d04b03a54..b2d1f894a 100644 --- a/pkg/sfu/streamtrackermanager.go +++ b/pkg/sfu/streamtrackermanager.go @@ -409,7 +409,7 @@ func (s *StreamTrackerManager) addAvailableLayer(layer int32) { // check if new layer is the max layer isMaxLayerChange := s.availableLayers[len(s.availableLayers)-1] == layer - s.logger.Infow( + s.logger.Debugw( "available layers changed - layer seen", "added", layer, "availableLayers", s.availableLayers, @@ -441,7 +441,7 @@ func (s *StreamTrackerManager) removeAvailableLayer(layer int32) { sort.Slice(newLayers, func(i, j int) bool { return newLayers[i] < newLayers[j] }) s.availableLayers = newLayers - s.logger.Infow( + s.logger.Debugw( "available layers changed - layer gone", "removed", layer, "availableLayers", newLayers,