From 2578d338d2ead4f051606488f76e8479d33a1b14 Mon Sep 17 00:00:00 2001 From: Dragos Vingarzan Date: Sat, 3 Oct 2026 16:05:17 +0200 Subject: [PATCH 1/3] Fix RTP output clock continuity across DTX restarts Cache timestamps from the actual output encoder rather than the DTX decoder context, and retain elapsed time when transcoding resumes after playback or floor blocking. Add repeated-burst coverage for PCMA, Opus and G.722, including timestamp wraparound, and update DTX restart expectations. Validation: 712 repeated-burst checks, 19 null-packet/DTMF checks and 87 playback checks passed. Extended DTX retains the same 56 baseline failures with no additional failures. (cherry picked from commit d0d3b2014505362b91cb1f770cd52bb8209801b2) --- daemon/codec.c | 18 ++++- include/ssrc.h | 1 + t/Makefile | 7 +- t/auto-daemon-tests-dtx-clock.pl | 129 +++++++++++++++++++++++++++++++ t/auto-daemon-tests-dtx.pl | 25 ++++-- 5 files changed, 168 insertions(+), 12 deletions(-) create mode 100644 t/auto-daemon-tests-dtx-clock.pl diff --git a/daemon/codec.c b/daemon/codec.c index 68fd50e71..385ae3acd 100644 --- a/daemon/codec.c +++ b/daemon/codec.c @@ -4100,8 +4100,6 @@ static void __dtx_send_later(struct codec_timer *ct) { mutex_unlock(&dtxb->lock); } } - if (ch && ch->encoder && mp_copy.ssrc_out) - mp_copy.ssrc_out->ts_out = ch->encoder->next_pts + ch->csch.first_ts; mutex_lock(&dtxb->lock); @@ -4726,6 +4724,14 @@ static void packet_encoded_tx(struct codec_ssrc_handler *ch, struct media_packet if (!repeats) break; } while (repeats--); + + // Save the clock of the actual output encoder. The DTX decoder may run at a + // different rate and cannot supply the timestamp for this listener. + if (!is_dtmf) { + mp->ssrc_out->ts_out = ch->csch.first_ts + fraction_divl(pts + duration, cr_fact); + mp->ssrc_out->ts_out_time = rtpe_now + + fraction_divl(duration, cr_fact) * 1000000LL / ch->handler->dest_pt.clock_rate; + } } @@ -4923,8 +4929,14 @@ static tc_code packet_decode(struct codec_ssrc_handler *ch, struct codec_ssrc_ha { tc_code ret = TCC_OK; - if (!ch->csch.first_ts) + if (!ch->csch.first_ts) { ch->csch.first_ts = mp->ssrc_out->ts_out ?: packet->ts; + // A stopped encoder does not produce samples while prompts or floor + // blocking are active. Keep that elapsed time in the listener's RTP clock. + if (mp->ssrc_out->ts_out_time && rtpe_now > mp->ssrc_out->ts_out_time) + ch->csch.first_ts += (rtpe_now - mp->ssrc_out->ts_out_time) + * ch->handler->dest_pt.clock_rate / 1000000; + } if (ch->decoder && ch->decoder->def->dtmf) { if (packet_dtmf_event(ch, input_ch, packet, mp) == -1) diff --git a/include/ssrc.h b/include/ssrc.h index 66087ba1b..6094a9739 100644 --- a/include/ssrc.h +++ b/include/ssrc.h @@ -53,6 +53,7 @@ struct ssrc_entry_call { uint32_t ssrc_map_out; uint16_t seq_out; unsigned long ts_out; + int64_t ts_out_time; // wall clock corresponding to the next output RTP timestamp bool seq_set; // RTCP stats diff --git a/t/Makefile b/t/Makefile index edd7cd33d..d51b96a32 100644 --- a/t/Makefile +++ b/t/Makefile @@ -90,7 +90,7 @@ include ../lib/common.Makefile daemon-tests-bundle daemon-tests-dtls daemon-tests-rollback \ daemon-tests-rollback-redis daemon-tests-redis-srtp-index \ daemon-tests-recording daemon-tests-create daemon-tests-alias \ - daemon-tests-kernel-api \ + daemon-tests-kernel-api daemon-tests-dtx-clock \ daemon-tests-video daemon-tests-inject daemon-tests-dtx-dtmf TESTS := test-bitstr aes-crypt aead-aes-crypt test-const_str_hash.strhash @@ -143,7 +143,7 @@ daemon-tests: daemon-tests-main daemon-tests-jb daemon-tests-pubsub daemon-tests daemon-tests-bundle daemon-tests-dtls daemon-tests-rollback daemon-tests-rollback-redis \ daemon-tests-redis-srtp-index \ daemon-tests-recording daemon-tests-create \ - daemon-tests-dtx daemon-tests-dtx-cn daemon-tests-dtx-no-shift daemon-tests-dtx-dtmf \ + daemon-tests-dtx daemon-tests-dtx-cn daemon-tests-dtx-no-shift daemon-tests-dtx-dtmf daemon-tests-dtx-clock \ daemon-tests-alias \ daemon-tests-kernel-api \ daemon-tests-video daemon-tests-inject @@ -184,6 +184,9 @@ daemon-tests-dtx: daemon-test-deps daemon-tests-dtx-dtmf: daemon-test-deps ./auto-test-helper "$@" perl -I../perl auto-daemon-tests-dtx-dtmf.pl +daemon-tests-dtx-clock: daemon-test-deps + ./auto-test-helper "$@" perl -I../perl auto-daemon-tests-dtx-clock.pl + daemon-tests-dtx-no-shift: daemon-test-deps ./auto-test-helper "$@" perl -I../perl auto-daemon-tests-dtx-no-shift.pl diff --git a/t/auto-daemon-tests-dtx-clock.pl b/t/auto-daemon-tests-dtx-clock.pl new file mode 100644 index 000000000..fef1cc9a4 --- /dev/null +++ b/t/auto-daemon-tests-dtx-clock.pl @@ -0,0 +1,129 @@ +#!/usr/bin/perl + +use strict; +use warnings; +use NGCP::Rtpengine::Test; +use NGCP::Rtpclient::SRTP; +use NGCP::Rtpengine::AutoTest; +use Test::More; + +# Repeated floor bursts must retain each output encoder clock through prompt playback. +autotest_start(qw(--config-file=none -t -1 -i 203.0.113.1 + -n 2223 -f -L 7 -E --silence-detect=1 --dtx-delay=50 --max-dtx=1)) or die; + +use Time::HiRes qw(time sleep); +use IO::Select; + +# Exercise equal rates, different RTP rates, and the G.722 sample/RTP rate factor. +for my $profile ( + ['PCMA/8000', 8, 8000, 100000], + ['opus/48000/2', 96, 48000, 100000], + ['G722/8000', 9, 8000, 0xfffff000], +) { + my ($codec, $pt, $rate, $origin) = @$profile; + my $offer_pts = $pt == 96 ? '96 97' : $pt; + my $offer_attrs = "a=rtpmap:$pt $codec"; + if ($pt == 96) { + $offer_attrs .= "\na=fmtp:96 useinbandfec=1\na=rtpmap:97 telephone-event/48000\na=fmtp:97 0-15"; + } + my ($sock_a, $sock_b) = new_call([qw(198.51.100.10 5000)], [qw(198.51.100.10 5002)]); + my $name = "DTX output clock across playback: $codec"; + + my ($port_a) = offer($name, { codec => { transcode => [$codec] } }, <new($sock_b); + my $end = time() + 0.3; + my $received = 0; + while (time() < $end && $sel->can_read(0.1)) { + my $p; + $sock_b->recv($p, 65535); + my ($out_pt, $q, $ts, $ssrc) = unpack('x C n N N', $p); + is($out_pt & 0x7f, $pt, 'burst uses the negotiated output codec'); + $audio_ssrc //= $ssrc; + is($ssrc, $audio_ssrc, 'speech SSRC survives playback transitions'); + my $now = time(); + if (defined $last_ts) { + my $delta = ($ts - $last_ts) & 0xffffffff; + cmp_ok($delta, '<', 0x80000000, 'output clock does not rewind'); + if ($now - $last_time > 1) { + # Receive after sending a 200 ms batch; allow that batching skew. + cmp_ok(abs($delta / $rate - ($now - $last_time)), '<', 0.3, + 'RTP clock includes elapsed playback and silence'); + } + } + $last_ts = $ts; + $last_time = $now; + $received++; + } + cmp_ok($received, '>=', 10, 'each burst produces output promptly'); + rtpe_req('block media', $name, {'from-tag' => ft(), flags => ['directional']}); + rtpe_req('play media', $name, {'from-tag' => tt(), blob => $wav}); + sleep(0.2); + rtpe_req('stop media', $name, {'from-tag' => tt()}); + while ($sel->can_read(0.01)) { + my $p; + $sock_b->recv($p, 65535); + } + sleep(1.4); + rtpe_req('unblock media', $name, {'from-tag' => ft(), flags => ['directional']}); + } + rtpe_req('delete', $name, {'from-tag' => ft()}); +} + +done_testing(); diff --git a/t/auto-daemon-tests-dtx.pl b/t/auto-daemon-tests-dtx.pl index e25e5e82e..578272e83 100755 --- a/t/auto-daemon-tests-dtx.pl +++ b/t/auto-daemon-tests-dtx.pl @@ -22,7 +22,7 @@ my ($sock_a, $sock_b, $sock_c, $sock_d, $port_a, $port_b, $ssrc, $ssrc_b, $resp, $sock_ax, $sock_bx, $port_ax, $port_bx, $srtp_ctx_a, $srtp_ctx_b, $srtp_ctx_a_rev, $srtp_ctx_b_rev, - @ret1, @ret2, @ret3, @ret4, $srtp_key_a, $srtp_key_b, $ts, $seq); + @ret1, @ret2, @ret3, @ret4, $srtp_key_a, $srtp_key_b, $ts, $seq, $resume_time); @@ -894,6 +894,7 @@ rcv($sock_b, $port_a, rtpm(8, $seq + 10, 5600, 0x5678, "\xd5\xd5\xd5\xd5\x55\x55\xd5\x55\x55\xd5\x55\x55\x55\x55\xd5\x55\x55\xd5\x55\xd5\x55\xd5\x55\x55\xd5\xd5\xd5\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\xd5\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\xd5\x55\x55\xd5\x55\x55\x55\x55\x55\x55\x55\xd5\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\xd5\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\xd5\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\x55\xd5\xd5\xd5\xd5\xd5\xd5\xd5\x55\x55\x55\x55\x55\x55\x55")); # inject old PCM +$resume_time = Time::HiRes::time(); snd($sock_a, $port_b, rtp(0, 2006, 5760, 0x5678, "\x40" x 160)); # packet dropped rcv_no($sock_b); @@ -947,9 +948,12 @@ snd($sock_a, $port_b, rtp(0, 2007, 5920, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(8, $seq + 11, 5760, $ssrc, "\x68" x 160)); +# Reconfiguration retains elapsed time in the output clock, independently of the input origin. +($ts) = rcv($sock_b, $port_a, rtpm(8, $seq + 11, -1, $ssrc, "\x68" x 160)); +cmp_ok(abs(($ts - 5600) / 8000 - (Time::HiRes::time() - $resume_time)), '<', 0.1, + 'output clock advances through codec reconfiguration'); snd($sock_a, $port_b, rtp(0, 2008, 6080, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(8, $seq + 12, 5920, $ssrc, "\x68" x 160)); +rcv($sock_b, $port_a, rtpm(8, $seq + 12, $ts + 160, $ssrc, "\x68" x 160)); rtpe_req('delete', 'G.711/AMR-WB codec change with timing', { 'from-tag' => ft() }); @@ -1081,6 +1085,7 @@ rcv($sock_b, $port_a, rtpm(8, $seq + 10, 5600, 0x5678, "\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5\xd5")); # inject old PCM +$resume_time = Time::HiRes::time(); snd($sock_a, $port_b, rtp(0, 2006, 5600, 0x5678, "\x40" x 160)); # packet dropped rcv_no($sock_b); @@ -1134,7 +1139,10 @@ snd($sock_a, $port_b, rtp(0, 2007, 5760, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(8, $seq + 11, 5760, $ssrc, "\x68" x 160)); +# Reconfiguration retains elapsed time in the output clock, independently of the input origin. +($ts) = rcv($sock_b, $port_a, rtpm(8, $seq + 11, -1, $ssrc, "\x68" x 160)); +cmp_ok(abs(($ts - 5600) / 8000 - (Time::HiRes::time() - $resume_time)), '<', 0.1, + 'output clock advances through codec reconfiguration'); rtpe_req('delete', 'G.711/AMR codec change with timing', { 'from-tag' => ft() }); @@ -2044,14 +2052,17 @@ rcv($sock_b, $port_a, rtpm(8, $seq + 9 + $i, 5440 + $i * 160, $ssrc, "\xd5" x 160)); } # now shut down +$resume_time = Time::HiRes::time(); rcv_no($sock_b); # start audio again snd($sock_a, $port_b, rtp(0, 2005, 90000, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(8, $seq + 507, 90000, $ssrc, "\x68" x 160)); +($ts) = rcv($sock_b, $port_a, rtpm(8, $seq + 507, -1, $ssrc, "\x68" x 160)); +cmp_ok(abs(($ts - (5440 + 497 * 160)) / 8000 - (Time::HiRes::time() - $resume_time)), '<', 0.1, + 'output clock survives maximum DTX shutdown'); snd($sock_a, $port_b, rtp(0, 2006, 90160, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(8, $seq + 508, 90160, $ssrc, "\x68" x 160)); +rcv($sock_b, $port_a, rtpm(8, $seq + 508, $ts + 160, $ssrc, "\x68" x 160)); # DTX -> silence -rcv($sock_b, $port_a, rtpm(8, $seq + 509, 90320, $ssrc, "\xd5" x 160)); +rcv($sock_b, $port_a, rtpm(8, $seq + 509, $ts + 320, $ssrc, "\xd5" x 160)); rtpe_req('delete', 'G.711 DTX ptime change', { 'from-tag' => ft() }); From 54616c4991c5f3c56bb4d720ca920d81e76264dd Mon Sep 17 00:00:00 2001 From: Dragos Vingarzan Date: Fri, 9 Oct 2026 15:40:24 +0200 Subject: [PATCH 2/3] fix timestamp regression by restricting output clock caching to DTX packets --- daemon/codec.c | 9 ++++++--- include/media_socket.h | 1 + 2 files changed, 7 insertions(+), 3 deletions(-) diff --git a/daemon/codec.c b/daemon/codec.c index 385ae3acd..ff34d066b 100644 --- a/daemon/codec.c +++ b/daemon/codec.c @@ -4061,6 +4061,8 @@ static void __dtx_send_later(struct codec_timer *ct) { rwlock_lock_r(&call->master_lock); __ssrc_lock_both(&mp_copy); + mp_copy.dtx = true; + if (dtxp) { ilogs(dtx, LOG_DEBUG, "Decoding DTX-buffered RTP packet (TS %lu) now; " "%i packets left in queue", ts, p_left); @@ -4725,9 +4727,10 @@ static void packet_encoded_tx(struct codec_ssrc_handler *ch, struct media_packet break; } while (repeats--); - // Save the clock of the actual output encoder. The DTX decoder may run at a - // different rate and cannot supply the timestamp for this listener. - if (!is_dtmf) { + // Save the clock of the actual output encoder for DTX restarts. The DTX decoder + // may run at a different rate and cannot supply the timestamp for this listener. + // Ordinary transcoding must retain the input timestamp origin when reconfigured. + if (mp->dtx && !is_dtmf) { mp->ssrc_out->ts_out = ch->csch.first_ts + fraction_divl(pts + duration, cr_fact); mp->ssrc_out->ts_out_time = rtpe_now + fraction_divl(duration, cr_fact) * 1000000LL / ch->handler->dest_pt.clock_rate; diff --git a/include/media_socket.h b/include/media_socket.h index 7817118b5..f7fd7c716 100644 --- a/include/media_socket.h +++ b/include/media_socket.h @@ -313,6 +313,7 @@ struct media_packet { struct sink_handler sink; struct media_player_cache_entry *cache_entry; bool recording_egress; + bool dtx; // processed by the DTX timer; retain the output encoder clock struct rtp_header *rtp; struct rtcp_packet *rtcp; From 8fb7c5f7c4de0d7685c4469010295a1d6a44c12e Mon Sep 17 00:00:00 2001 From: Dragos Vingarzan Date: Fri, 9 Oct 2026 17:16:53 +0200 Subject: [PATCH 3/3] test: update reverse AMR-WB codec-change test to verify elapsed output clock continuity --- t/auto-daemon-tests-dtx.pl | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/t/auto-daemon-tests-dtx.pl b/t/auto-daemon-tests-dtx.pl index 578272e83..c34982d37 100755 --- a/t/auto-daemon-tests-dtx.pl +++ b/t/auto-daemon-tests-dtx.pl @@ -705,10 +705,13 @@ rcv($sock_b, $port_a, rtpm(96, $seq + 10, 7200, 0x5678, "\xf0\x1c\x50\x54\x30\x77\xf3\xdd\x1d\xd3\x57\x6b\xce\xc7\xcd\x7a\x17\x71\x05\x36\x04\x42\x70\x72\x73\x25\x0c\x14\x26\x2a\x05\x72\x03\x90\xf2\x5c\x48\xd8")); # inject old PCM +$resume_time = Time::HiRes::time(); snd($sock_a, $port_b, rtp(0, 2004, 5120, 0x5678, "\x40" x 160)); snd($sock_a, $port_b, rtp(0, 2006, 5440, 0x5678, "\x40" x 160)); # packet dropped rcv_no($sock_b); +# Make the elapsed gap large enough to distinguish it from a single 20 ms increment. +Time::HiRes::usleep(200000); # reinvite back to PCMU @@ -762,9 +765,12 @@ snd($sock_a, $port_b, rtp(0, 2007, 5760, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(96, $seq + 11, 7520, $ssrc, "\xf0\x1c\x21\x40\x00\xff\xfb\xfc\x92\x17\x2f\x21\x34\xcb\x60\x28\x1b\x23\x23\x30\x04\x87\xb1\x30\x4f\x91\x04\x5e\xd9\xc6\x6c\xfc\x28\xed\xe1\xc6\xd5\xe0")); +# AMR-WB uses a 16 kHz output clock, independently of the G.711 input origin. +($ts) = rcv($sock_b, $port_a, rtpm(96, $seq + 11, -1, $ssrc, "\xf0\x1c\x21\x40\x00\xff\xfb\xfc\x92\x17\x2f\x21\x34\xcb\x60\x28\x1b\x23\x23\x30\x04\x87\xb1\x30\x4f\x91\x04\x5e\xd9\xc6\x6c\xfc\x28\xed\xe1\xc6\xd5\xe0")); +cmp_ok(abs(($ts - 7200) / 16000 - (Time::HiRes::time() - $resume_time)), '<', 0.1, + 'AMR-WB output clock advances through codec reconfiguration'); snd($sock_a, $port_b, rtp(0, 2007, 5920, 0x5678, "\x40" x 160)); -rcv($sock_b, $port_a, rtpm(96, $seq + 12, 7840, $ssrc, "\xf0\x1c\xc8\xc6\x04\x55\x92\x65\x07\x9c\x21\x19\x06\x71\x89\xd4\x66\xe6\x84\xe6\xc5\xc4\xc4\xcc\x5e\xc1\xc5\xf5\x4c\x55\xde\x71\x9a\x57\xc0\xde\xe4\xd0")); +rcv($sock_b, $port_a, rtpm(96, $seq + 12, $ts + 320, $ssrc, "\xf0\x1c\xc8\xc6\x04\x55\x92\x65\x07\x9c\x21\x19\x06\x71\x89\xd4\x66\xe6\x84\xe6\xc5\xc4\xc4\xcc\x5e\xc1\xc5\xf5\x4c\x55\xde\x71\x9a\x57\xc0\xde\xe4\xd0")); rtpe_req('delete', 'G.711/AMR-WB codec change reverse', { 'from-tag' => ft() });