From ffd6dc221048cab7e7f271d1efb644c7ccfa9dac Mon Sep 17 00:00:00 2001
From: Raja Subramanian <raja.gobi@tutanota.com>
Date: Tue, 25 Jul 2023 13:53:21 +0530
Subject: [PATCH] Packet level ddebug logs. (#1900)

Only for debugging for a bit. Not for deploy.
---
 pkg/sfu/downtrack.go | 95 +++++++++++++++++++++++++++++++++++++++++---
 1 file changed, 90 insertions(+), 5 deletions(-)

diff --git a/pkg/sfu/downtrack.go b/pkg/sfu/downtrack.go
index d943b7c75..77226e7b5 100644
--- a/pkg/sfu/downtrack.go
+++ b/pkg/sfu/downtrack.go
@@ -621,11 +621,27 @@ func (d *DownTrack) WriteRTP(extPkt *buffer.ExtPacket, layer int32) error {
 		return err
 	}
 
+	var iPID, iTL0PICIDX, iKEYIDX, iTID, oPID, oTL0PICIDX, oKEYIDX, oTID int // TOOD-REMOVE-AFTER-DEBUG
 	var payload []byte
 	pool := PacketFactory.Get().(*[]byte)
 	if len(tp.codecBytes) != 0 {
-		incomingVP8, _ := extPkt.Payload.(buffer.VP8)
-		payload = d.translateVP8PacketTo(extPkt.Packet, &incomingVP8, tp.codecBytes, pool)
+		incomingVP8, ok := extPkt.Payload.(buffer.VP8)
+		if ok {
+			iPID = int(incomingVP8.PictureID)
+			iTL0PICIDX = int(incomingVP8.TL0PICIDX)
+			iKEYIDX = int(incomingVP8.KEYIDX)
+			iTID = int(incomingVP8.TID)
+
+			var outgoingVP8 buffer.VP8
+			if uerr := outgoingVP8.Unmarshal(append(tp.codecBytes, 0x0)); uerr == nil {
+				oPID = int(outgoingVP8.PictureID)
+				oTL0PICIDX = int(outgoingVP8.TL0PICIDX)
+				oKEYIDX = int(outgoingVP8.KEYIDX)
+				oTID = int(outgoingVP8.TID)
+			}
+
+			payload = d.translateVP8PacketTo(extPkt.Packet, &incomingVP8, tp.codecBytes, pool)
+		}
 	}
 	if payload == nil {
 		payload = (*pool)[:len(extPkt.Packet.Payload)]
@@ -652,6 +668,28 @@ func (d *DownTrack) WriteRTP(extPkt *buffer.ExtPacket, layer int32) error {
 		return err
 	}
 
+	if d.kind == webrtc.RTPCodecTypeVideo {
+		d.logger.Debugw(
+			"packet debug (forwarding)",
+			"layer", layer,
+			"isn", extPkt.Packet.SequenceNumber,
+			"its", extPkt.Packet.Timestamp,
+			"im", extPkt.Packet.Marker,
+			"osn", hdr.SequenceNumber,
+			"ots", hdr.Timestamp,
+			"om", hdr.Marker,
+			"len", len(payload),
+			"iPID", iPID,
+			"iTL0PICIDX", iTL0PICIDX,
+			"iKEYIDX", iKEYIDX,
+			"iTID", iTID,
+			"oPID", oPID,
+			"oTL0PICIDX", oTL0PICIDX,
+			"oKEYIDX", oKEYIDX,
+			"oTID", oTID,
+		)
+	}
+
 	d.pacer.Enqueue(pacer.Packet{
 		Header:             hdr,
 		Extensions:         []pacer.ExtensionData{{ID: uint8(d.dependencyDescriptorExtID), Payload: tp.ddBytes}},
@@ -735,6 +773,16 @@ func (d *DownTrack) WritePaddingRTP(bytesToSend int, paddingOnMute bool, forceMa
 		// last byte of padding has padding size including that byte
 		payload[RTPPaddingMaxPayloadSize-1] = byte(RTPPaddingMaxPayloadSize)
 
+		if d.kind == webrtc.RTPCodecTypeVideo {
+			d.logger.Debugw(
+				"packet debug (padding)",
+				"osn", hdr.SequenceNumber,
+				"ots", hdr.Timestamp,
+				"om", hdr.Marker,
+				"len", len(payload),
+			)
+		}
+
 		d.pacer.Enqueue(pacer.Packet{
 			Header:             &hdr,
 			Payload:            payload,
@@ -1488,18 +1536,22 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) {
 			numRepeatedNACKs++
 		}
 
+		var incomingHdr rtp.Header // TODO-REMOVE-AFTER-DEBUG
 		var pkt rtp.Packet
 		if err = pkt.Unmarshal(pktBuff[:n]); err != nil {
+			d.logger.Errorw("unmarshalling rtp packet failed in retransmit", err)
 			continue
 		}
+		incomingHdr = pkt.Header
 		pkt.Header.SequenceNumber = meta.targetSeqNo
 		pkt.Header.Timestamp = meta.timestamp
 		pkt.Header.SSRC = d.ssrc
 		pkt.Header.PayloadType = d.payloadType
 
+		var iPID, iTL0PICIDX, iKEYIDX, iTID, oPID, oTL0PICIDX, oKEYIDX, oTID int // TOOD-REMOVE-AFTER-DEBUG
 		var payload []byte
 		pool := PacketFactory.Get().(*[]byte)
-		if d.mime == "video/vp8" && len(pkt.Payload) > 0 {
+		if d.mime == "video/vp8" && len(pkt.Payload) > 0 && len(meta.codecBytes) != 0 {
 			var incomingVP8 buffer.VP8
 			if err = incomingVP8.Unmarshal(pkt.Payload); err != nil {
 				d.logger.Errorw("unmarshalling VP8 packet err", err)
@@ -1507,15 +1559,48 @@ func (d *DownTrack) retransmitPackets(nacks []uint16) {
 				continue
 			}
 
-			if len(meta.codecBytes) != 0 {
-				payload = d.translateVP8PacketTo(&pkt, &incomingVP8, meta.codecBytes, pool)
+			iPID = int(incomingVP8.PictureID)
+			iTL0PICIDX = int(incomingVP8.TL0PICIDX)
+			iKEYIDX = int(incomingVP8.KEYIDX)
+			iTID = int(incomingVP8.TID)
+
+			var outgoingVP8 buffer.VP8
+			if uerr := outgoingVP8.Unmarshal(append(meta.codecBytes, 0x0)); uerr == nil {
+				oPID = int(outgoingVP8.PictureID)
+				oTL0PICIDX = int(outgoingVP8.TL0PICIDX)
+				oKEYIDX = int(outgoingVP8.KEYIDX)
+				oTID = int(outgoingVP8.TID)
 			}
+
+			payload = d.translateVP8PacketTo(&pkt, &incomingVP8, meta.codecBytes, pool)
 		}
 		if payload == nil {
 			payload = (*pool)[:len(pkt.Payload)]
 			copy(payload, pkt.Payload)
 		}
 
+		if d.kind == webrtc.RTPCodecTypeVideo {
+			d.logger.Debugw(
+				"packet debug (retransmit)",
+				"layer", meta.layer,
+				"isn", incomingHdr.SequenceNumber,
+				"its", incomingHdr.Timestamp,
+				"im", incomingHdr.Marker,
+				"osn", pkt.Header.SequenceNumber,
+				"ots", pkt.Header.Timestamp,
+				"om", pkt.Header.Marker,
+				"len", len(payload),
+				"iPID", iPID,
+				"iTL0PICIDX", iTL0PICIDX,
+				"iKEYIDX", iKEYIDX,
+				"iTID", iTID,
+				"oPID", oPID,
+				"oTL0PICIDX", oTL0PICIDX,
+				"oKEYIDX", oKEYIDX,
+				"oTID", oTID,
+			)
+		}
+
 		d.pacer.Enqueue(pacer.Packet{
 			Header:             &pkt.Header,
 			Extensions:         []pacer.ExtensionData{{ID: uint8(d.dependencyDescriptorExtID), Payload: meta.ddBytes}},