This document describes log analysis of the debugs generated in command line interface (CLI) for Cisco IP phone 7800/8800 series for one way audio issue.
Troubleshoot Cisco Phone 7800/8800 Series One Way Audio Issues
When troubleshooting one way audio problem the very first task is to draw the topology and determine RTP media (Real-Time Protocol) path and devices that send and receive RTP streams. Particularly complex task is to figure out whether IP phone was sending and receiving the streams.
The most common way is to collect a packet capture from Cisco IP phone as described in the respective article. But in most cases when the problem is intermittent it is challenging to determine the phone that will be affected by the one way audio issue next time.
In this article an alternative method is used. It can be very useful especially when dealing with sporadic one way audio issues.
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
In eight seconds called party answers the call and the audio streams are established. It is important to note down negotiated media addresses. Media addresses are negotiated in INVITE and 200 OK messages for early offer SIP mode, and in 200 OK followed by ACK for delayed offer mode.
When analysing any black box device pay attention to the timestamps especially with a relation to a call context.
Find confirmation that the transmittion is not active yet.
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]
Messages to update receiving (RX) audio streams parameters. 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
Messages that display information regarding transmitted (TX) audio stream. 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]
Call termination can be found with ONHOOK state transition. 2113 NOT Dec 21 14:33:18.699974 JAVA-SIPCC-CC_API: 1/8, cc_int_onhook: GSM -> SIP: ONHOOK
After 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]
Tip: Call duration can be counted by dividing the number of transmitted packets on the packetization period. In the example 514 / 50 = 10.28 seconds.