SIPP 压测 IVR,FreeSWITCH收到了DTMF按键,但无法识别的问题


        昨天咱们团队的测试小姐姐跑过来找我,说通过SIPP压测IVR时,发现业务日志中没看到采集的按键,让我帮忙看看是哪里出了问题。         明明以前可以运行的脚本,为啥放在现在的环境玩不转了呢?!一番拔丝抽茧后,问题被解决了……           今早运动后,看了一眼窗外,风未止,雨已停。既然周末时光如此美好,思虑三秒后,决定写个随笔总结一下,毕竟年纪大了,好记性不如烂笔头嘛!         说干咱就干,兄dei,让我们一起来解开呼叫中心IVR业务压测“事故现场”之谜吧         

一、问题现象:

  SIP和FS可以成功建立通话,并且SIPP脚本中明确采用读取pcap文件的方式发送了DTMF按键,但FS日志上看却没有收到按键信息(即没有打印 RTP RECV DTMF的字样)

二、运行环境

  SIPP 版本 : v3.4.1-TLS-PCAP-RTPSTREAM built Jan 23 2017, 18:38:09   FS 版本    :v1.6.20   OS 版本   : CentOs 7.9

二、问题分析

  首先,咱检查下自己的SIPP脚本是否正确        仔细确认过眼神,SIPP脚本中虽然给FS回ACK部分有些问题,但并不是影响按键的原因。发送按键的代码并没写错,确实发了按键,日志也能佐证。
 1 压测脚本目录:
 2 ../sipp_script/
 3 ├── caller_ivr.xml
 4 ├── ivrsipp.cvs
 5 ├── pcap
 6 │   └── dtmf_2833_4.pcap
 7 └── sipp
 8 
 9 
10 caller_ivr.xml  文件中发送按键的内容
11 
12 
13   "3000"/>
14   
15         
16                 "pcap/dtmf_2833_4.pcap"/>
17                 "Call_num: [$caller_num1] send dtmf 4===================="/>
18         
19   
20 
21 vi caller_ivr_5648_logs.log SIPP日志,可以看到已经执行了发按键
22 
23 ===========From is Custom header is 491998 10.21.39.117
24 ===========From is Custom header is 491998
25 Call_num: 491998 send dtmf 4====================
:SIPP压测代码和日志   其次,咱看看FS日志,找找事故现场的蛛丝马迹   过滤后发现两点:
  • FS日志里确实没有打印按键信息,因为没有打印 RTP RECV DTMF
  • 通话的SDP里没检测到rfc2833, 被改用INFO 模式传输了
1 [powerop@FATD00194498 logs]$ grep e3bdf4d6-8ef5-48e4-9ed3-e48aa6b35a3c freeswitch.log* | grep "dtmf\|DTMF"
2 e3bdf4d6-8ef5-48e4-9ed3-e48aa6b35a3c tid:[139758169360128] 2022-02-18 13:23:34.924687 [DEBUG] switch_core_media.c:4784 No 2833 in SDP.  Disable 2833 dtmf and switch to INFO
3 e3bdf4d6-8ef5-48e4-9ed3-e48aa6b35a3c tid:[139758169360128] 2022-02-18 13:23:34.924687 [DEBUG] switch_core_media.c:7220 sofia/external/491998@10.2.85.25 Set rtp dtmf delay to 40
:FS排查日志

  我们用软电话注册呼叫的方式测试一通,软电话按键模式采用rfc2833,FS可以收到按键,日志是下面这样的:

85ea46bd-ec8e-434e-9f55-a869738ef2ad tid:[139758169360128] 2022-02-18 13:25:53.664688 [DEBUG] switch_core_media.c:4777 sofia/external/1022@10.2.32.142 Set 2833 dtmf send payload to 101 recv payload to 101
85ea46bd-ec8e-434e-9f55-a869738ef2ad tid:[139758169360128] 2022-02-18 13:25:53.664688 [DEBUG] switch_core_media.c:7190 sofia/external/1022@10.2.32.142 Set 2833 dtmf send payload to 101
85ea46bd-ec8e-434e-9f55-a869738ef2ad tid:[139758169360128] 2022-02-18 13:25:53.664688 [DEBUG] switch_core_media.c:7197 sofia/external/1022@10.2.32.142 Set 2833 dtmf receive payload to 101
85ea46bd-ec8e-434e-9f55-a869738ef2ad tid:[139758169360128] 2022-02-18 13:25:53.664688 [DEBUG] switch_core_media.c:7220 sofia/external/1022@10.2.32.142 Set rtp dtmf delay to 40
85ea46bd-ec8e-434e-9f55-a869738ef2ad tid:[139758169360128] 2022-02-18 13:25:56.004688 [DEBUG] switch_rtp.c:7738 RTP RECV DTMF 4:1440
85ea46bd-ec8e-434e-9f55-a869738ef2ad tid:[139758169360128] 2022-02-18 13:25:56.004688 [INFO] switch_channel.c:515 RECV DTMF 4:1440
:FS能解析按键的日志         然后,既然客户端发送了按键,但FS日志没有打印出来,咱就看看是不是因为网络原因,导致服务端FS没有收到RTP吧         咱在服务端FS上抓包,从文件看,FS其实是收到了SIPP确实发了DTMF的,但最终没有解析出来         

        

  到这里,咱其实已经能得出下面一个结论:网络没有问题,问题出在FS上,应该是FS无法解析SIPP传输的inbound带内按键模式 ,只能处理RFC2833按键。           BTW,关于DTMF在呼叫中心业务中的传输方式通常包含 outbound带外传输(SIP INFO)、inbound带内传输(DTMF放在RTP流中)、RFC2833(严格的讲也算inbound模式,只是这个有特殊的Payload Type值 101),这里不进行发散介绍了,有兴趣的同学就自行度娘吧。         不过,我们可以顺道来看看SIP报文,发现SIPP测试时,FS回复的 200 OK 的 SDP里没有 DTMF 2833 信息,进一步佐证了咱前面的结论。
FS回复的异常200 OK FS回复的正常200 OK
SIP/2.0 200 OK Via:  SIP/2.0/UDP 10.2.85.25:5070;branch=z9hG4bK14d6.216056d2.0 Via:  SIP/2.0/UDP 10.2.32.116:20001;branch=z9hG4bK-22926-1-0 Record-Route:   From:  491998 ;tag=1 To:  331054 ;tag=Z0ZXmD2ev4yBp Call-ID: 1-22926@10.2.32.116 CSeq:  1 INVITE Contact:   User-Agent:  FreeSWITCH-mod_sofia/1.6.20~64bit Accept:  application/sdp Allow:  INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported:  timer, path, replaces Allow-Events:  talk, hold, conference, refer Content-Type:  application/sdp Content-Disposition:  session Content-Length:  198 Remote-Party-ID:  "331054" ;party=calling;privacy=off;screen=no   v=0 o=FreeSWITCH 1645141666 1645141667 IN IP4 10.21.39.117 s=FreeSWITCH c=IN IP4 10.21.39.117 t=0 0 m=audio 20148 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=ptime:20 a=rtcp:20149 IN IP4 10.21.39.117 SIP/2.0 200 OK Via:  SIP/2.0/UDP 10.2.85.25:5070;branch=z9hG4bK57df.e5d8b5c2.0 Via:  SIP/2.0/UDP 10.2.32.142:5080;received=10.2.32.142;rport=5080;branch=z9hG4bKp449tF2aKt50r Record-Route:   From:  "Extension 1022" ;tag=1Htg00NZF7j2j To:  ;tag=m04rB9St6S40e Call-ID: 1555d89c-0b1e-123b-a58b-fa163e1b47d2 CSeq:  48027184 INVITE Contact:   User-Agent:  FreeSWITCH-mod_sofia/1.6.20~64bit Accept:  application/sdp Allow:  INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported:  timer, path, replaces Allow-Events:  talk, hold, conference, refer Content-Type:  application/sdp Content-Disposition:  session Content-Length:  254 X-FS-Display-Name:  331054 X-FS-Display-Number:  sip:331054@10.2.85.25 X-FS-Support:  update_display,send_info Remote-Party-ID:  "331054" ;party=calling;privacy=off;screen=no   v=0 o=FreeSWITCH 1645135459 1645135460 IN IP4 10.21.39.117 s=FreeSWITCH c=IN IP4 10.21.39.117 t=0 0 m=audio 26494 RTP/AVP 0 101 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20 a=rtcp:26495 IN IP4 10.21.39.117
SIPP 发送的INVITE 【以下给的是OpenSIPs上转发给FS的报文】 软电话测试发起的INVITE 【以下给的是OpenSIPs上转发给FS的报文】
INVITE sip:331054@10.21.39.117:5080 SIP/2.0 Record-Route:   Via:  SIP/2.0/UDP 10.2.85.25:5070;branch=z9hG4bK14d6.216056d2.0 Via:  SIP/2.0/UDP 10.2.32.116:20001;branch=z9hG4bK-22926-1-0 From:  491998 ;tag=1 To:  331054 Call-ID: 1-22926@10.2.32.116 CSeq:  1 INVITE Contact:   Max-Forwards:  69 Subject:  Call Performance Test user-agent:  SIPp client mode version unknown Content-Type:  application/sdp Content-Length:    200 X-UUI:  &XCID=09469f19016451618148EXCIDEND X-CID:  09469f19016451618148EXCIDEND   v=0 o=user1 53655765 2353687637 IN IP4 10.2.32.116 s=- c=IN IP4 10.2.32.116 t=0 0 m=audio 6000 RTP/AVP 0 a=rtpmap:0 PCMU/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-11,16   【这里是脚本故意为之,咱用不到12-15】 a=sendrecv INVITE sip:331054@10.21.39.117:5080 SIP/2.0 Record-Route:   Via:  SIP/2.0/UDP 10.2.85.25:5070;branch=z9hG4bK57df.e5d8b5c2.0 Via:  SIP/2.0/UDP 10.2.32.142:5080;received=10.2.32.142;rport=5080;branch=z9hG4bKp449tF2aKt50r Max-Forwards:  68 From:  "Extension 1022" ;tag=1Htg00NZF7j2j To:   Call-ID: 1555d89c-0b1e-123b-a58b-fa163e1b47d2 CSeq:  48027184 INVITE Contact:   User-Agent:  FreeSWITCH-mod_sofia/1.6.20+git~20201225T055006Z~c731e3fe87~64bit Allow:  INVITE, ACK, BYE, CANCEL, OPTIONS, MESSAGE, INFO, UPDATE, REGISTER, REFER, NOTIFY Supported:  timer, path, replaces Allow-Events:  talk, hold, conference, refer Content-Type:  application/sdp Content-Disposition:  session Content-Length:  242 X-FS-Support:  update_display,send_info Remote-Party-ID:  "Extension 1022" ;party=calling;screen=yes;privacy=off X-UUI:  &XCID=0aab741d616451619532EXCIDEND X-CID:  0aab741d616451619532EXCIDEND   v=0 o=FreeSWITCH 1645138423 1645138424 IN IP4 10.2.32.142 s=FreeSWITCH c=IN IP4 10.2.32.142 t=0 0 m=audio 23530 RTP/AVP 0 8 101 a=rtpmap:0 PCMU/8000 a=rtpmap:8 PCMA/8000 a=rtpmap:101 telephone-event/8000 a=fmtp:101 0-16 a=ptime:20
          接下来检查FS配置文件 vars.xml ,  发现文件中没有配置 rtp_liberal_dtmf ,导致无法兼容非常规的按键模式。   三、解决问题         调整FS vars.xml 文件,增加下面蓝色加粗部分的配置项, 重启FS,问题解决
1   
2   "set" data="suppress_cng=true"/>
3 
4   
5   "set" data="rtcp_mux=false"/>
6   "set" data="rtcp_audio_interval_msec=3000"/>
7 
8   
9   

        重新运行SIPP压测脚本,成功获取到按键,得到FS日志如下:

SDP中没有2833,所以FS自动进行兼容,增加 101 telephone-event SDP 头
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:35.942635 [DEBUG] switch_core_media.c:4738 No 2833 in SDP. Liberal DTMF mode adding 101 as telephone-event.
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:35.942635 [DEBUG] switch_core_media.c:4767 sofia/external/491998@10.2.32.142 Set 2833 dtmf send payload to 101 recv payload to 101
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:35.942635 [DEBUG] switch_core_media.c:7180 sofia/external/491998@10.2.32.142 Set 2833 dtmf send payload to 101
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:35.942635 [DEBUG] switch_core_media.c:7187 sofia/external/491998@10.2.32.142 Set 2833 dtmf receive payload to 101
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:35.942635 [DEBUG] switch_core_media.c:7210 sofia/external/491998@10.2.32.142 Set rtp dtmf delay to 40
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:39.082643 [DEBUG] switch_rtp.c:7534 RTP RECV DTMF 4:2240
acd3b564-90be-11ec-9fca-9785bd7be268 tid:[139932390749952] 2022-02-18 21:28:39.082643 [INFO] switch_channel.c:515 RECV DTMF 4:2240
:FS日志,按键采集成功   附录: SDP 信息中 【 a=fmtp:101 0-11,16】 的含义 101 : 代表是采用rfc2833 telephone-event模式传输按键 0-11,16 :代表支持的DTMF按键 
DTMF-related named Event Event encoding (decimal)
0–9 0–9
* 10
# 11
A–D 12–15
Flash 16

  Tips,对于编写SIPP脚本不是很熟练的同学,可以通过用软电话注册拨打测试,并进行抓包,然后分析抓包文件中SIP 信令,按照信令内容编写SIPP脚步即可。

  这里给出本次测试的SIPP脚步和抓包文件,供大家参看。

  • SIPP测试脚本+抓包文件
  • SIPP使用手册