Use trackID consistently as log key (#491)

* Use trackID consistently as log key

* more useful logging for track published

pkg/rtc/participant.go

@@ -857,7 +857,7 @@ func (p *ParticipantImpl) AddSubscribedTrack(subTrack types.SubscribedTrack) {
 	p.params.Logger.Debugw("added subscribedTrack",
 		"publisherID", subTrack.PublisherID(),
 		"publisherIdentity", subTrack.PublisherIdentity(),
-		"track", subTrack.ID())
+		"trackID", subTrack.ID())
 	p.lock.Lock()
 	p.subscribedTracks[subTrack.ID()] = subTrack
 	settings := p.subscribedTracksSettings[subTrack.ID()]
@@ -879,7 +879,7 @@ func (p *ParticipantImpl) RemoveSubscribedTrack(subTrack types.SubscribedTrack)
 	p.params.Logger.Debugw("removed subscribedTrack",
 		"publisherID", subTrack.PublisherID(),
 		"publisherIdentity", subTrack.PublisherIdentity(),
-		"track", subTrack.ID(), "kind", subTrack.DownTrack().Kind())
+		"trackID", subTrack.ID(), "kind", subTrack.DownTrack().Kind())
 
 	p.subscriber.RemoveTrack(subTrack)
 
@@ -1063,18 +1063,18 @@ func (p *ParticipantImpl) onMediaTrack(track *webrtc.TrackRemote, rtpReceiver *w
 		return
 	}
 
-	p.params.Logger.Debugw("mediaTrack added",
-		"kind", track.Kind().String(),
-		"track", track.ID(),
-		"rid", track.RID(),
-		"SSRC", track.SSRC())
-
 	if !p.CanPublish() {
 		p.params.Logger.Warnw("no permission to publish mediaTrack", nil)
 		return
 	}
 
 	publishedTrack, isNewTrack := p.mediaTrackReceived(track, rtpReceiver)
+
+	p.params.Logger.Infow("mediaTrack published",
+		"kind", track.Kind().String(),
+		"trackID", publishedTrack.ID(),
+		"rid", track.RID(),
+		"SSRC", track.SSRC())
 	if !isNewTrack && publishedTrack != nil && p.IsReady() && p.onTrackUpdated != nil {
 		p.onTrackUpdated(p, publishedTrack)
 	}
@@ -1378,7 +1378,7 @@ func (p *ParticipantImpl) setTrackMuted(trackID livekit.TrackID, muted bool) {
 	p.pendingTracksLock.RUnlock()
 
 	if !isPending {
-		p.params.Logger.Warnw("could not locate track", nil, "track", trackID)
+		p.params.Logger.Warnw("could not locate track", nil, "trackID", trackID)
 	}
 }
 

pkg/rtc/room.go

@@ -612,12 +612,12 @@ func (r *Room) onTrackPublished(participant types.LocalParticipant, track types.
 		r.Logger.Debugw("subscribing to new track",
 			"participants", []livekit.ParticipantIdentity{participant.Identity(), existingParticipant.Identity()},
 			"pIDs", []livekit.ParticipantID{participant.ID(), existingParticipant.ID()},
-			"track", track.ID())
+			"trackID", track.ID())
 		if _, err := participant.AddSubscriber(existingParticipant, types.AddSubscriberParams{TrackIDs: []livekit.TrackID{track.ID()}}); err != nil {
 			r.Logger.Errorw("could not subscribe to remoteTrack", err,
 				"participants", []livekit.ParticipantIdentity{participant.Identity(), existingParticipant.Identity()},
 				"pIDs", []livekit.ParticipantID{participant.ID(), existingParticipant.ID()},
-				"track", track.ID())
+				"trackID", track.ID())
 		}
 	}
 

pkg/rtc/signalhandler.go

@@ -16,7 +16,7 @@ func HandleParticipantSignal(room types.Room, participant types.LocalParticipant
 			return err
 		}
 	case *livekit.SignalRequest_AddTrack:
-		pLogger.Debugw("add track request", "track", msg.AddTrack.Cid)
+		pLogger.Debugw("add track request", "trackID", msg.AddTrack.Cid)
 		participant.AddTrack(msg.AddTrack)
 	case *livekit.SignalRequest_Answer:
 		sd := FromProtoSessionDescription(msg.Answer)

pkg/rtc/uptrackmanager.go

@@ -149,7 +149,7 @@ func (u *UpTrackManager) SetPublishedTrackMuted(trackID livekit.TrackID, muted b
 		track.SetMuted(muted)
 
 		if currentMuted != track.IsMuted() {
-			u.params.Logger.Debugw("mute status changed", "track", trackID, "muted", track.IsMuted())
+			u.params.Logger.Debugw("mute status changed", "trackID", trackID, "muted", track.IsMuted())
 			if u.onTrackUpdated != nil {
 				u.onTrackUpdated(track, false)
 			}

pkg/service/roommanager.go

@@ -462,7 +462,7 @@ func (r *RoomManager) handleRTCMessage(_ context.Context, roomName livekit.RoomN
 			return
 		}
 		pLogger.Debugw("setting track muted",
-			"track", rm.MuteTrack.TrackSid, "muted", rm.MuteTrack.Muted)
+			"trackID", rm.MuteTrack.TrackSid, "muted", rm.MuteTrack.Muted)
 		if !rm.MuteTrack.Muted && !r.config.Room.EnableRemoteUnmute {
 			pLogger.Errorw("cannot unmute track, remote unmute is disabled", nil)
 			return

test/client/client.go

@@ -320,7 +320,7 @@ func (c *RTCClient) Run() error {
 			c.lock.Unlock()
 
 		case *livekit.SignalResponse_TrackPublished:
-			logger.Debugw("track published", "track", msg.TrackPublished.Track.Name, "participant", c.localParticipant.Sid,
+			logger.Debugw("track published", "trackID", msg.TrackPublished.Track.Name, "participant", c.localParticipant.Sid,
 				"cid", msg.TrackPublished.Cid, "trackSid", msg.TrackPublished.Track.Sid)
 			c.lock.Lock()
 			c.pendingPublishedTracks[msg.TrackPublished.Cid] = msg.TrackPublished.Track
@@ -690,7 +690,7 @@ func (c *RTCClient) processTrack(track *webrtc.TrackRemote) {
 
 	logger.Infow("client added track", "participant", c.localParticipant.Identity,
 		"pID", pId,
-		"track", trackId,
+		"trackID", trackId,
 	)
 
 	defer func() {
@@ -719,7 +719,7 @@ func (c *RTCClient) processTrack(track *webrtc.TrackRemote) {
 		numBytes += pkt.MarshalSize()
 		if time.Since(lastUpdate) > 30*time.Second {
 			logger.Infow("consumed from participant",
-				"track", trackId, "pID", pId,
+				"trackID", trackId, "pID", pId,
 				"size", numBytes)
 			lastUpdate = time.Now()
 		}

test/client/trackwriter.go

@@ -54,7 +54,7 @@ func (w *TrackWriter) Start() error {
 	}
 
 	logger.Debugw("starting track writer",
-		"track", w.track.ID(),
+		"trackID", w.track.ID(),
 		"mime", w.mime)
 	switch w.mime {
 	case webrtc.MimeTypeOpus: