使用Cisco IP电话7800/8800系列的CLI调试输出排除单向音频问题
简介
本文档介绍在CLI中为单向音频问题生成的Cisco IP电话7800/8800系列调试的日志分析。
思科电话7800/8800系列单向音频问题故障排除
排除单向音频故障时，首要任务是绘制拓扑并确定RTP媒体（实时协议）路径和发送和接收RTP流的设备。一个特别复杂的任务是确定IP电话是否在发送和接收流。
最常见的方法是从思科IP电话收集数据包捕获，如相关文章所述。但是，在大多数情况下，当问题间歇性出现时，确定下次受单向音频问题影响的电话会非常困难。
本文采用了一种替代方法。它非常有用，特别是在处理偶发的单向音频问题时。
捕获日志
步骤1.在IP电话上启用SSH。
步骤2.可选步骤。配置将电话日志转储到系统日志服务器。
如前所述，单向音频问题通常是间歇性的。需要配置将日志转储到远程系统日志服务器的选项，使多个电话受到影响。
在思科统一通信管理器(CUCM)中，启用以下参数。
重置电话。
步骤3.通过SSH协议登录电话的CLI。
步骤4.启用电话日志。
DEBUG> settmask -p ms -t 0xfffff -b LOG_DEBUG
DEBUG> debug lsm vcm fim fsm gsm
debugs: fim fsm gsm lsm sip-state sip-messages sip-reg-state ccdefault vcm
DEBUG> debug jvm SIPCC
DEBUG> Successfully executed the command.
步骤5.开始转储日志。
DEBUG> sdump
步骤6.通过重置电话取消日志收集。
呼叫详细信息
Calling phone firmware: sip78xx.10-3-1-12 Calling phone ip address: 10.62.153.20 Calling phone number: 5035 Called phone ip address: 10.229.16.243 Called phone number: 2211 CUCM version: 11.0.1.20000-2 CUCM Publisher ip address: 10.48.47.143 CUCM Subscriber ip address: 10.48.47.136 CUBE: 10.62.150.10
信令分析
首先需要找到存在单向音频问题的呼叫的信令。
最简单的方法是使用被叫号码作为搜索参数。
电话向CUCM订用服务器发送INVITE消息。并接收标准回复。呼叫ID记录允许跟踪此特定呼叫的所有相关消息。
0611 DEB Dec 21 14:33:00.127717 JAVA-sipio-sent---> INVITE sip:2211@10.48.47.136;user=phone SIP/2.0^M
Via: SIP/2.0/TCP 10.62.153.20:52464;branch=z9hG4bK2037857c^M
From: "5035" <sip:5035@10.48.47.136>;tag=c80084aa872103164b6d6bb1-699aac4f^M
To: <sip:2211@10.48.47.136>^M
Call-ID: c80084aa-8721000b-302564ee-403d3d01@10.62.153.20^M
Max-Forwards: 70^M
Date: Wed, 21 Dec 2016 14:33:00 GMT^M
CSeq: 101 INVITE^M
User-Agent: Cisco-CP7821/10.3.1^M
Contact: <sip:2fbf6265-bffc-4f99-b8b2-40dce7ed2d19@10.62.153.20:52464;transport=tcp>^M
Expires: 180^M
Accept: application/sdp^M
Allow: ACK,BYE,CANCEL,INVITE,NOTIFY,OPTIONS,REFER,REGISTER,UPDATE,SUBSCRIBE,INFO^M
Remote-Party-ID: "5035" <sip:5035@10.48.47.136>;party=calling;id-type=subscriber;privacy=off;screen=yes^M
Supported: replaces,join,sdp-anat,norefersub,resource-priority,extended-refer,X-cisco-callinfo,X-cisco-serviceuri,X-cisco-escapecodes,X-cisco-service-control,X-cisco-srtp-fallback,X-cisco-monrec,X-cisco-config,X-cisco-sis-7.0.0,X-cisco-xsi-8.5.1^M
Allow-Events: kpml,dialog^M
Content-Length: 348^M
Content-Type: application/sdp^M
Content-Disposition: session;handling=optional^M
^M
v=0^M
o=Cisco-SIPUA 7726 0 IN IP4 10.62.153.20^M
s=SIP Call^M
t=0 0^M
m=audio 27986 RTP/AVP 9 0 8 116 18 101^M
c=IN IP4 10.62.153.20^M
a=rtpmap:9 G722/8000^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:8 PCMA/8000^M
a=rtpmap:116 iLBC/8000^M
a=fmtp:116 mode=20^M
a=rtpmap:18 G729/8000^M
a=fmtp:18 annexb=yes^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
a=sendrecv^M
0650 DEB Dec 21 14:33:00.171483 JAVA-sipio-recv<--- SIP/2.0 100 Trying^M
0782 DEB Dec 21 14:33:00.249127 JAVA-sipio-recv<--- SIP/2.0 180 Ringing^M
在8秒内，被叫方应答呼叫并建立音频流。务必记下协商的介质地址。媒体地址在INVITE和200 OK消息中协商，以用于早期提供SIP模式，在200 OK后面是ACK，以用于延迟提供模式。
1150 DEB Dec 21 14:33:08.179266 JAVA-sipio-recv<--- SIP/2.0 200 OK^M
Via: SIP/2.0/TCP 10.62.153.20:52464;branch=z9hG4bK2037857c^M
From: "5035" <sip:5035@10.48.47.136>;tag=c80084aa872103164b6d6bb1-699aac4f^M
To: <sip:2211@10.48.47.136>;tag=59591~c6f18c49-d13e-4c97-aefc-039c35dcaca0-37698453^M
Date: Wed, 21 Dec 2016 14:32:59 GMT^M
Call-ID: c80084aa-8721000b-302564ee-403d3d01@10.62.153.20^M
CSeq: 101 INVITE^M
Allow: INVITE, OPTIONS, INFO, BYE, CANCEL, ACK, PRACK, UPDATE, REFER, SUBSCRIBE, NOTIFY^M
Allow-Events: presence^M
Supported: replaces^M
Server: Cisco-CUCM11.0^M
Call-Info: ; security= NotAuthenticated; orientation= to; gci= 2-6064; isVoip; call-instance= 1^M
Send-Info: conference, x-cisco-conference^M
Remote-Party-ID: <sip:2211@10.48.47.136>;party=called;screen=no;privacy=off^M
Session-ID: f329a19bdd6e9960881d66e6bab59592;remote=7d416919fab94807bcc061c4baa59591^M
Remote-Party-ID: <sip:2211@10.48.47.136;user=phone>;party=x-cisco-original-called;privacy=off^M
Contact: <sip:2211@10.48.47.136:5060;transport=tcp>^M
Content-Type: application/sdp^M
Content-Length: 236^M
^M
v=0^M
o=CiscoSystemsCCM-SIP 59591 1 IN IP4 10.48.47.136^M
s=SIP Call^M
c=IN IP4 10.62.150.10^M
b=TIAS:64000^M
b=AS:64^M
t=0 0^M
m=audio 23672 RTP/AVP 0 101^M
a=ptime:20^M
a=rtpmap:0 PCMU/8000^M
a=rtpmap:101 telephone-event/8000^M
a=fmtp:101 0-15^M
最后，查找呼叫终止消息。
2081 DEB Dec 21 14:33:18.688956 JAVA-sipio-recv<--- BYE sip:2fbf6265-bffc-4f99-b8b2-40dce7ed2d19@10.62.153.20:52464;transport=tcp SIP/2.0^M
Via: SIP/2.0/TCP 10.48.47.136:5060;branch=z9hG4bK17c47b18ed76^M
From: <sip:2211@10.48.47.136>;tag=59591~c6f18c49-d13e-4c97-aefc-039c35dcaca0-37698453^M
To: "5035" <sip:5035@10.48.47.136>;tag=c80084aa872103164b6d6bb1-699aac4f^M
Date: Wed, 21 Dec 2016 14:33:07 GMT^M
Call-ID: c80084aa-8721000b-302564ee-403d3d01@10.62.153.20^M
User-Agent: Cisco-CUCM11.0^M
Max-Forwards: 70^M
CSeq: 101 BYE^M
Reason: Q.850;cause=16^M
Session-ID: f329a19bdd6e9960881d66e6bab59592;remote=7d416919fab94807bcc061c4baa59591^M
Remote-Party-ID: <sip:2211@10.48.47.136;user=phone>;party=x-cisco-original-called;privacy=off^M
Content-Length: 0^M
^M
媒体流分析
分析任何黑匣子设备时，都要注意时间戳，特别是与呼叫上下文相关的时间戳。
查找确认传输尚未激活。
0407 NOT Dec 21 14:33:00.082822 ms-RTCPMGR.rtcpm_getSr[A:17] TX stream state not connected [ingress=0][state=0] 1144 NOT Dec 21 14:33:08.152988 ms-RTCPMGR.rtcpm_getSr[A:17] TX stream state not connected [ingress=7][state=1]
更新接收(RX)音频流参数的消息。
1380 NOT Dec 21 14:33:08.220957 ms-RTPSESSION.ms_updateRTPRxParam[A:17] UPDATE RX [mediaType(codec)=4][dynamicPayloadType=0][hootNumTalkers=0][dtmfPayloadType=101][pktperiod=20][security=0] 1481 INF Dec 21 14:33:08.282028 ms-RCVMGR.receiveManagerStartReceive[A:17] Start RX 5: syncId 5, codec 16, rtnCode 0
显示与传输(TX)音频流有关的信息的消息。
1668 DEB Dec 21 14:33:08.380273 ms-RTPSESSION.startRTPSessionTx[A:17] enter 1670 DEB Dec 21 14:33:08.380395 ms-RTPMGR.rtpmgr_txStart[A:17] [streamId=7] enter 1673 INF Dec 21 14:33:08.380609 ms-MGRRTP.rtpTransmitStart[A:17] TX [CT=1][msPktSz=20][Ssrc=0xE322D7C2][Csrc=0x0][fTyp=0][SPF=80][FPP=2][pktSz=236][Buf=Y] 1674 INF Dec 21 14:33:08.380670 ms-MGRRTP.rtpTransmitStart[A:17] RFC2833: [PT=101][tsscale=8][pktPeriod=20][step=10][sizeof=4] 1771 NOT Dec 21 14:33:08.407650 ms-RTPSESSION.ms_startRTPSessionTx[A:17] START TX: [mediaType(codec)=4][pkt size=20][remote IPv4=10.62.150.10][rport=23672][groupid=8][callid=8]
可以通过ONHOOK状态转换找到呼叫终止。
2113 NOT Dec 21 14:33:18.699974 JAVA-SIPCC-CC_API: 1/8, cc_int_onhook: GSM -> SIP: ONHOOK
After the call is terminated RTP statistics will be displayed. From this message it is clear that the phone did not receive any packets, so the next step would be to enable packet captures on the CUBE.
2121 NOT Dec 21 14:33:18.701225 ms-MS.statm_printDecoderStats[A:17]
[Rx Count=0][Rx Lost=0][Pkts Discarded=0][Rx Octets=0]
[Avg Jitter=0][Max Jitter=0]
[RFC2833=0]
[CCR=0.0000][ICR=0.0000][MaxCR=0.0000][CS=0][SCS=0]
Encoder stats display that 514 packets were sent.
2124 NOT Dec 21 14:33:18.701897 ms-MS.statm_printEncoderStats[A:17]
[Tx Count=514][TX Octets=82240]
反馈