From 883f7250f5b2941e476e3400eb051447be9e61d4 Mon Sep 17 00:00:00 2001 From: "Brandon McGinty (chatgpt)" Date: Wed, 12 Aug 2026 17:38:04 -0400 Subject: [PATCH] Avoid debug logging induced UDP loss --- gumble/gumble/udp.go | 5 ++++- gumble/gumble/udp15.go | 14 ++++++++++---- gumble/gumbleopenal/stream.go | 20 +++++++++++++------- 3 files changed, 27 insertions(+), 12 deletions(-) diff --git a/gumble/gumble/udp.go b/gumble/gumble/udp.go index 8c9a767..02ea3c2 100644 --- a/gumble/gumble/udp.go +++ b/gumble/gumble/udp.go @@ -59,7 +59,10 @@ func (c *Client) udpReadRoutine() { return } packetCount++ - if log.Enabled(log.LevelDebug) { + // A synchronous log write for every UDP datagram can itself make the + // reader fall behind and lose voice packets. Keep enough samples to + // diagnose framing while avoiding work on the audio hot path. + if log.Enabled(log.LevelDebug) && (packetCount <= 3 || packetCount%1000 == 0) { log.Debug("UDP recv #%d: %d bytes from %s hex=%s", packetCount, n, addr, hex.EncodeToString(buf[:n])) } diff --git a/gumble/gumble/udp15.go b/gumble/gumble/udp15.go index bb0c792..2b742dc 100644 --- a/gumble/gumble/udp15.go +++ b/gumble/gumble/udp15.go @@ -639,8 +639,10 @@ func (c *Client) WriteAudioUDP15(format byte, target uint32, sequence int64, dat return false, err } - log.Debug("UDP15 send: frame=%d opus_len=%d enc_len=%d final=%v", - frameNum, len(data), len(encrypted), final) + if log.Enabled(log.LevelDebug) && (frameNum < 3 || frameNum%1000 == 0 || final) { + log.Debug("UDP15 send: frame=%d opus_len=%d enc_len=%d final=%v", + frameNum, len(data), len(encrypted), final) + } _, err = udpConn.Write(encrypted) if err != nil { @@ -675,7 +677,9 @@ func (c *Client) HandleUDPPacket15(packet []byte, pktNum uint64) { return } - log.Debug("UDP15 #%d: decrypt OK, plaintext_len=%d", pktNum, len(plaintext)) + if log.Enabled(log.LevelDebug) && (pktNum <= 3 || pktNum%1000 == 0) { + log.Debug("UDP15 #%d: decrypt OK, plaintext_len=%d", pktNum, len(plaintext)) + } c.markUDPActive() // Check type byte (0x00 = Audio, 0x01 = Ping) @@ -841,7 +845,9 @@ func (c *Client) decodeAndDispatch(pktNum uint64, user *User, decoder AudioDecod return } - log.Debug("UDP15 #%d: Opus OK for %s, pcm_samples=%d", pktNum, user.Name, len(pcm)) + if log.Enabled(log.LevelDebug) && (pktNum <= 3 || pktNum%1000 == 0) { + log.Debug("UDP15 #%d: Opus OK for %s, pcm_samples=%d", pktNum, user.Name, len(pcm)) + } user.audioSequence = frameNum user.audioSequenceValid = true user.audioFrameStep = audioFrameStep(len(pcm)) diff --git a/gumble/gumbleopenal/stream.go b/gumble/gumbleopenal/stream.go index 3cc64a4..bb691fa 100644 --- a/gumble/gumbleopenal/stream.go +++ b/gumble/gumbleopenal/stream.go @@ -486,6 +486,7 @@ func (s *Stream) OnAudioStream(e *gumble.AudioStreamEvent) { var jitterBuf []*gumble.AudioPacket var jitterNextSeq int64 var jitterInit, jitterStarted bool + var jitterDrainLogCounter, jitterAnomalyLogCounter int // insertSorted inserts a packet into the jitter buffer sorted // by sequence number. @@ -563,7 +564,6 @@ func (s *Stream) OnAudioStream(e *gumble.AudioStreamEvent) { jitterStarted = true // Drain all packets that are ready (in sequence order) - drainedCount := 0 for { pkt := popNext() if pkt == nil { @@ -571,16 +571,22 @@ func (s *Stream) OnAudioStream(e *gumble.AudioStreamEvent) { if jitterBuf[0].Sequence < jitterNextSeq { // Late or duplicate: discard so it doesn't // permanently block the drain loop. - log.Debug("jitter: discarding late seq=%d for %s (next=%d buf=%d)", - jitterBuf[0].Sequence, e.User.Name, jitterNextSeq, len(jitterBuf)) + jitterAnomalyLogCounter++ + if jitterAnomalyLogCounter <= 3 || jitterAnomalyLogCounter%1000 == 0 { + log.Debug("jitter: discarding late seq=%d for %s (next=%d buf=%d)", + jitterBuf[0].Sequence, e.User.Name, jitterNextSeq, len(jitterBuf)) + } jitterBuf = jitterBuf[1:] continue } if jitterBuf[0].Sequence > jitterNextSeq { // Gap in sequence: skip ahead so we don't // wait forever for a lost packet. - log.Debug("jitter: seq gap for %s, skipping from %d to %d (buf=%d)", - e.User.Name, jitterNextSeq, jitterBuf[0].Sequence, len(jitterBuf)) + jitterAnomalyLogCounter++ + if jitterAnomalyLogCounter <= 3 || jitterAnomalyLogCounter%1000 == 0 { + log.Debug("jitter: seq gap for %s, skipping from %d to %d (buf=%d)", + e.User.Name, jitterNextSeq, jitterBuf[0].Sequence, len(jitterBuf)) + } jitterNextSeq = jitterBuf[0].Sequence continue } @@ -589,8 +595,8 @@ func (s *Stream) OnAudioStream(e *gumble.AudioStreamEvent) { } break } - drainedCount++ - if drainedCount <= 3 || drainedCount%50 == 0 { + jitterDrainLogCounter++ + if jitterDrainLogCounter <= 3 || jitterDrainLogCounter%1000 == 0 { log.Debug("jitter: draining seq=%d for %s (buf=%d emptyBufs=%d)", pkt.Sequence, e.User.Name, len(jitterBuf), len(emptyBufs)) }