CCM6.1.1, MGCP 2821, one way audio

richb1971 · ‎04-28-2011

Hi,

Got a CUCM 6.1.1 and an MGCP 2821. Was working fine but we're getting one way audio now. This is intermittent but frequent enough to be a major problem. The 1 way audio is both ongoing and incoming via the ISDN E1. I have bound the MGCP to the only live interface on the 2821, restarted all servers and the 2821-no difference.

Can some suggest a starting point?

Rich

barry · ‎04-28-2011

Hi Rich

Assuming purely internal calls (i.e. those that don't go out via the MGCP gateway) aren't ever impacted couple of ways you can go about this:

1. If you have active Smartnet on the gateway you can raise a TAC case. TAC have tools where they can dump audio calls out when they are received by PRI/DSPs and listen to them (one in each direction) to see if your audio is making it on over the PRI. This has saved me on loads of occasions - for one way audio and DTMF issues.

2. If you don't have active maintenance, I would start by capturing traffic in / out of the gateway using a sniffer product (e.g. Wireshark) + Switch Port mirror. If you manage to capture and identify a failing call, you can replay the captured RTP streams to see if you have audio in each direction. I have a high level document on how to do this if you need it.

Once you know if the audio is or isn't making it in over the PRI interface, you can plan your next steps.

If do you (2), and it shows no audio, it could either be a carrier or gateway issue, however it will assist you in removing your LAN / phones from being the cause of the problem.

Barry

richb1971 · ‎04-28-2011

Barry,

Thanks for your reply. Unfortunately its option 2. Could you post the documentation that'll help me progress? As you can see from the screenshot theres a few line slips.... anything that can help me prove its the supplier?

Rich

barry · ‎04-28-2011

Hi Rich

I'll post a document covering how to replay audio when I get back to my office.

In terms of clock slips, they generally don't cause one way audio, rather just "clicks" that don't really impact speech. They do however cause fax machines loads of problems.

Try the "network-clock-select" command to sort this out and point it at your PRI.

Document is now attached.

Barry

Message was edited by: barry@nettitude.uk.com

richb1971 · ‎05-03-2011

Thanks Barry-I'll try it asap and report findings.

richb1971 · ‎05-03-2011

Hi Barry,

I've collected some logs from RTMT and noticed the 'recvonly' keeps appearing on the 1 way audio calls:

05/03/2011 15:53:17.820 CCM|MGCPHandler send msg SUCCESSFULLY to: 172.16.1.253
CRCX 4419 S0/SU0/DS1-0/2@MYCOM_2851.mycom.local MGCP 0.1
C: D00000000ac14531000000F580000002
X: 2
L: p:20, a:PCMU, s:off, t:b8
M: recvonly
R: D/[0-9ABCD*#]
Q: process,loop

Sounds related. Any ideas?

Rich

barry · ‎05-03-2011

Hi Rich

Could be related. The MGCP state should switch to M: sendrecv once two way communications are established.

An RTP trace will however tell us whether any audio is being received over the PRI.

Attached is a link to an MGCP debug document.

http://www.cisco.com/en/US/products/sw/voicesw/ps556/products_tech_note09186a0080174804.shtml

Barry

richb1971 · ‎05-04-2011

Hi Barry,

I've collected a wireshark file and can see and play both sides of the audio but the external caller still hears nothing. I spanned the switch port the IP phone was connected to. I guess the service provider is OK so not sure of next step.

Rich

barry · ‎05-05-2011

Hi Rich

Well done on replaying the audio. Took me about 2 weeks to get that working the first time I did it...

Doesn't obviously follow that the carrier is not having an issue. I would try and rerun the tracing at the port connecting to the gateway to see if the audio is making it that far; I can't think of any reason why it wouldn't, however worth checking.

If the audio is making it to the gateway (i.e your RTP stream in direction handset to gateway gets through in one piece) then you are faced with either a problem with the gateway itself (and most likely to be one of the DSPs having a problem), or the PRI / carrier itself. I don't know how easy it would be, but if you run a Q.931 trace on the gateway you could try and see if there is anything common in the calls that provide one way audio - in particular if they always go out over the same B channel number? Do you see anything in a "show log" command that would indicate any DSP issues? They are normally quite vocal when one of them has a problem.

If the audio isn't making it to the gateway, then you have an internal problem, and the carrier / gateway are out of the picture.

Either way, you may want to consider getting some form of Smartnet maintenance on your gateway. TAC have a very clever utility that allows them to capture and replay audio as it is processed by the DSPs on the gateway. This would allow you to prove immediately whether the problem was on the gateway / PRI or not.

Final question, my fading memory reminds me that I have seem something similar on CUCM 7.x when the gateway was in a separate region to the handset (although this was H.323 and not MGCP) and turned out to be a CUCM bug. Is your gateway in a different region?

Barry

richb1971 · ‎05-05-2011

Hi Barry,

Thanks for reply. I have run wireshark on the swicthport that connects to the voice gateway and could hear audio fine.

Heres the show log:

#sh log
Syslog logging: enabled (0 messages dropped, 47 messages rate-limited,
0 flushes, 0 overruns, xml disabled, filtering disabled)

No Active Message Discriminator.

No Inactive Message Discriminator.

    Console logging: level debugging, 3076 messages logged, xml disabled,
                     filtering disabled
    Monitor logging: level debugging, 1710 messages logged, xml disabled,
                     filtering disabled
    Buffer logging: level debugging, 3122 messages logged, xml disabled,
                     filtering disabled
    Logging Exception size (4096 bytes)
    Count and timestamp logging messages: disabled
    Persistent logging: disabled

No active filter modules.

ESM: 0 messages dropped

Trap logging: level informational, 769 message lines logged

Log Buffer (10000 bytes):
5:54.926: ISDN Se0/0/0:15 Q931: RX <- CONNECT pd = 8 callref = 0x803A
May 4 14:45:54.930: ISDN Se0/0/0:15 Q931: TX -> CONNECT_ACK pd = 8 callref = 0x003A
May 4 14:46:50.495: ISDN Se0/0/0:15 Q931: TX -> DISCONNECT pd = 8 callref = 0x0039
        Cause i = 0x8A90 - Normal call clearing
May 4 14:46:50.671: ISDN Se0/0/0:15 Q931: RX <- RELEASE pd = 8 callref = 0x8039
May 4 14:46:50.703: ISDN Se0/0/0:15 Q931: TX -> RELEASE_COMP pd = 8 callref = 0x0039
May 4 14:47:28.532: ISDN Se0/0/0:15 Q931: TX -> DISCONNECT pd = 8 callref = 0x003A
        Cause i = 0x8A90 - Normal call clearing
May 4 14:47:28.692: ISDN Se0/0/0:15 Q931: RX <- RELEASE pd = 8 callref = 0x803A
May 4 14:47:28.720: ISDN Se0/0/0:15 Q931: TX -> RELEASE_COMP pd = 8 callref = 0x003A
May 4 14:48:21.989: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8 callref = 0x0001
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Calling Party Number i = 0x2183, '7912345678'
                Plan:ISDN, Type:National
        Called Party Number i = 0x81, '114800'
                Plan:ISDN, Type:Unknown
May 4 14:48:22.017: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x8001
        Channel ID i = 0xA98381
                Exclusive, Channel 1
May 4 14:48:22.017: ISDN Se0/0/0:15 Q931: TX -> ALERTING pd = 8 callref = 0x8001
        Progress Ind i = 0x8088 - In-band info or appropriate now available
May 4 14:48:38.201: ISDN Se0/0/0:15 Q931: TX -> CONNECT pd = 8 callref = 0x8001
May 4 14:48:38.261: ISDN Se0/0/0:15 Q931: RX <- CONNECT_ACK pd = 8 callref = 0x0001
May 4 14:48:54.170: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8 callref = 0x0002
        Sending Complete
        Bearer Capability i = 0x9090A3
                Standard = CCITT
                Transfer Capability = 3.1kHz Audio
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98382
                Exclusive, Channel 2
        Calling Party Number i = 0x00A3, N/A
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0x81, '114917'
                Plan:ISDN, Type:Unknown
May 4 14:48:54.190: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x8002
        Channel ID i = 0xA98382
                Exclusive, Channel 2
May 4 14:48:54.202: ISDN Se0/0/0:15 Q931: TX -> ALERTING pd = 8 callref = 0x8002
        Progress Ind i = 0x8088 - In-band info or appropriate now available
May 4 14:49:06.326: ISDN Se0/0/0:15 Q931: TX -> CONNECT pd = 8 callref = 0x8002
May 4 14:49:06.386: ISDN Se0/0/0:15 Q931: RX <- CONNECT_ACK pd = 8 callref = 0x0002
May 4 14:49:12.702: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x0002
        Cause i = 0x8090 - Normal call clearing
        Progress Ind i = 0x8288 - In-band info or appropriate now available
May 4 14:49:12.734: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x8002
May 4 14:49:12.782: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x0002
May 4 14:49:22.242: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8 callref = 0x003B
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98382
                Exclusive, Channel 2
        Calling Party Number i = 0x0081, '114826'
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0x80, '08451234567'
                Plan:Unknown, Type:Unknown
May 4 14:49:22.410: ISDN Se0/0/0:15 Q931: RX <- CALL_PROC pd = 8 callref = 0x803B
        Channel ID i = 0xA98382
                Exclusive, Channel 2
May 4 14:49:23.206: ISDN Se0/0/0:15 Q931: RX <- ALERTING pd = 8 callref = 0x803B
        Progress Ind i = 0x8482 - Destination address is non-ISDN
May 4 14:49:23.382: ISDN Se0/0/0:15 Q931: RX <- CONNECT pd = 8 callref = 0x803B
May 4 14:49:23.390: ISDN Se0/0/0:15 Q931: TX -> CONNECT_ACK pd = 8 callref = 0x003B
May 4 14:50:25.392: ISDN Se0/0/0:15 Q931: TX -> DISCONNECT pd = 8 callref = 0x003B
        Cause i = 0x8090 - Normal call clearing
May 4 14:50:25.552: ISDN Se0/0/0:15 Q931: RX <- RELEASE pd = 8 callref = 0x803B
May 4 14:50:25.576: ISDN Se0/0/0:15 Q931: TX -> RELEASE_COMP pd = 8 callref = 0x003B
May 4 14:51:10.629: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x0001
        Cause i = 0x8090 - Normal call clearing
        Progress Ind i = 0x8288 - In-band info or appropriate now available
May 4 14:51:10.661: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x8001
May 4 14:51:10.713: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x0001
May 4 14:51:44.557: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8 callref = 0x003C
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Calling Party Number i = 0x0081, '114826'
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0x80, '08451234567'
                Plan:Unknown, Type:Unknown
May 4 14:51:44.741: ISDN Se0/0/0:15 Q931: RX <- CALL_PROC pd = 8 callref = 0x803C
        Channel ID i = 0xA98381
                Exclusive, Channel 1
May 4 14:51:45.733: ISDN Se0/0/0:15 Q931: RX <- ALERTING pd = 8 callref = 0x803C
        Progress Ind i = 0x8482 - Destination address is non-ISDN
May 4 14:51:45.901: ISDN Se0/0/0:15 Q931: RX <- CONNECT pd = 8 callref = 0x803C
May 4 14:51:45.909: ISDN Se0/0/0:15 Q931: TX -> CONNECT_ACK pd = 8 callref = 0x003C
May 4 14:51:54.234: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x803C
        Cause i = 0x8A90 - Normal call clearing
        Progress Ind i = 0x8288 - In-band info or appropriate now available
May 4 14:51:54.274: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x003C
May 4 14:51:54.326: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x803C
May 4 14:52:39.603: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8 callref = 0x0001
        Sending Complete
        Bearer Capability i = 0x9090A3
                Standard = CCITT
                Transfer Capability = 3.1kHz Audio
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Calling Party Number i = 0x2183, '7812456789'
                Plan:ISDN, Type:National
        Called Party Number i = 0x81, '114932'
                Plan:ISDN, Type:Unknown
May 4 14:52:39.627: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x8001
        Channel ID i = 0xA98381
                Exclusive, Channel 1
May 4 14:52:39.627: ISDN Se0/0/0:15 Q931: TX -> ALERTING pd = 8 callref = 0x8001
        Progress Ind i = 0x8088 - In-band info or appropriate now available
May 4 14:52:59.739: ISDN Se0/0/0:15 Q931: TX -> CONNECT pd = 8 callref = 0x8001
May 4 14:52:59.795: ISDN Se0/0/0:15 Q931: RX <- CONNECT_ACK pd = 8 callref = 0x0001
May 4 14:53:05.051: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x0001
        Cause i = 0x8090 - Normal call clearing
        Progress Ind i = 0x8288 - In-band info or appropriate now available
May 4 14:53:05.087: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x8001
May 4 14:53:05.139: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x0001
May 4 14:55:11.374: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8 callref = 0x0001
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Calling Party Number i = 0x00A3, N/A
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0x81, '114822'
                Plan:ISDN, Type:Unknown
        High Layer Compat i = 0x9181
May 4 14:55:11.406: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x8001
        Channel ID i = 0xA98381
                Exclusive, Channel 1
May 4 14:55:11.414: ISDN Se0/0/0:15 Q931: TX -> SETUP pd = 8 callref = 0x003D
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98382
                Exclusive, Channel 2
        Calling Party Number i = 0x00A3, '90'
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0x80, '07789123456'
                Plan:Unknown, Type:Unknown
May 4 14:55:11.610: ISDN Se0/0/0:15 Q931: RX <- CALL_PROC pd = 8 callref = 0x803D
        Channel ID i = 0xA98382
                Exclusive, Channel 2
May 4 14:55:22.890: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x0001
        Cause i = 0x8090 - Normal call clearing
May 4 14:55:22.898: ISDN Se0/0/0:15 Q931: TX -> DISCONNECT pd = 8 callref = 0x003D
        Cause i = 0x8090 - Normal call clearing
May 4 14:55:22.922: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x8001
May 4 14:55:22.982: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x0001
May 4 14:55:23.042: ISDN Se0/0/0:15 Q931: RX <- RELEASE pd = 8 callref = 0x803D
May 4 14:55:23.070: ISDN Se0/0/0:15 Q931: TX -> RELEASE_COMP pd = 8 callref = 0x003D
May 4 14:55:35.374: ISDN Se0/0/0:15 Q931: RX <- SETUP pd = 8 callref = 0x0001
        Sending Complete
        Bearer Capability i = 0x8090A3
                Standard = CCITT
                Transfer Capability = Speech
                Transfer Mode = Circuit
                Transfer Rate = 64 kbit/s
        Channel ID i = 0xA98381
                Exclusive, Channel 1
        Calling Party Number i = 0x00A3, N/A
                Plan:Unknown, Type:Unknown
        Called Party Number i = 0x81, '114800'
                Plan:ISDN, Type:Unknown
        High Layer Compat i = 0x9181
May 4 14:55:35.398: ISDN Se0/0/0:15 Q931: TX -> CALL_PROC pd = 8 callref = 0x8001
        Channel ID i = 0xA98381
                Exclusive, Channel 1
May 4 14:55:35.398: ISDN Se0/0/0:15 Q931: TX -> ALERTING pd = 8 callref = 0x8001
        Progress Ind i = 0x8088 - In-band info or appropriate now available
May 4 14:55:40.254: ISDN Se0/0/0:15 Q931: TX -> CONNECT pd = 8 callref = 0x8001
May 4 14:55:40.314: ISDN Se0/0/0:15 Q931: RX <- CONNECT_ACK pd = 8 callref = 0x0001
May 4 14:56:35.076: ISDN Se0/0/0:15 Q931: RX <- DISCONNECT pd = 8 callref = 0x0001
        Cause i = 0x8090 - Normal call clearing
        Progress Ind i = 0x8288 - In-band info or appropriate now available
May 4 14:56:35.112: ISDN Se0/0/0:15 Q931: TX -> RELEASE pd = 8 callref = 0x8001
May 4 14:56:35.168: ISDN Se0/0/0:15 Q931: RX <- RELEASE_COMP pd = 8 callref = 0x0001

Gateway and phones regions: Same Device Pool, Same Region.

I've done a debug q931 (below). Any call involving 07712345678 had the one way audio. I suspected we may have a duff channel but have made it busy and tested different channel-same problem. One call was fine on the debug: callref = 0x0005.

Regards

Rich

barry · ‎05-05-2011

Hi Rich

If you can see the audio arriving at the gateway in one piece, and you get the issue on multiple B channels then it is starting to look like the gateway itself I'm afraid. Your logs don't have any DSP error messages in them which tends to rule out major hardware failure on them.

Alas its starting to look like you will need to get TAC involved in this one. Whilst I have copy of the script they use to capture the audio on the gateway itself, I don't have access to the tool that is used to convert it to a sensible audio format.

Barry

richb1971 · ‎05-05-2011

Yeah its TAC time. Frustrating. Thanks for all your help though Barry. Much appreciated.

Rich

richb1971 · ‎05-06-2011

Sorted!

Good old BT finally admitted after 2 weeks- yes there is a problem with 4 channels.

Can we charge THEM for loss of time as its their equipment?! I wish. I hate BT.

The channels have been temporarily disabled and service is working fine now.

Grr

barry · ‎05-06-2011

Hi Rich

Good news. I share your feelings about that certain supplier too.... This kind of thing has happened to me more than once.

Then again, I also had a similar issue with the company belonging to Mr Branson as well.

Carriers. Don't you just love them.

At least you now how to capture and replay audio streams now, so not all wasted time :-)

Barry