Add counter for pub&sub time metrics (#3084)

* Add counter for pub&sub time metrics

The pub&sub shows large value in migration related case like
muted/disabled migration, the subscription time depends on
the time when publisher unmute the track(sending rtp packet
after migration), add a counter to distinguish since we
can't control the time in such cases and the first subscription
attemps also is more meaningful than those cases.

* Add info log for high publish delay
This commit is contained in:
cnderrauber
2024-10-11 04:07:24 +00:00
committed by GitHub
parent c8dbe8e977
commit cf59267631
3 changed files with 27 additions and 14 deletions
+18 -6
View File
@@ -2231,12 +2231,24 @@ func (p *ParticipantImpl) mediaTrackReceived(track *webrtc.TrackRemote, rtpRecei
if newTrack {
go func() {
p.pubLogger.Debugw(
"track published",
"trackID", mt.ID(),
"track", logger.Proto(mt.ToProto()),
"cost", pubTime.Milliseconds(),
)
// TODO: remove this after we know where the high delay is coming from
if pubTime > 3*time.Second {
p.pubLogger.Infow(
"track published with high delay",
"trackID", mt.ID(),
"track", logger.Proto(mt.ToProto()),
"cost", pubTime.Milliseconds(),
"rid", track.RID(),
"mime", track.Codec().MimeType,
)
} else {
p.pubLogger.Debugw(
"track published",
"trackID", mt.ID(),
"track", logger.Proto(mt.ToProto()),
"cost", pubTime.Milliseconds(),
)
}
prometheus.RecordPublishTime(mt.Source(), mt.Kind(), pubTime, p.GetClientInfo().GetSdk(), p.Kind())
p.handleTrackPublished(mt)
+3 -2
View File
@@ -759,7 +759,8 @@ type trackSubscription struct {
subStartedAt atomic.Pointer[time.Time]
// the timestamp when the subscription was started, will be reset when downtrack is closed with expected resume
subscribeAt atomic.Pointer[time.Time]
subscribeAt atomic.Pointer[time.Time]
succRecordCounter atomic.Int32
}
func newTrackSubscription(subscriberID livekit.ParticipantID, trackID livekit.TrackID, l logger.Logger) *trackSubscription {
@@ -1003,7 +1004,7 @@ func (s *trackSubscription) maybeRecordSuccess(ts telemetry.TelemetryService, pI
d := time.Since(*s.subscribeAt.Load())
s.logger.Debugw("track subscribed", "cost", d.Milliseconds())
subscriber := subTrack.Subscriber()
prometheus.RecordSubscribeTime(mediaTrack.Source(), mediaTrack.Kind(), d, subscriber.GetClientInfo().GetSdk(), subscriber.Kind())
prometheus.RecordSubscribeTime(mediaTrack.Source(), mediaTrack.Kind(), d, subscriber.GetClientInfo().GetSdk(), subscriber.Kind(), int(s.succRecordCounter.Inc()))
eventSent := s.eventSent.Swap(true)
+6 -6
View File
@@ -115,7 +115,7 @@ func initRoomStats(nodeID string, nodeType livekit.NodeType) {
Name: "ms",
ConstLabels: prometheus.Labels{"node_id": nodeID, "node_type": nodeType.String()},
Buckets: []float64{100, 200, 500, 700, 1000, 5000, 10000},
}, append(promStreamLabels, "sdk", "kind"))
}, append(promStreamLabels, "sdk", "kind", "count"))
prometheus.MustRegister(promRoomCurrent)
prometheus.MustRegister(promRoomDuration)
@@ -173,19 +173,19 @@ func AddPublishSuccess(kind string) {
}
func RecordPublishTime(source livekit.TrackSource, trackType livekit.TrackType, d time.Duration, sdk livekit.ClientInfo_SDK, kind livekit.ParticipantInfo_Kind) {
recordPubSubTime(true, source, trackType, d, sdk, kind)
recordPubSubTime(true, source, trackType, d, sdk, kind, 1)
}
func RecordSubscribeTime(source livekit.TrackSource, trackType livekit.TrackType, d time.Duration, sdk livekit.ClientInfo_SDK, kind livekit.ParticipantInfo_Kind) {
recordPubSubTime(false, source, trackType, d, sdk, kind)
func RecordSubscribeTime(source livekit.TrackSource, trackType livekit.TrackType, d time.Duration, sdk livekit.ClientInfo_SDK, kind livekit.ParticipantInfo_Kind, count int) {
recordPubSubTime(false, source, trackType, d, sdk, kind, count)
}
func recordPubSubTime(isPublish bool, source livekit.TrackSource, trackType livekit.TrackType, d time.Duration, sdk livekit.ClientInfo_SDK, kind livekit.ParticipantInfo_Kind) {
func recordPubSubTime(isPublish bool, source livekit.TrackSource, trackType livekit.TrackType, d time.Duration, sdk livekit.ClientInfo_SDK, kind livekit.ParticipantInfo_Kind, count int) {
direction := "subscribe"
if isPublish {
direction = "publish"
}
promPubSubTime.WithLabelValues(direction, source.String(), trackType.String(), sdk.String(), kind.String()).Observe(float64(d.Milliseconds()))
promPubSubTime.WithLabelValues(direction, source.String(), trackType.String(), sdk.String(), kind.String(), strconv.Itoa(count)).Observe(float64(d.Milliseconds()))
}
func RecordTrackSubscribeSuccess(kind string) {