昨天咱們團隊的測試小姐姐跑過來找我,說通過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 <pause milliseconds="3000"/> 14 <nop> 15 <action> 16 <exec play_pcap_audio="pcap/dtmf_2833_4.pcap"/> 17 <log message="Call_num: [$caller_num1] send dtmf 4===================="/> 18 </action> 19 </nop> 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====================
其次,咱看看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
我們用軟電話注冊呼叫的方式測試一通,軟電話按鍵模式采用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沒有收到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: <sip:10.2.85.25:5070;lr;did=a0d.0f8a73e6>
From: 491998 <sip:491998@10.2.85.25>;tag=1
To: 331054 <sip:331054@10.2.85.25>;tag=Z0ZXmD2ev4yBp
Call-ID: 1-22926@10.2.32.116
CSeq: 1 INVITE
Contact: <sip:331054@10.21.39.117:5080;transport=udp>
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" <sip:331054@10.2.85.25>;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: <sip:10.2.85.25:5070;lr;did=9cf.c6140023>
From: "Extension 1022" <sip:1022@10.2.32.142>;tag=1Htg00NZF7j2j
To: <sip:331054@10.2.85.25:5070>;tag=m04rB9St6S40e
Call-ID: 1555d89c-0b1e-123b-a58b-fa163e1b47d2
CSeq: 48027184 INVITE
Contact: <sip:331054@10.21.39.117:5080;transport=udp>
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" <sip:331054@10.2.85.25>;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: <sip:10.2.85.25:5070;lr;did=a0d.0f8a73e6>
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 <sip:491998@10.2.85.25>;tag=1
To: 331054 <sip:331054@10.2.85.25>
Call-ID: 1-22926@10.2.32.116
CSeq: 1 INVITE
Contact: <sip:491998@10.2.32.116:20001>
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: <sip:10.2.85.25:5070;lr;did=9cf.c6140023>
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" <sip:1022@10.2.32.142>;tag=1Htg00NZF7j2j
To: <sip:331054@10.2.85.25:5070>
Call-ID: 1555d89c-0b1e-123b-a58b-fa163e1b47d2
CSeq: 48027184 INVITE
Contact: <sip:mod_sofia@10.2.32.142:5080>
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" <sip:1022@10.2.32.142>;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 <!--close rtp cng 2021-04-29--> 2 <X-PRE-PROCESS cmd="set" data="suppress_cng=true"/> 3 4 <!--open rtcp cng 2021-11-11--> 5 <X-PRE-PROCESS cmd="set" data="rtcp_mux=false"/> 6 <X-PRE-PROCESS cmd="set" data="rtcp_audio_interval_msec=3000"/> 7 8 <!-- Enable liberal DTMF for those that can't get it right --> 9 <X-PRE-PROCESS cmd="set" data="rtp_liberal_dtmf=true"/>
重新運行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
附錄:
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腳步和抓包文件,供大家參看。