Reduced log verbosity for pieces that are stable (#1274)

This commit is contained in:
David Zhao
2022-12-29 23:47:36 -08:00
committed by GitHub
parent fe6234329d
commit 112d6fc18b
8 changed files with 37 additions and 26 deletions

View File

@@ -448,7 +448,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
@@ -462,7 +462,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
@@ -476,7 +476,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{
@@ -937,14 +937,14 @@ func (p *ParticipantImpl) AddSubscribedTrack(subTrack types.SubscribedTrack, sou
if v, ok := p.trackPublisherVersion[subTrack.ID()]; ok && v > subTrack.PublisherVersion() {
p.supervisor.SetSubscribedTrack(subTrack.ID(), subTrack, sourceTrack)
p.lock.Unlock()
p.params.Logger.Infow("ignoring add subscribedTrack from older version",
p.params.Logger.Debugw("ignoring add subscribedTrack from older version",
"current", v,
"requesting", subTrack.PublisherVersion(),
"trackID", subTrack.ID(),
)
return
}
p.params.Logger.Infow("added subscribedTrack",
p.params.Logger.Debugw("added subscribedTrack",
"publisherID", subTrack.PublisherID(),
"publisherIdentity", subTrack.PublisherIdentity(),
"trackID", subTrack.ID())
@@ -985,14 +985,14 @@ func (p *ParticipantImpl) RemoveSubscribedTrack(subTrack types.SubscribedTrack,
if v, ok := p.trackPublisherVersion[subTrack.ID()]; ok && v > subTrack.PublisherVersion() {
p.supervisor.ClearSubscribedTrack(subTrack.ID(), subTrack, sourceTrack)
p.lock.Unlock()
p.params.Logger.Infow("ignoring remove subscribedTrack from older version",
p.params.Logger.Debugw("ignoring remove subscribedTrack from older version",
"current", v,
"requesting", subTrack.PublisherVersion(),
"trackID", subTrack.ID(),
)
return
}
p.params.Logger.Infow("removed subscribedTrack",
p.params.Logger.Debugw("removed subscribedTrack",
"publisherID", subTrack.PublisherID(),
"publisherIdentity", subTrack.PublisherIdentity(),
"trackID", subTrack.ID(), "kind", subTrack.DownTrack().Kind())
@@ -1198,7 +1198,7 @@ func (p *ParticipantImpl) updateState(state livekit.ParticipantInfo_State) {
// 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),

View File

@@ -57,8 +57,6 @@ func HandleParticipantSignal(room types.Room, participant types.LocalParticipant
pLogger.Errorw("failed to update subscribed track settings", err, "trackID", sid)
continue
}
pLogger.Infow("updated subscribed track settings", "trackID", sid, "settings", msg.TrackSetting)
}
case *livekit.SignalRequest_Leave:
pLogger.Infow("client leaving room")

View File

@@ -8,6 +8,7 @@ import (
"go.uber.org/atomic"
"github.com/livekit/protocol/livekit"
"github.com/livekit/protocol/logger"
"github.com/livekit/livekit-server/pkg/rtc/types"
"github.com/livekit/livekit-server/pkg/sfu"
@@ -32,7 +33,8 @@ type SubscribedTrack struct {
params SubscribedTrackParams
subMuted atomic.Bool
pubMuted atomic.Bool
settings atomic.Value // *livekit.UpdateTrackSettings
settings atomic.Pointer[livekit.UpdateTrackSettings]
logger logger.Logger
onBind atomic.Value // func()
bound atomic.Bool
@@ -42,7 +44,12 @@ type SubscribedTrack struct {
func NewSubscribedTrack(params SubscribedTrackParams) *SubscribedTrack {
s := &SubscribedTrack{
params: params,
params: params,
logger: params.Subscriber.GetLogger().WithValues(
"trackID", params.DownTrack.ID(),
"publisherID", params.PublisherID,
"publisher", params.PublisherIdentity,
),
debouncer: debounce.New(subscriptionDebounceInterval),
}
@@ -120,6 +127,11 @@ func (t *SubscribedTrack) SetPublisherMuted(muted bool) {
func (t *SubscribedTrack) UpdateSubscriberSettings(settings *livekit.UpdateTrackSettings) {
prevDisabled := t.subMuted.Swap(settings.Disabled)
t.settings.Store(settings)
if prevDisabled != settings.Disabled {
t.logger.Infow("updated subscribed track enabled", "enabled", !settings.Disabled)
}
// avoid frequent changes to mute & video layers, unless it became visible
if prevDisabled != settings.Disabled && !settings.Disabled {
t.UpdateVideoLayer()
@@ -133,13 +145,16 @@ func (t *SubscribedTrack) UpdateVideoLayer() {
if t.DownTrack().Kind() != webrtc.RTPCodecTypeVideo {
return
}
t.Subscriber().GetLogger().Debugw("updating video layer")
settings, ok := t.settings.Load().(*livekit.UpdateTrackSettings)
if !ok {
settings := t.settings.Load()
if settings == nil {
return
}
t.logger.Debugw("updating video layer",
"settings", settings,
)
quality := settings.Quality
if settings.Width > 0 {
quality = t.MediaTrack().GetQualityForDimension(settings.Width, settings.Height)

View File

@@ -1365,7 +1365,7 @@ func (t *PCTransport) handleRemoteICECandidate(e *event) error {
}
func (t *PCTransport) handleLogICECandidates(e *event) error {
t.params.Logger.Infow(
t.params.Logger.Debugw(
"ice candidates",
"lc", t.allowedLocalCandidates,
"rc", t.allowedRemoteCandidates,

View File

@@ -123,10 +123,8 @@ func (u *UpTrackManager) AddSubscriber(sub types.LocalParticipant, params types.
for _, track := range tracks {
trackIDs = append(trackIDs, track.ID())
}
u.params.Logger.Debugw("subscribing participant to tracks",
"subscriber", sub.Identity(),
"subscriberID", sub.ID(),
"trackIDs", trackIDs)
sub.GetLogger().Debugw("subscribing to tracks",
"trackID", trackIDs)
n := 0
for _, track := range tracks {

View File

@@ -258,7 +258,7 @@ func (r *RoomManager) StartSession(
return errors.New("could not restart participant")
}
logger.Infow("starting RTC session",
logger.Debugw("starting RTC session",
"room", roomName,
"nodeID", r.currentNode.Id,
"participant", pi.Identity,
@@ -456,7 +456,7 @@ func (r *RoomManager) getOrCreateRoom(ctx context.Context, roomName livekit.Room
// manages an RTC session for a participant, runs on the RTC node
func (r *RoomManager) rtcSessionWorker(room *rtc.Room, participant types.LocalParticipant, requestSource routing.MessageSource) {
defer func() {
logger.Infow("RTC session finishing",
logger.Debugw("RTC session finishing",
"participant", participant.Identity(),
"pID", participant.ID(),
"room", room.Name(),

View File

@@ -689,7 +689,7 @@ func (d *DownTrack) CloseWithFlush(flush bool) {
}
d.bindLock.Lock()
d.logger.Infow("close down track", "flushBlankFrame", flush)
d.logger.Debugw("close down track", "flushBlankFrame", flush)
if d.bound.Load() {
if d.forwarder != nil {
d.forwarder.Mute(true)
@@ -717,7 +717,7 @@ func (d *DownTrack) CloseWithFlush(flush bool) {
d.receiver.DeleteDownTrack(d.subscriberID)
if d.rtcpReader != nil {
logger.Infow("downtrack close rtcp reader")
logger.Debugw("downtrack close rtcp reader")
d.rtcpReader.Close()
d.rtcpReader.OnPacket(nil)
}

View File

@@ -302,7 +302,7 @@ func (f *Forwarder) Mute(muted bool) (bool, VideoLayers) {
return false, f.maxLayers
}
f.logger.Infow("setting forwarder mute", "muted", muted)
f.logger.Debugw("setting forwarder mute", "muted", muted)
f.muted = muted
// resync when muted so that sequence numbers do not jump on unmute
@@ -1271,7 +1271,7 @@ func (f *Forwarder) updateAllocation(alloc VideoAllocation, reason string) Video
}
if alloc.state != f.lastAllocation.state || alloc.targetLayers != f.lastAllocation.targetLayers {
f.logger.Infow(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc)
f.logger.Debugw(fmt.Sprintf("stream allocation: %s", reason), "allocation", alloc)
}
f.lastAllocation = alloc