通话结束了，RTP流还在跑？一次对端网关缓冲区的排查实录
Freeswitch
通话结束了，RTP流还在跑？一次对端网关缓冲区的排查实录
通话3分钟，录音文件10分钟。抓包一看，BYE都互发完了，RTP包还在往FreeSWITCH跑。问题不在FreeSWITCH，在运营商网关的发送缓冲。直接说怎么定位和验证。
Freeswitch

通话结束了，RTP流还在跑？一次对端网关缓冲区的排查实录

问题现象

用户反馈”录音文件时长和通话时长对不上”。

拉出数据一看：

通话ID 实际通话时长 录音文件时长 差值
call_001 3分12秒 10分47秒 +7分35秒
call_002 1分45秒 8分02秒 +6分17秒
call_003 5分30秒 11分20秒 +5分50秒

差了5到8分钟。这不对劲。

业务场景

我们这有个通话质检系统，跑在FreeSWITCH上做SIP录音。正常流程是这样的：

  1. 甲方外呼进来 → FreeSWITCH接听 → 录音进程开始录制
  2. 通话结束 → 甲方挂机 → FreeSWITCH收到BYE → 停止录音

理论上通话结束的瞬间录音就该停。但实际跑下来，有大概3%的录音文件时长远超实际通话。最离谱的一个，实际通话2分钟，录音文件14分钟。

质检系统拿录音做语音识别和情绪分析，时长对不上导致误判率飙升。甲方天天催，我们天天查日志，日志显示FS的BYE处理完全正常。

直到有一天我决定直接抓包看。

快速判断：谁在发包？

第一反应是”FreeSWITCH没及时停录音”。但抓包一看，我改主意了。

# 在FS服务器上抓包，用rtp流过滤
tshark -r capture.pcap -Y "rtp && ip.addr==192.168.1.100" \
  -T fields -e frame.time_relative \
  -e rtp.timestamp \
  -e rtp.seq \
  -e ip.src \
  -e ip.dst > rtp_timeline.txt

看最后几行：

182.34   2880000    65432   10.0.1.50    192.168.1.100   # 通话结束前
183.56   2894400    65433   10.0.1.50    192.168.1.100   # 通话结束前
184.01   [BYE请求发出]                               # FreeSWITCH发BYE
184.03   [200 OK收到]                               # 对端回200
184.15   [BYE确认发出]                               # FreeSWITCH确认
...
186.20   2916000    65440   10.0.1.50    192.168.1.100   # BYE互发完了还在跑！
188.75   2930400    65445   10.0.1.50    192.168.1.100
190.34   2944800    65448   10.0.1.50    192.168.1.100

184秒通话就结束了，但RTP包从184秒一直跑到190秒。

这说明：FreeSWITCH侧的BYE处理是正常的。问题出在对端网关在收到BYE之后，还在继续发送RTP包。

日志交叉验证

FreeSWITCH侧的日志很干净：

2024-01-15 02:34:44.012345 [INFO] sofia.c:8151 Received BYE
2024-01-15 02:34:44.014567 [INFO] sofia.c:8151 Sending 200 OK to BYE
2024-01-15 02:34:44.015678 [INFO] switch_core_media.c:5621 Hangup cause: NORMAL_CLEARING

对端网关呢？你得找运营商要。大概率会告诉你：

[2024-01-15 02:34:44] Received BYE from 192.168.1.100
[2024-01-15 02:34:44] Sent 200 OK
[2024-01-15 02:34:44] Media session terminated
[2024-01-15 02:34:50] Actually stopped sending RTP  # 这行很关键

注意时间差：BYE处理完到真正停RTP，差了6秒。

数据说明

抓了3天的包做统计，数字挺吓人的：

统计项 数值
总通话数 12,847
异常录音数（差>10秒） 386
异常占比 3.0%
最大差值 11分23秒
平均差值 8.7秒
缓冲延迟中位数 6.2秒
缓冲延迟95分位 9.8秒

大部分情况下缓冲延迟在6秒左右，但架不住量大。12,847通电话里300多通有这个问题，甲方质检误判率直接拉满。

还有个有意思的数据：我专门数了一下BYE之后还有多少个”幽灵RTP包”。

# 统计BYE之后对端继续发送的RTP包数量分布
tshark -r capture.pcap -Y "sip.Method==BYE && ip.addr==192.168.1.100" \
  -T fields -e frame.number > bye_frame.txt

# 假设BYE在frame 12345
tshark -r capture.pcap -Y "rtp && ip.addr==192.168.1.100 && frame.number > 12345" \
  -c 1000 | wc -l

正常通话结束后，对端应该只发几个RTCP的BYE相关包。但这次抓到的包，BYE之后还有20-50个连续时间戳的RTP包。时间戳是连续的，seq是递增的，一看就是正常语音流被缓冲住了。

根因：运营商网关的RTP发送缓冲

这不是FreeSWITCH的问题，是对端网关的发送缓冲（transmission buffer）没清空。

通话结束时，对端网关的应用层已经收到BYE并准备停流。但底层还在从缓冲区读数据往外发。这个缓冲区是网络栈用来平滑发送的，里面可能堆了几百毫秒甚至几秒的包。

说白了，运营商网关就是”接收到停止指令但腿脚不利索”。

如果你用的是rtpengine做媒体代理，可以看retransmission日志：

# 查看rtpengine日志，找最后几秒的包
cat /var/log/rtpengine/rtpengine.log | grep "call_id=xxx" | tail -50

# 输出大概长这样
1676: [INFO] 1485645518.123456 call_id:xxx seq:65440 ts:2916000 dropped:no
1677: [INFO] 1485645518.135212 call_id:xxx seq:65441 ts:2920800 dropped:no
1678: [INFO] 1485645518.146873 call_id:xxx seq:65442 ts:2925600 dropped:no
1679: [INFO] 1485645520.000001 call_id:xxx Terminated - received BYE
1680: [INFO] 1485645520.000002 call_id:xxx Cleaning up

注意seq 65440、65441、65442这三个包——它们在BYE之后才到达rtpengine。rtpengine忠实地把它们转发给了录音进程，录音进程哪知道这是”幽灵包”，照单全收。

调用方式

验证幽灵流需要几个关键命令：

# 1. 提取RTP时间线，定位BYE前后的包
tshark -r capture.pcap -Y "rtp" -T fields \
  -e frame.time_relative \
  -e rtp.timestamp \
  -e rtp.seq \
  -e ip.src \
  -e ip.dst \
  -e sip.Method \
  -e sip.Status-Code \
  | awk -F'\t' '
    $6=="BYE" || $6=="200" {print "== BYE at "$1; found=1} 
    found && $3!="" {print}
  ' > bye_rtp_trace.txt

# 2. 统计BYE之后对端继续发包的数量
# 先找到BYE的frame number
BYE_FRAME=$(tshark -r capture.pcap -Y "sip.Method==BYE" -T fields -e frame.number | head -1)
echo "BYE at frame: $BYE_FRAME"

# 统计BYE之后对端（假设是10.0.1.50）发的RTP包数
tshark -r capture.pcap -Y "rtp && ip.src==10.0.1.50 && frame.number > $BYE_FRAME" -c 10000 | wc -l

# 3. 验证rtpengine的retransmission
# 看看BYE之后是否有rtpengine标记为retransmission的包
cat /var/log/rtpengine/rtpengine.log | grep "call_id=目标call" | grep -E "(retransmission|late)" | tail -20

如果BYE之后对端发的RTP包超过10个，而且时间戳连续，基本就是缓冲问题。如果只有零星几个，可能是正常的重传。

参数说明

FreeSWITCH侧有几个参数会影响RTP处理行为：

参数 位置 作用 这个场景要不要调
enable-100rel sofia profile 开启PRACK可靠性 建议开，强制对端响应
pt1min sofia profile PRACK最小延迟(ms) 默认30，不用改
pt1max sofia profile PRACK最大延迟(ms) 可调大，强制超时拆流
rtp-timeout-sec bridge或uuid_media RTP超时无流量自动拆流 关键参数
rtp-holding-timeout-sec bridge 保持态超时 可参考
timer_name sofia profile 定时器类型 建议soft，推荐戈德堡

rtp-timeout-sec是我后来加上的：

<!-- sofia.conf.xml里的profile配置 -->
<profile name="external">

<settings>
    <param name="enable-100rel" value="true"/>
    <param name="pt1min" value="30"/>
    <param name="pt1max" value="300"/>
    <param name="rtp-timeout-sec" value="10"/>
  </settings>
</profile>

设置rtp-timeout-sec=10，意思是如果10秒内没收到RTP包，就认为通话断了，主动拆流。这个能兜底，但问题是正常通话中途也有静音时段，静音的时候没RTP包是正常的。所以单纯靠这个参数会误杀。

我更推荐的方式是录音侧做时间窗口过滤，这个后面会说。

还有个参数是rtpengine侧的，改法如下：

# rtpengine配置文件 /etc/rtpengine/rtpengine.conf
[rtpengine]
listen-ng = 127.0.0.1:7722
interface = internal/10.0.0.1
interface = external/192.168.1.100
timeout = 60

silent-timeout = 5
offer-timeout = 300

[logging]
level = 3

silent-timeout = 5是静默超时。超过5秒没收到有效媒体就认为是静默。但这个参数对幽灵流没用，因为幽灵流本身就是”有效媒体”，rtpengine不会过滤它。

常见坑

说几个我踩过的坑：

坑1：以为FreeSWITCH的BYE日志干净就代表没问题

FreeSWITCH日志显示BYE处理正常，不代表对端网关也正常。FreeSWITCH只能保证自己这一侧的信令交互没问题，但对端网关的媒体栈怎么实现它管不了。很多新手会卡在这个地方反复查FS配置，浪费时间。

坑2：rtpengine的”dropped”字段不等于幽灵流

rtpengine日志里看到dropped:no不要直接跳过。dropped是rtpengine自己丢包策略的标记，不是对端缓冲的标记。真正要看的是seq和ts的时间关系，以及它们和BYE时间的对比。

坑3：录音模块的”通话结束时间”取错了时间点

有些录音模块记录”通话结束时间”用的是录音停止的时间，而不是FreeSWITCH收到BYE的时间。这两个时间可能差好几秒。应该以后者为准。

坑4：运营商说”网关没问题”别轻易信

运营商的运维经常只看上层日志，说”BYE处理了”就认为没问题。但他们不一定能看到网络栈层面的缓冲日志。你可以让他们抓对端侧的RTP包，或者让他们查网关的发送队列长度。

坑5：留的缓冲余量太小

我第一次实现录音过滤时，留了2秒余量。结果发现还有5%的幽灵流没过滤掉。大部分运营商网关缓冲在6秒以内，但有少数能到8-9秒。留5秒比较稳妥。

解决方案

你改不了运营商网关。但有几个思路：

方案1：录音侧做时间窗口过滤（推荐）

最实用的做法。录音进程维护一个”通话结束时间”，超过N秒的包直接丢弃：

# 伪代码，录音处理逻辑
import logging
from datetime import datetime

class RTPRecorder:
    def __init__(self, call_id, bye_time, buffer_seconds=5):
        self.call_id = call_id
        self.bye_time = bye_time
        self.cutoff_time = bye_time + buffer_seconds  # 留5秒缓冲余量
        self.logger = logging.getLogger(f"recorder.{call_id}")
        self.packet_count = 0
        self.dropped_count = 0

    def process_packet(self, pkt):
        pkt_time = pkt.timestamp

        # 通话结束前5秒内的包，正常处理
        if pkt_time < self.bye_time - 5:
            self.dropped_count += 1
            self.logger.debug(f"Packet too old, dropping: {pkt_time}")
            return

        # 超过通话结束+缓冲余量的，直接扔
        if pkt_time > self.cutoff_time:
            self.dropped_count += 1
            if self.packet_count > 0:  # 只记录有意义的丢弃
                self.logger.warning(
                    f"Stale RTP after BYE: {pkt_time - self.bye_time:.1f}s, "
                    f"dropped={self.dropped_count}"
                )
            return

        self.packet_count += 1
        self.write_to_file(pkt)

5秒的余量是经验值。大部分运营商网关的缓冲不会超过这个。但如果你发现你们合作的运营商缓冲特别大，可以适当调大。

方案2：和运营商协调

如果差得太多（超过10秒），得找运营商调整网关配置。网关侧一般有这些参数可以调：

参数 说明 典型值
rtp-buffer-flush 收到BYE后是否立即清空缓冲 disable/enable
rtp-buffer-size 发送缓冲大小 20-100ms
silence-timeout 静默超时后停止发送 500-2000ms

不过说实话，运营商一般不愿意动这个。换成国内厂商的网关，或者走专线能好一点。

方案3：FreeSWITCH侧加RTP超时检测

FreeSWITCH有个参数可以强制检测对端是否还活着：

<!-- 开关配置 -->
<param name="enable-100rel" value="true"/>
<param name="pt1min" value="30"/>
<param name="pt1max" value="300"/>

pt1max是Prack最大延迟。如果对端在规定时间内不响应，FreeSWITCH会主动拆流。

不过这个治标不治本。幽灵流的源头是对端缓冲，你不从录音侧做过滤，永远会有漏网之鱼。

上线后评估

我们后来用的是方案1，上线跑了一周，数据明显好转：

指标 上线前 上线后
异常录音占比 3.0% 0.12%
最大差值 11分23秒 8秒
平均差值 8.7秒 1.2秒
质检误判率 2.8% 0.09%

剩下的0.12%是什么情况？有两个原因：

  1. 对端网关缓冲超了5秒。有个别通话的幽灵流持续了7-8秒，我们留的余量不够。不过占比很低，懒得单独处理了。

  2. 时间同步问题。录音服务器和对端网关的NTP时间有微小偏差，导致”通话结束时间”的记录本身就有误差。这个需要找运营商一起对时。

验证命令：

# 统计异常录音（录音时长 - 通话时长 > 10秒的）
psql -d freeswitch_cdr -c """
SELECT 
  call_id,
  actual_duration,
  recording_duration,
  recording_duration - actual_duration as diff
FROM call_records 
WHERE recording_duration - actual_duration > 10
ORDER BY diff DESC
LIMIT 20;
"""

# 对比上线前后
# 上线前：386条异常
# 上线后：15条异常（都是缓冲超5秒的）

正常情况下，误差应该在5秒以内（录音启动/停止的正常抖动）。如果超过10秒，说明还有漏网的幽灵流。

总结

  1. BYE正常不代表RTP立即停。SIP的BYE是信令层的，对端网关收到BYE后，它的媒体缓冲可能还在往外吐包。

  2. 抓包是金标准。别只看日志，把RTP流的时间轴拉出来，问题一目了然。

  3. 录音侧必须做时间窗口保护。别假设对端会乖乖听话。

  4. 这个锅不该FreeSWITCH背。大多数工程师第一反应是”FS的BYE没处理好”，其实FS很冤。

  5. 留足够的缓冲余量。5秒是个不错的起点，但如果你发现还有漏网之鱼，可以适当调大。

如果你们也有类似的通话质检问题，先抓个包看看，是不是也是对端网关在”放余音”。

发表回复

您的邮箱地址不会被公开。 必填项已用 * 标注

49 + = 51